Need help debugging ...

Hy list,

I like to learn how to fix wine problems myself and am trying to track down an exception
occuring while starting good old 'Dungeon Keeper'.

For now I have two problems:
1. When I invoke the game with 'wine' and with 'winedbg' I get different exception messages
    (traces see below), why?
2. How to compile debug information into the 32bit DLL's so I don't get
    'No debug information in 32bit DLL' anymore and maybe some better info?
    I tried 'configure --enable-debug && make depend && make && su -c "make install"' to
    no avail.

I compiled 'fixme's into the 'SetThreadExecutionState' and 'VerSetConditionMask' funcs to
see where the exceptions occure but it seems the methods aren't even called at all because
the messages don't get printed out (or need the fixme messages switched on somewhere for
that particular dll?).

I also tried to start with --debugmsg +all in which case the output is overwriting the
winedbg command line interface and crashing it when trying to exit with CTRL-C
and CTRL-D. Only killall -9 wine-pthread helps then.

The wine I'm using is fresh from CVS as of 15. Jan. 2004 but I had the problem with earlier
versions too.

============= STARTING WITH 'wine' ================
merlin(a)Merlin:~/.wine/fake_windows/Program Files/Bullfrog/Keeper> wine KEEPER95.EXE
wine: Unhandled exception (thread 0009), starting debugger...
WineDbg starting on pid 8
Loaded debug information from ELF 'wine' ((nil))
No debug information in 32bit DLL 'C:\Program Files\Bullfrog\Keeper\KEEPER95.EXE' (0x400000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\NTDLL.DLL' (0x40220000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\KERNEL32.DLL' (0x404b0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\ADVAPI32.DLL' (0x40760000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\GDI32.DLL' (0x406f0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\USER32.DLL' (0x407d0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WINSPOOL.DRV' (0x40790000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WINMM.DLL' (0x408f0000)
No debug information in 32bit DLL 'C:\PROGRAM FILES\BULLFROG\KEEPER\MSS32.DLL' (0x20000000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\RPCRT4.DLL' (0x409e0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\OLE32.DLL' (0x40960000)
No debug information in 32bit DLL 'C:\PROGRAM FILES\BULLFROG\KEEPER\WSND7R.DLL' (0x10000000)
No debug information in 32bit DLL 'C:\PROGRAM FILES\BULLFROG\KEEPER\SMACKW32.DLL' (0x40022000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\DDRAW.DLL' (0x40a20000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\DPLAYX.DLL' (0x40be0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\IPHLPAPI.DLL' (0x40c30000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WS2_32.DLL' (0x40c10000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WSOCK32.DLL' (0x40a80000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\X11DRV.DLL' (0x40d10000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WINEOSS.DRV' (0x41390000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\MSACM32.DLL' (0x413e0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\MSACM.DRV' (0x413c0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\MIDIMAP.DRV' (0x41400000)
Unhandled exception: page fault on write access to 0x00000000 in 32-bit code (0x00406062).
In 32-bit mode.
0x00406062 (KEEPER95.EXE..text+0x5062 in KEEPER95.EXE): movb    $0x0,0x0(%eax)
Wine-dbg>bt
Backtrace:
=>0 0x00406062 (KEEPER95.EXE..text+0x5062 in KEEPER95.EXE) (ebp=406cff2c)
   1 0x40501e3d (KERNEL32.DLL.SetThreadExecutionState+0x17fd in KERNEL32.DLL) (ebp=406cfff4)
   2 0x4003e60d (SMACKW32.DLL..reloc+0x660d) (ebp=00000000)

Wine-dbg>
============= STARTING WITH 'wine' END ============


============= STARTING WITH 'winedbg' =============
merlin(a)Merlin:~/.wine/fake_windows/Program Files/Bullfrog/Keeper> winedbg KEEPER95.EXE
fixme:console:SetConsoleCtrlHandler (0x405feed0,1) - no error checking or testing yet
WineDbg starting on pid 19
Breakpoint 1 at 0x004f1ed0
Unable to add breakpoint, will check again any time a new DLL is loaded
Loaded debug information from ELF 'wine' ((nil))
No debug information in 32bit DLL 'C:\Program Files\Bullfrog\Keeper\KEEPER95.EXE' (0x400000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\NTDLL.DLL' (0x40220000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\KERNEL32.DLL' (0x404b0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\ADVAPI32.DLL' (0x40760000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\GDI32.DLL' (0x406f0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\USER32.DLL' (0x407d0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WINSPOOL.DRV' (0x40790000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WINMM.DLL' (0x408f0000)
No debug information in 32bit DLL 'C:\PROGRAM FILES\BULLFROG\KEEPER\MSS32.DLL' (0x20000000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\RPCRT4.DLL' (0x409e0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\OLE32.DLL' (0x40960000)
No debug information in 32bit DLL 'C:\PROGRAM FILES\BULLFROG\KEEPER\WSND7R.DLL' (0x10000000)
No debug information in 32bit DLL 'C:\PROGRAM FILES\BULLFROG\KEEPER\SMACKW32.DLL' (0x40a05000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\DDRAW.DLL' (0x40a40000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\DPLAYX.DLL' (0x40be0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\IPHLPAPI.DLL' (0x40c30000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WS2_32.DLL' (0x40c10000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WSOCK32.DLL' (0x40aa0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\X11DRV.DLL' (0x40d20000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\WINEOSS.DRV' (0x41390000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\MSACM32.DLL' (0x413e0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\MSACM.DRV' (0x413d0000)
No debug information in 32bit DLL 'C:\WINDOWS\SYSTEM\MIDIMAP.DRV' (0x41400000)
In 32-bit mode.
Wine-dbg>cont
Stopped on breakpoint 1 at 0x004f1ed0 (KEEPER95.EXE.EntryPoint in KEEPER95.EXE)
Wine-dbg>cont
First chance exception: page fault on write access to 0x00000000Invalid address for breakpoint 1, disabling it
  in 32-bit code (0x00406062).
Register dump:
  CS:0023 SS:002b DS:002b ES:002b FS:1007 GS:0007
  EIP:00406062 ESP:406cfd18 EBP:406cff2c EFLAGS:00010206(  R- 00  I   - -P1 )
  EAX:00000000 EBX:ffffffff ECX:00000000 EDX:406cfcec
  ESI:00776685 EDI:406cfd99
Stack dump:
0x406cfd18 (KERNEL32.DLL.VerSetConditionMask+0x14e97a): *** Invalid address 0x406cfd18 (KERNEL32.DLL.VerSetConditionMask+0x14e97a)


0200: sel=1007 base=4001a000 limit=00001f83 32-bit rw-
Backtrace:
=>0 0x00406062 (KEEPER95.EXE..text+0x5062 in KEEPER95.EXE) (ebp=406cff2c)
Can't read TEB:cur_stack
0x00406062 (KEEPER95.EXE..text+0x5062 in KEEPER95.EXE): *** Invalid address 0x00406062 (KEEPER95.EXE..text+0x5062 in KEEPER95.EXE)
-- no code --
Wine-dbg>
============= STARTING WITH 'winedbg' END =========

-- 
Thanks,
   Frank

[Mike Hearn]

On Thu, 15 Jan 2004 01:00:32 +0100, Frank Schruefer wrote:
> Hey list,
>
> I like to learn how to fix wine problems myself and am trying to track down an exception
> occuring while starting good old 'Dungeon Keeper'.

Good luck! Please don't be discouraged if you can't crack this one though,
both me and Lionel have looked at Dungeon Keeper (1 and 2) and couldn't
figure out why it doesn't work. Lionel has been a Wine hacker for 5+ years
now! If you can't get DK to work, or are finding it too
frustrating, perhaps move on to another program and see if it's any easier?
> For now I have two problems:
> 1. When I invoke the game with 'wine' and with 'winedbg' I get different exception messages
>     (traces see below), why?

You don't, you get the same crash:

from just wine:
> Unhandled exception: page fault on write access to 0x00000000 in 32-bit
> code (00406062).

from winedbg:
> First chance exception: page fault on write access to 0x00000000
> in 32-bit code (0x00406062).

Unhandled vs first chance, hmm, how to explain this. Well in the debugger
you can trap *all* exceptions, even if the program itself may in turn
catch that exception and deal with it. So it's called a first-chance
because you the debugger get the first chance to deal with it. Unhandled
just means there was an exception and the program didn't do anything with
it, so it falls back to the debugger (in Windows you would see the crash
dialog). Notice how the numbers are the same, and the fault (writing to
null) is the same.

You can disassemble this code to see what caused the crash using "disas
0x406062" but I seem to remember the results were inconclusive - as they
often are with disassembly.
> 2. How to compile debug information into the 32bit DLL's so I don't get
>     'No debug information in 32bit DLL' anymore and maybe some better info?
>     I tried 'configure --enable-debug && make depend && make && su -c "make install"' to
>     no avail.

They have debugging info in, but unfortunately there has been breakage in
the debugger recently which has not yet been fixed in CVS. This is very
bad :( EricP sent a patch here which works great for me and fixed all my
debugger problems, try looking in the archives for Jan and December
looking for it (it was sent to wine-devel not wine-patches iirc).

For now try setting WINELOADER to the path to your actual wine binary
(wine-pthread)

Eric, could you please submit that patch? Even if it's not correct, having
the debuggers out of action like this is causing big problems.
> I compiled 'fixme's into the 'SetThreadExecutionState' and 'VerSetConditionMask' funcs to
> see where the exceptions occure but it seems the methods aren't even called at all because
> the messages don't get printed out (or need the fixme messages switched on somewhere for
> that particular dll?).

No, they aren't called, they just happen to be the closest exported
symbols the debugger could find. In general the names given to you when
there are no debug symbols are useless. Look:

1 0x40501e3d (KERNEL32.DLL.SetThreadExecutionState+0x17fd in KERNEL2.DLL)

see the +0x17fd here? That means the crash occurred in some code a long
way from the start of that function, who knows where without debug symbols
though.
> I also tried to start with --debugmsg +all in which case the output is overwriting the
> winedbg command line interface and crashing it when trying to exit with CTRL-C
> and CTRL-D. Only killall -9 wine-pthread helps then.

Redirect the output to a logfile:

wine --debugmsg +all keeper.exe 2>log

Useful channels are +relay which show every API call, +snoop which does
the same but between non-wine DLLs (so it's a bit crashy but should be
fine here) and so on.

IIRC keeper makes only one or two API calls before crashing, both of those
calls are trivial and succeed (setting a timer or something I think) so
it's more likely to be to do with the layout of an in memory struct or
something. Remember that the TEB is stored in %fs, if you see references
to that register.
> The wine I'm using is fresh from CVS as of 15. Jan. 2004 but I had the problem with earlier
> versions too.

Yes, keeper has never worked for me :(

thanks -mike

[Boaz Harrosh]

Mike Hearn wrote:
> IIRC keeper makes only one or two API calls before crashing, both of those
> calls are trivial and succeed (setting a timer or something I think) so
> it's more likely to be to do with the layout of an in memory struct or
> something. Remember that the TEB is stored in %fs, if you see references
> to that register.

Just a long shot. I had a problem with my own program. where I would 
crush on a bug as so:

in the code at global scope I had:

SomeStruct table[] = {
    {1,2,3,4}
    {1,2,3,4}
    .....
    {1,2,3,4}
} ;
// Note that the the last null record is missing

now the startup code will load this table until seeing null in first 
field. That never crashed on windows (5 years old code). But on Linux it 
would (same PE binary). Is it possible that static uninitialized data 
(in a data segment) is set to 0 on Windows and is untouched in Linux/wine?

[Mike Hearn]

On Thu, 15 Jan 2004 15:36:17 +0200, Boaz Harrosh wrote:
> Just a long shot. I had a problem with my own program. where I would 
> crush on a bug as so:
>
> in the code at global scope I had:
>
> SomeStruct table[] = {
>     {1,2,3,4}
>     {1,2,3,4}
>     .....
>     {1,2,3,4}
> } ;
> // Note that the the last null record is missing
>
> now the startup code will load this table until seeing null in first 
> field. That never crashed on windows (5 years old code). But on Linux it 
> would (same PE binary). Is it possible that static uninitialized data 
> (in a data segment) is set to 0 on Windows and is untouched in Linux/wine?

That sounds like the sort of bug it might be. I'm pretty sure Linux
initializes static data to zero, but anyway, it shouldn't matter right
because even if ELF binaries are different in this regard we are loading
keeper.exe - a PE binary.

One thing it could be is if we load the data segments in a different
way to Windows I guess..... something like that

> Good luck! Please don't be discouraged if you can't crack this one though,
> both me and Lionel have looked at Dungeon Keeper (1 and 2) and couldn't
> figure out why it doesn't work. Lionel has been a Wine hacker for 5+ years
> now! If you can't get DK to work, or are finding it too
> frustrating, perhaps move on to another program and see if it's any easier?

Hehe, ok ... but I'm not giving up yet;)
> Unhandled vs first chance, hmm, how to explain this. Well in the debugger
> you can trap *all* exceptions, even if the program itself may in turn
> catch that exception and deal with it. So it's called a first-chance
> because you the debugger get the first chance to deal with it. Unhandled
> just means there was an exception and the program didn't do anything with
> it, so it falls back to the debugger (in Windows you would see the crash
> dialog). Notice how the numbers are the same, and the fault (writing to
> null) is the same.

Ok, I understand.
> > 2. How to compile debug information into the 32bit DLL's so I don't get
> >    'No debug information in 32bit DLL' anymore and maybe some better info?
> >    I tried 'configure --enable-debug && make depend && make && su -c "make install"' to
> >    no avail.
>
> They have debugging info in, but unfortunately there has been breakage in
> the debugger recently which has not yet been fixed in CVS. This is very
> bad :( EricP sent a patch here which works great for me and fixed all my
> debugger problems, try looking in the archives for Jan and December
> looking for it (it was sent to wine-devel not wine-patches iirc).
>
> For now try setting WINELOADER to the path to your actual wine binary
> (wine-pthread)

That works.
> No, they aren't called, they just happen to be the closest exported
> symbols the debugger could find. In general the names given to you when
> there are no debug symbols are useless. Look:
>
> 1 0x40501e3d (KERNEL32.DLL.SetThreadExecutionState+0x17fd in KERNEL2.DLL)
>
> see the +0x17fd here? That means the crash occurred in some code a long
> way from the start of that function, who knows where without debug symbols
> though.

Ok.
> IIRC keeper makes only one or two API calls before crashing, both of those
> calls are trivial and succeed (setting a timer or something I think) so
> it's more likely to be to do with the layout of an in memory struct or
> something. Remember that the TEB is stored in %fs, if you see references
> to that register.

Yep. It's setting up a timer which in turn creates a thread as far as I
understand until now. There's something like a stack overflow going on _maybe_.
I've put a backtrace dumping to the start of RTLLeaveCriticalSection which shows more
than >1024 stackframes being used near the occurance of the prob - it's showing a re-
peating pattern, as does wine --debugmsg +relay,+seh.

Here a little excerpt of the latter:
...
...
...
0013:Ret  ntdll.RtlLeaveCriticalSection() retval=00000000 ret=4094afe9
0013:Call ntdll.RtlEnterCriticalSection(403ac6a8) ret=4094ae6f
0013:Ret  ntdll.RtlEnterCriticalSection() retval=00000000 ret=4094ae6f
0013:Call ntdll.RtlLeaveCriticalSection(403ac6a8) ret=4094afe9
0013:Ret  ntdll.RtlLeaveCriticalSection() retval=00000000 ret=4094afe9
0013:Call ntdll.RtlEnterCriticalSection(403ac6a8) ret=4094ae6f
0013:Ret  ntdll.RtlEnterCriticalSection() retval=00000000 ret=4094ae6f
0013:Call ntdll.RtlLeaveCriticalSection(403ac6a8) ret=4094afe9
0013:Ret  ntdll.RtlLeaveCriticalSection() retval=00000000 ret=4094afe9
0013:Call ntdll.RtlEnterCriticalSection(403ac6a8) ret=4094ae6f
0013:Ret  ntdll.RtlEnterCriticalSection() retval=00000000 ret=4094ae6f
0013:Call ntdll.RtlLeaveCriticalSection(403ac6a8) ret=4094afe9
0013:Ret  ntdll.RtlLeaveCriticalSection() retval=00000000 ret=4094afe9
0013:Call ntdll.RtlEnterCriticalSection(403ac6a8) ret=4094ae6f
0013:Ret  ntdll.RtlEnterCriticalSection() retval=00000000 ret=4094ae6f
0013:Call ntdll.RtlLeaveCriticalSection(403ac6a8) ret=4094afe9
0013:Ret  ntdll.RtlLeaveCriticalSection() retval=00000000 ret=4094afe9
0013:Call ntdll.RtlEnterCriticalSection(403ac6a8) ret=4094ae6f
0013:RUnhandled exception: page fault on write access to 0x00000000 in 32-bit code (0x00406062).
In 32-bit mode.
0x00406062 (KEEPER95.EXE..text+0x5062 in KEEPER95.EXE): movb    $0x0,0x0(%eax)
Wine-dbg>walk thread
process  tid      prio
00000011 (D) C:\Program Files\Bullfrog\Keeper\KEEPER95.EXE
         00000013    0
         00000012    0 <==
00000008
         00000009    0
Wine-dbg>

I've set stack_reserve to 8MB min. That didn't make much of a difference.
Unfortunitely I run across a bunch of debugger bugs (I think) following the creation
of the timer thread, I decided to put these problems into another post though.
I wanted to step to the point where the thread comes alive when the debugger left me at/near
a syscall :(
I think it has something to do with this thread cause the exception you get is always
another depending on what you currently debug ... somehow asynchronous, as the above :)

-- 
Thank you,
   Frank

[Eric Pouech]

> Eric, could you please submit that patch? Even if it's not correct, having
> the debuggers out of action like this is causing big problems.

I won't submit the patch as it today:
- too hacky
- not correct (we use the debugger thread environment, while we should 
use the debuggees environment. This shouldn't be too much an issue in 
most of the cases, except if you debug on a remote machine using the gdb 
proxy stuff)
- there's an easy workaround with WINELOADER env variable

the proper fix could be to:
- add a mechanism while loading an image (from disk) to check it's the 
same one as the one of the debuggee
- then, use that to test both wine-pthread and wine-kthread

A+