documentation/debugging

   1 This file describes where to start debugging Wine. If at any point
   2 you get stuck and want to ask for help, please read the file
   3 documentation/bugreports for information on how to write useful bug
   4 reports.
   5
   6 Crashes
   7 =======
   8
   9   These usually show up like this:
  10
  11 |Unexpected Windows program segfault - opcode = 8b
  12 |Segmentation fault in Windows program 1b7:c41.
  13 |Loading symbols from ELF file /root/wine/wine...
  14 |....more Loading symbols from ...
  15 |In 16 bit mode.
  16 |Register dump:
  17 | CS:01b7 SS:016f DS:0287 ES:0000
  18 | IP:0c41 SP:878a BP:8796 FLAGS:0246
  19 | AX:811e BX:0000 CX:0000 DX:0000 SI:0001 DI:ffff
  20 |Stack dump:
  21 |0x016f:0x878a:  0001 016f ffed 0000 0000 0287 890b 1e5b
  22 |0x016f:0x879a:  01b7 0001 000d 1050 08b7 016f 0001 000d
  23 |0x016f:0x87aa:  000a 0003 0004 0000 0007 0007 0190 0000
  24 |0x016f:0x87ba:
  25 |
  26 |0050: sel=0287 base=40211d30 limit=0b93f (bytes) 16-bit rw-
  27 |Backtrace:
  28 |0 0x01b7:0x0c41 (PXSRV_FONGETFACENAME+0x7c)
  29 |1 0x01b7:0x1e5b (PXSRV_FONPUTCATFONT+0x2cd)
  30 |2 0x01a7:0x05aa
  31 |3 0x01b7:0x0768 (PXSRV_FONINITFONTS+0x81)
  32 |4 0x014f:0x03ed (PDOXWIN_@SQLCURCB$Q6CBTYPEULN8CBSCTYPE+0x1b1)
  33 |5 0x013f:0x00ac
  34 |
  35 |0x01b7:0x0c41 (PXSRV_FONGETFACENAME+0x7c):  movw        %es:0x38(%bx),%dx
  36
  37 Steps to debug a crash. You may stop at any step, but please report the bug
  38 and provide as much of the information gathered to the newsgroup or the
  39 relevant developer as feasonable.
  40
  41  1. Get the reason for the crash. This is usually an access to an invalid
  42     selector, an access to an out of range address in a valid selector,
  43     popping a segmentregister from the stack or the like. When reporting a
  44     crash, report this WHOLE crashdump even if it doesn't make sense to you.
  45
  46     (In this case it is access to an invalid selector, for %es is 0000, as
  47     seen in the register dump).
  48
  49  2. Determine where the reason came from.
  50     Since this is usually a primary/secondary reaction to a failed or
  51     misbehaving Wine function, rerun Wine with "-debugmsg +relay" (without ")
  52     added to the commandline. This will get rather much output, but usually
  53     the reason is located in the last call(s).  Those lines usually look like
  54     this:
  55
  56 |Call KERNEL.90: LSTRLEN(0227:0692 "text") ret=01e7:2ce7 ds=0227
  57       ^^^^^^^^^  ^       ^^^^^^^^^ ^^^^^^      ^^^^^^^^^    ^^^^
  58       |          |       |         |           |            |Datasegment
  59       |          |       |         |           |Return address
  60       |          |       |         |textual parameter
  61       |          |       |
  62       |          |       |Argument(s). This one is a win16 segmented pointer.
  63       |          |Function called.
  64       |The module, the function is called in. In this case it is KERNEL.
  65
  66 |Ret  KERNEL.90: LSTRLEN() retval=0x0004 ret=01e7:2ce7 ds=0227
  67                                   ^^^^^^
  68                                   |Returnvalue is 16 bit and has the value 4.
  69
  70
  71  3. If you have found a misbehaving function, try to find out why it
  72     misbehaves. Find the function in the source code. Try to make sense of
  73     the arguments passed. Usually there is a 'TRACE(<channel>,"(...)\n");'
  74     at the beginning of the function. Rerun wine with
  75     "-debugmsg +xyz,+relay" added to the commandline.
  76
  77  4. Additional information on how to debug using the internal debugger can be
  78     found in debugger/README.
  79
  80  5. If those information isn't clear enough or if you want to know more about
  81     what's happening in the function itself, try running wine with "-debugmsg
  82     +all", which dumps ALL included debug information in wine.
  83
  84  6. If that isn't enough add more debug output for yourself into the
  85     functions you find relevant.  See documentation/debug-msgs.
  86     You might also try to run the program in gdb instead of using the
  87     WINE-debugger. If you do that, use "handle SIGSEGV nostop noprint"
  88     to disable the handling of seg faults inside gdb (needed for Win16).
  89     If you don't use the "-desktop" or "-managed" option,
  90     start the WINE process with "-sync", or chances are good to get X into
  91     an unusable state.
  92
  93  7. You can also set a breakpoint for that function. Start wine with the
  94     "-debug" option added to the commandline. After loading the executable
  95     wine will enter the internal debugger. Use "break KERNEL_LSTRLEN"
  96     (replace by function you want to debug, CASE IS RELEVANT.) to set a
  97     breakpoint.  Then use "continue" to start normal program-execution. Wine
  98     will stop if it reaches the breakpoint. If the program isn't yet at the
  99     crashing call of that function, use "continue" again until you are about
 100     to enter that function. You may now proceed with single-stepping the
 101     function until you reach the point of crash. Use the other debugger
 102     commands to print registers and the like.
 103
 104
 105 Program hangs, nothing happens
 106 ==============================
 107
 108   Switch to UNIX shell, get the process-ID using "ps -a|grep wine", and do a
 109   "kill -HUP <pid>" (without " and <>). Wine will then enter its internal
 110   debugger and you can proceed as explained above. Also, you can use -debug
 111   switch and then you can get into internal debugger by pressing Ctrl-C in
 112   the terminal where you run Wine.
 113
 114 Program reports an error with a Messagebox
 115 ==========================================
 116
 117   Sometimes programs are reporting failure using a more or less nondescript
 118   messageboxes. We can debug this using the same method as Crashes, but there
 119   is one problem... For setting up a message box the program also calls Wine
 120   producing huge chunks of debug code.
 121
 122   Since the failure happens usually directly before setting up the Messagebox
 123   you can start wine with "-debug" added to the commandline, set a breakpoint
 124   at "MessageBoxA" (called by win16 and win32 programs) and proceed with
 125   "continue". With "-debugmsg +all" Wine will now stop directly before
 126   setting up the Messagebox.  Proceed as explained above.
 127
 128   You can also run wine using "wine -debugmsg +relay program.exe 2>&1|less -i"
 129   and in less search for messagebox.
 130
 131 Disassembling programs:
 132 =======================
 133   You may also try to disassemble the offending program to check for
 134   undocumented features and/or use of them.
 135
 136   The best, freely available, disassembler for Win16 programs is
 137   Windows Codeback, archivename wcbxxx.zip, which usually can be found
 138   in the Cica-Mirror subdirectory on the WINE ftpsites. (See ANNOUNCE).
 139
 140   Disassembling win32 programs is possible using the Windows Disassembler 32,
 141   archivename something like w32dsm87.zip (or similar) on ftp.winsite.com
 142   and mirrors.  The shareware version does not allow saving of disassembly
 143   listings.
 144   You can also use the newer (and in the full version better) Interactive
 145   Disassembler (IDA) from the ftp sites mentioned at the end of the document.
 146
 147   Understanding disassembled code is mostly a question of exercise.
 148
 149   Most code out there uses standard C function entries (for it is usually
 150   written in C). Win16 function entries usually look like that:
 151 |       push bp
 152 |       mov bp, sp
 153 |       ... function code ..
 154 |       retf XXXX       <--------- XXXX is number of bytes of arguments
 155
 156   This is a FAR function with no local storage. The arguments usually start
 157   at [bp+6] with increasing offsets. Note, that [bp+6] belongs to the RIGHTMOST
 158   argument, for exported win16 functions use the PASCAL calling convention.
 159   So, if we use strcmp(a,b) with a and b both 32 bit variables b would be at
 160   [bp+6] and a at [bp+10].
 161   Most functions make also use of local storage in the stackframe:
 162 |       enter 0086, 00
 163 |       ... function code ...
 164 |       leave
 165 |       retf XXXX
 166   This does mostly the same as above, but also adds 0x86 bytes of
 167   stackstorage, which is accessed using [bp-xx].
 168   Before calling a function, arguments are pushed on the stack using something
 169   like this:
 170 |       push word ptr [bp-02]   <- will be at [bp+8]
 171 |       push di                 <- will be at [bp+6]
 172 |       call KERNEL.LSTRLEN
 173   Here first the selector and then the offset to the passed string are pushed.
 174
 175 Sample debugging session:
 176 =========================
 177
 178   Let's debug the infamous Word SHARE.EXE messagebox:
 179
 180 |marcus@jet $ wine winword.exe
 181 |            +---------------------------------------------+
 182 |            | !  You must leave Windows and load SHARE.EXE|
 183 |            |    before starting Word.                    |
 184 |            +---------------------------------------------+
 185
 186
 187 |marcus@jet $ wine winword.exe -debugmsg +relay -debug
 188 |CallTo32(wndproc=0x40065bc0,hwnd=000001ac,msg=00000081,wp=00000000,lp=00000000)
 189 |Win16 task 'winword': Breakpoint 1 at 0x01d7:0x001a
 190 |CallTo16(func=0127:0070,ds=0927)
 191 |Call WPROCS.24: TASK_RESCHEDULE() ret=00b7:1456 ds=0927
 192 |Ret  WPROCS.24: TASK_RESCHEDULE() retval=0x8672 ret=00b7:1456 ds=0927
 193 |CallTo16(func=01d7:001a,ds=0927)
 194 |     AX=0000 BX=3cb4 CX=1f40 DX=0000 SI=0000 DI=0927 BP=0000 ES=11f7
 195 |Loading symbols: /home/marcus/wine/wine...
 196 |Stopped on breakpoint 1 at 0x01d7:0x001a
 197 |In 16 bit mode.
 198 |Wine-dbg>break MessageBoxA                          <---- Set Breakpoint
 199 |Breakpoint 2 at 0x40189100 (MessageBoxA [msgbox.c:190])
 200 |Wine-dbg>c                                            <---- Continue
 201 |Call KERNEL.91: INITTASK() ret=0157:0022 ds=08a7
 202 |     AX=0000 BX=3cb4 CX=1f40 DX=0000 SI=0000 DI=08a7 ES=11d7 EFL=00000286
 203 |CallTo16(func=090f:085c,ds=0dcf,0x0000,0x0000,0x0000,0x0000,0x0800,0x0000,0x0000,0x0dcf)
 204 |...                                                   <----- Much debugoutput
 205 |Call KERNEL.136: GETDRIVETYPE(0x0000) ret=060f:097b ds=0927
 206                                ^^^^^^ Drive 0 (A:)
 207 |Ret  KERNEL.136: GETDRIVETYPE() retval=0x0002 ret=060f:097b ds=0927
 208                                         ^^^^^^  DRIVE_REMOVEABLE
 209                                                 (It is a floppy diskdrive.)
 210
 211 |Call KERNEL.136: GETDRIVETYPE(0x0001) ret=060f:097b ds=0927
 212                                ^^^^^^ Drive 1 (B:)
 213 |Ret  KERNEL.136: GETDRIVETYPE() retval=0x0000 ret=060f:097b ds=0927
 214                                         ^^^^^^  DRIVE_CANNOTDETERMINE
 215                                                 (I don't have drive B: assigned)
 216
 217 |Call KERNEL.136: GETDRIVETYPE(0x0002) ret=060f:097b ds=0927
 218                                ^^^^^^^ Drive 2 (C:)
 219 |Ret  KERNEL.136: GETDRIVETYPE() retval=0x0003 ret=060f:097b ds=0927
 220                                         ^^^^^^ DRIVE_FIXED
 221                                                (specified as a harddisk)
 222
 223 |Call KERNEL.97: GETTEMPFILENAME(0x00c3,0x09278364"doc",0x0000,0927:8248) ret=060f:09b1 ds=0927
 224                                  ^^^^^^           ^^^^^        ^^^^^^^^^
 225                                  |                |            |buffer for fname
 226                                  |                |temporary name ~docXXXX.tmp
 227                                  |Force use of Drive C:.
 228
 229 |Warning: GetTempFileName returns 'C:~doc9281.tmp', which doesn't seem to be writeable.
 230 |Please check your configuration file if this generates a failure.
 231
 232 Whoops, it even detects that something is wrong!
 233
 234 |Ret  KERNEL.97: GETTEMPFILENAME() retval=0x9281 ret=060f:09b1 ds=0927
 235                                           ^^^^^^ Temporary storage ID
 236
 237 |Call KERNEL.74: OPENFILE(0x09278248"C:~doc9281.tmp",0927:82da,0x1012) ret=060f:09d8 ds=0927
 238                                     ^^^^^^^^^^^^^^^^ ^^^^^^^^^ ^^^^^^^
 239                                     |filename        |OFSTRUCT |open mode:
 240
 241                                        OF_CREATE|OF_SHARE_EXCLUSIVE|OF_READWRITE
 242
 243 This fails, since my C: drive is in this case mounted readonly.
 244
 245 |Ret  KERNEL.74: OPENFILE() retval=0xffff ret=060f:09d8 ds=0927
 246                                    ^^^^^^ HFILE_ERROR16, yes, it failed.
 247
 248 |Call USER.1: MESSAGEBOX(0x0000,0x09278376"Sie müssen Windows verlassen und SHARE.EXE laden bevor Sie Word starten.",0x00000000,0x1030) ret=060f:084f ds=0927
 249
 250 And MessageBox'ed.
 251
 252 |Stopped on breakpoint 2 at 0x40189100 (MessageBoxA [msgbox.c:190])
 253 |190     {              <- the sourceline
 254 In 32 bit mode.
 255 Wine-dbg>
 256
 257         The code seems to find a writeable harddisk and tries to create a file
 258         there. To work around this bug, you can define C: as a networkdrive,
 259         which is ignored by the code above.
 260
 261 Written by Marcus Meissner <msmeissn@cip.informatik.uni-erlangen.de>,
 262 additions welcome.
 263 -------
 264
 265 Here are some useful debugging tips, added by Andreas Mohr:
 266
 267
 268 a) If you have a program crashing at such an early loader phase that you can't
 269 use the Wine debugger normally, but Wine already executes the program's
 270 start code, then you may use a special trick:
 271 You should do a
 272 wine -debugmsg +relay program
 273 to get a listing of the functions the program calls in its start function.
 274 Now you do a
 275 wine -debug winfile.exe
 276 This way, you get into Wine-dbg. Now you can set a breakpoint on any
 277 function the program calls in the start function and just type "c" to bypass
 278 the eventual calls of Winfile to this function until you are finally at the
 279 place where this function gets called by the crashing start function.
 280 Now you can proceed with your debugging as usual.
 281
 282
 283 b) If you try to run a program and it quits after showing an error messagebox,
 284 the problem can usually be identified in the return value of one of the
 285 functions executed before MessageBox().
 286 That's why you should re-run the program with e.g.
 287 wine -debugmsg +relay <program name> &>relmsg
 288 Then do a "more relmsg" and search for the last occurrence of a call to the string "MESSAGEBOX".
 289 This is a line like
 290 Call USER.1: MESSAGEBOX(0x0000,0x01ff1246 "Runtime error 219 at 0004:1056.",0x00000000,0x1010) ret=01f7:2160 ds=01ff
 291
 292 In my example the lines before the call to MessageBox() look like that:
 293
 294 Call KERNEL.96: FREELIBRARY(0x0347) ret=01cf:1033 ds=01ff
 295 CallTo16(func=033f:0072,ds=01ff,0x0000)
 296 Ret  KERNEL.96: FREELIBRARY() retval=0x0001 ret=01cf:1033 ds=01ff
 297 Call KERNEL.96: FREELIBRARY(0x036f) ret=01cf:1043 ds=01ff
 298 CallTo16(func=0367:0072,ds=01ff,0x0000)
 299 Ret  KERNEL.96: FREELIBRARY() retval=0x0001 ret=01cf:1043 ds=01ff
 300 Call KERNEL.96: FREELIBRARY(0x031f) ret=01cf:105c ds=01ff
 301 CallTo16(func=0317:0072,ds=01ff,0x0000)
 302 Ret  KERNEL.96: FREELIBRARY() retval=0x0001 ret=01cf:105c ds=01ff
 303 Call USER.171: WINHELP(0x02ac,0x01ff05b4 "COMET.HLP",0x0002,0x00000000) ret=01cf:1070 ds=01ff
 304 CallTo16(func=0117:0080,ds=01ff)
 305 Call WPROCS.24: TASK_RESCHEDULE() ret=00a7:0a2d ds=002b
 306 Ret  WPROCS.24: TASK_RESCHEDULE() retval=0x0000 ret=00a7:0a2d ds=002b
 307 Ret  USER.171: WINHELP() retval=0x0001 ret=01cf:1070 ds=01ff
 308 Call KERNEL.96: FREELIBRARY(0x01be) ret=01df:3e29 ds=01ff
 309 Ret  KERNEL.96: FREELIBRARY() retval=0x0000 ret=01df:3e29 ds=01ff
 310 Call KERNEL.52: FREEPROCINSTANCE(0x02cf00ba) ret=01f7:1460 ds=01ff
 311 Ret  KERNEL.52: FREEPROCINSTANCE() retval=0x0001 ret=01f7:1460 ds=01ff
 312 Call USER.1: MESSAGEBOX(0x0000,0x01ff1246 "Runtime error 219 at 0004:1056.",0x00000000,0x1010) ret=01f7:2160 ds=01ff
 313
 314 I think that the call to MessageBox() in this example is _not_ caused
 315 by a wrong result value of some previously executed function (it's
 316 happening quite often like that), but instead the messagebox complains
 317 about a runtime error at 0x0004:0x1056.
 318
 319 As the segment value of the address is only "4", I think that that is
 320 only an internal program value. But the offset address reveals something
 321 quite interesting:
 322
 323 Offset 1056 is _very_ close to the return address of FREELIBRARY():
 324
 325 Call KERNEL.96: FREELIBRARY(0x031f) ret=01cf:105c ds=01ff
 326                                              ^^^^
 327 Provided that segment 0x0004 is indeed
 328 segment 0x1cf, we now we can use IDA (available at
 329 ftp://ftp.uni-koeln.de/pc/msdos/programming/assembler/ida35bx.zip)
 330 to disassemble the part that caused the error. We just have to find
 331 the address of the call to FreeLibrary(). Some lines before that the
 332 runtime error occurred.  But be careful ! In some cases you don't have
 333 to disassemble the main program, but instead some DLL called by it in
 334 order to find the correct place where the runtime error occurred. That
 335 can be determined by finding the origin of the segment value (in this
 336 case 0x1cf).
 337
 338 c) If you have created a relay file of some crashing program and want to set a
 339 breakpoint at a certain location which is not yet available as the
 340 program loads the breakpoint's segment during execution,
 341 you may set a breakpoint to GetVersion16/32 as those functions are called
 342 very often.
 343 Then do a "c" until you are able to set this breakpoint without error message.
 344
 345 d) Some useful programs:
 346 IDA: ftp://ftp.uni-koeln.de/pc/msdos/programming/assembler/ida35bx.zip
 347 *Very* good DOS disassembler ! It's badly needed for debugging Wine sometimes.
 348
 349 XRAY: ftp://ftp.th-darmstadt.de/pub/machines/ms-dos/SimTel/msdos/asmutil/xray15.zip
 350 Traces DOS calls (Int 21h, DPMI, ...). Use it with Windows to correct
 351 file management problems etc.
 352
 353 pedump: http://oak.oakland.edu/pub/simtelnet/win95/prog/pedump.zip
 354 Dumps the imports and exports of a PE (Portable Executable) DLL.
 355
 356
 357 Some basic debugger usages:
 358 ===========================
 359
 360 After starting you program with
 361   wine -debug myprog.exe
 362 the program loads and you get a prompt at the program starting point.
 363 Then you can set breakpoints:
 364   b RoutineName      (by outine name) OR
 365   b *0x812575        (by address)
 366 Then you hit 'c' (continue) to run the program. It stops at
 367 the breakpoint. You can type
 368   step               (to step one line) OR
 369   stepi              (to step one machine instruction at a time;
 370                       here, it helps to know the basic 386
 371                       instruction set)
 372   info reg           (to see registers)
 373   info stack         (to see hex values in the stack)
 374   info local         (to see local variables)
 375   list <line number> (to list source code)
 376   x <variable name>  (to examine a variable; only works if code
 377                       is not compiled with optimization)
 378   x 0x4269978        (to examine a memory location)
 379   ?                  (help)
 380   q                  (quit)
 381 By hitting Enter, you repeat the last command.