documentation/debugging

   1 This file describes where to start debugging Wine and how to write
   2 useful bug reports.
   3
   4 Crashes
   5 =======
   6
   7   These usually show up like this:
   8
   9 |Unexpected Windows program segfault - opcode = 8b
  10 |Segmentation fault in Windows program 1b7:c41.
  11 |Reading symbols from file /root/wine/wine.sym
  12 |In 16 bit mode.
  13 |Register dump:
  14 | CS:01b7 SS:016f DS:0287 ES:0000
  15 | IP:0c41 SP:878a BP:8796 FLAGS:0246
  16 | AX:811e BX:0000 CX:0000 DX:0000 SI:0001 DI:ffff
  17 |Stack dump:
  18 |0x016f:0x878a:  0001 016f ffed 0000 0000 0287 890b 1e5b
  19 |0x016f:0x879a:  01b7 0001 000d 1050 08b7 016f 0001 000d
  20 |0x016f:0x87aa:  000a 0003 0004 0000 0007 0007 0190 0000
  21 |0x016f:0x87ba:
  22 |
  23 |0050: sel=0287 base=40211d30 limit=0b93f (bytes) 16-bit rw-
  24 |Backtrace:
  25 |0 0x01b7:0x0c41 (PXSRV.FONGETFACENAME+0x7c)
  26 |1 0x01b7:0x1e5b (PXSRV.FONPUTCATFONT+0x2cd)
  27 |2 0x01a7:0x05aa
  28 |3 0x01b7:0x0768 (PXSRV.FONINITFONTS+0x81)
  29 |4 0x014f:0x03ed (PDOXWIN.@SQLCURCB$Q6CBTYPEULN8CBSCTYPE+0x1b1)
  30 |5 0x013f:0x00ac
  31 |
  32 |0x01b7:0x0c41 (PXSRV.FONGETFACENAME+0x7c):  movw        %es:0x38(%bx),%dx
  33
  34 Steps to debug a crash. You may stop at any step, but please report the bug
  35 and provide as much of the information gathered to the newsgroup or the
  36 relevant developer as feasonable.
  37
  38  1. Get the reason for the crash. This is usually an access to an invalid
  39     selector, an access to an out of range address in a valid selector,
  40     popping a segmentregister from the stack or the like. When reporting a
  41     crash, report this WHOLE crashdump even if it doesn't make sense to you.
  42
  43     (In this case it is access to an invalid selector, for %es is 0000, as
  44     seen in the register dump).
  45
  46  2. Determine where the reason came from.
  47     Since this is usually a primary/secondary reaction to a failed or
  48     misbehaving Wine function, rerun Wine with "-debugmsg +relay" (without ")
  49     added to the commandline. This will get rather much output, but usually
  50     the reason is located in the last call(s).  Those lines usually look like
  51     this:
  52
  53 |Call KERNEL.90: LSTRLEN(0227:0692) ret=01e7:2ce7 ds=0227
  54       ^^^^^^^^^  ^       ^^^^^^^^^      ^^^^^^^^^    ^^^^
  55       |          |       |              |            |Datasegment on entry
  56       |          |       |              |Return address.
  57       |          |       |
  58       |          |       |Argument(s). This one is a win16 segmented pointer.
  59       |          |Function called.
  60       |The module, the function is called in. In this case it is KERNEL.
  61
  62 |Ret  KERNEL.90: LSTRLEN() retval=0x0007 ret=01e7:2ce7 ds=0227
  63                                   ^^^^^^
  64                                   |Returnvalue is 16 bit and has the value 7.
  65
  66
  67  3. If you have found a misbehaving function, try to find out why it
  68     misbehaves. Find the function in the source code. Try to make sense of
  69     the arguments passed. Usually there is a
  70     "dprintf_xyz(stddeb,"Fnction(...)"...);" at the beginning of the
  71     function. Rerun wine with "-debugmsg +xyz,+relay" added to the
  72     commandline.
  73
  74  4. If the crash happened in a function in WINE, find out the exact line using
  75     gdb (the sample crash has another reason):
  76 |... somewhere in the backtrace ...
  77 |5 0x080e5ad8 (CreateWindowEx32A+0xd8)
  78 |...
  79 |$ gdb wine
  80 |...
  81 |(gdb) l *0x080e5ad8
  82 |0x80e5ad8 is in CreateWindowEx32A (win.c:837).
  83 |...
  84 |837         return WIN_CreateWindowEx( &cs, classAtom, FALSE );
  85 |...
  86
  87
  88  5. If those information isn't clear enough or if you want to know more about
  89     what's happening in the function itself, try running wine with "-debugmsg
  90     +all", which dumps ALL included debug information in wine.
  91
  92  6. If that isn't enough add more debug output for yourself into the
  93     functions you find relevant.
  94     You might also try to run the program in gdb instead of using the
  95     WINE-debugger.
  96
  97  7. You can also set a breakpoint for that function. Start wine with the
  98     "-debug" option added to the commandline. After loading the executable
  99     wine will enter the internal debugger. Use "break KERNEL.LSTRLEN"
 100     (replace by function you want to debug, CASE IS RELEVANT.) to set a
 101     breakpoint.  Then use "continue" to start normal program-execution. Wine
 102     will stop if it reaches the breakpoint. If the program isn't yet at the
 103     crashing call of that function, use "continue" again until you are about
 104     to enter that function. You may now proceed with single-stepping the
 105     function until you reach the point of crash. Use the other debugger
 106     commands to print registers and the like.
 107
 108
 109 Program hangs, nothing happens
 110 ==============================
 111
 112   Switch to UNIX shell, get the process-ID using "ps -a|grep wine", and do a
 113   "kill -HUP <pid>" (without " and <>). Wine will then enter its internal
 114   debugger and you can proceed as explained above.
 115
 116 Program reports an error with a Messagebox
 117 ==========================================
 118
 119   Sometimes programs are reporting failure using a more or less nondescript
 120   messageboxes. We can debug this using the same method as Crashes, but there
 121   is one problem... For setting up a message box the program also calls Wine
 122   producing huge chunks of debug code.
 123
 124   Since the failure happens usually directly before setting up the Messagebox
 125   you can start wine with "-debug" added to the commandline, set a breakpoint
 126   at "USER.MESSAGEBOX" (win16 programs) "USER32.MessageBox" (win32 Programs)
 127   and proceed with "continue". With "-debugmsg +all" Wine will now stop
 128   directly directly before setting up the Messagebox.  Proceed as explained
 129   above.
 130
 131
 132 Disassembling programs:
 133 =======================
 134   You may also try to disassemble the offending program to check for
 135   undocumented features and/or use of them.
 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   Disassembling win32 programs is currenty only possible using
 140   Windows Disassembler 32, archivename something like wdasm32x.zip on
 141   ftp.winsite.com and mirrors.
 142   Understanding disassembled code is just a question of exercise.
 143   Most code out there uses standard C function entries (for it is usually
 144   written in C). Win16 function entries usually look like that:
 145 |       push bp
 146 |       mov bp, sp
 147 |       ... function code ..
 148 |       retf XXXX       <--------- XXXX is number of bytes of arguments
 149
 150   This is a FAR function with no local storage. The arguments usually start
 151   at [bp+6] with increasing offsets. Note, that [bp+6] belongs to the RIGHTMOST
 152   argument, for exported win16 functions use the PASCAL calling convention.
 153   So, if we use strcmp(a,b) with a and b both 32 bit variables b would be at
 154   [bp+6] and a at [bp+10].
 155   Most functions make also use of local storage in the stackframe:
 156 |       enter 0086, 00
 157 |       ... function code ...
 158 |       leave
 159 |       retf XXXX
 160   This does mostly the same as above, but also adds 0x86 bytes of
 161   stackstorage, which is accessed using [bp-xx].
 162   Before calling a function, arguments are pushed on the stack using something
 163   like this:
 164 |       push word ptr [bp-02]   <- will be at [bp+8]
 165 |       push di                 <- will be at [bp+6]
 166 |       call KERNEL.LSTRLEN
 167   Here first the selector and then the offset to the passed string are pushed.
 168
 169
 170 Sample debugging session:
 171 =========================
 172
 173   Let's debug the infamous Word SHARE.EXE messagebox:
 174
 175 |marcus@jet $ wine winword.exe
 176 |            +---------------------------------------------+
 177 |            | !  You must leave Windows and load SHARE.EXE|
 178 |            |    before starting Word.                    |
 179 |            +---------------------------------------------+
 180
 181
 182 |marcus@jet $ wine winword.exe -debugmsg +relay -debug
 183 |CallTo32(func=08007e00,000001c4,00000081,00000000,00000000)
 184 |CallTo32(func=08007e00,000001c4,00000014,000006d0,00000000)
 185 |Win16 task 'winword': Breakpoint 1 at 0x0157:0x001a
 186 |CallTo16(func=0097:0130,ds=0000)
 187 |Call WPROCS.24: TASK_RESCHEDULE() ret=003f:0759 ds=0000
 188 |Ret  WPROCS.24: TASK_RESCHEDULE() retval=0x0000 ret=003f:0759 ds=08a7
 189 |CallTo16(func=0157:001a,ds=08a7,0x11d7,0x0000,0x0000,0x3cb4,0x1f40,0x0000,0x0000,0x08a7)
 190 |Reading symbols from file /root/wine/wine.sym
 191 |Stopped on breakpoint 1 at 0x0157:0x001a
 192 |In 16 bit mode.
 193 |0x0157:0x001a:  xorw   %bp,%bp
 194 |Wine-dbg> break USER.MESSAGEBOX                       <---- Set Breakpoint
 195 |Breakpoint 2 at 0x0067:0x00000000 (USER.MESSAGEBOX)
 196 |Wine-dbg>c                                            <---- Continue
 197 |Call KERNEL.91: INITTASK() ret=0157:0022 ds=08a7
 198 |     AX=0000 BX=3cb4 CX=1f40 DX=0000 SI=0000 DI=08a7 ES=11d7 EFL=00000286
 199 |CallTo16(func=090f:085c,ds=0dcf,0x0000,0x0000,0x0000,0x0000,0x0800,0x0000,0x0000,0x0dcf)
 200 |...                                                   <----- Much debugoutput
 201 |Call KERNEL.97: GETTEMPFILENAME(0x00c3,08a7:8350,0x0000,08a7:8234) ret=058f:09b1 ds=08a7
 202                                  ^      ^         ^      ^
 203                                  |      |         |      |LPSTR buffer
 204                                  |      |         |UINT16 unique
 205                                  |      |LPCSTR prefix
 206                                  |BYTE drive
 207
 208 |Ret  KERNEL.97: GETTEMPFILENAME() retval=0xce3f ret=058f:09b1 ds=08a7
 209                                           ^
 210                                           |new unique number
 211
 212 |Call KERNEL.74: OPENFILE(08a7:8234,08a7:82c6,0x1012) ret=058f:09d8 ds=08a7
 213                           ^         ^         ^
 214                           |         |         |UINT32 mode
 215                           |         |OFSTRUCT *ofs
 216                           |LPCSTR name
 217
 218 |Ret  KERNEL.74: OPENFILE() retval=0xffff ret=058f:09d8 ds=08a7
 219                                    ^
 220                                    | -1 aka. HFILE_ERROR
 221
 222 |Stopped on breakpoint 2 at 0x0067:0x00000000 (USER.MESSAGEBOX)
 223 |In 32 bit mode.
 224 |0x0067:0x00000000 (USER.MESSAGEBOX):  pushw    %bp
 225
 226     Now, we see that OPENFILE seem to have returned 0xFFFF (or -1). Checking
 227     the implementation of OpenFile in files/file.c, this signals an error.
 228     The mode flags (OF_READWRITE|OF_SHARE_EXCLUSIVE|OF_CREATE) seems to
 229     indicate, that WinWord wants to open the file for writing, so we check
 230     the filename. Since we don't see the filename in this debugoutput, we use
 231     the dprintf_file() in OpenFile to print out more information by adding
 232     "-debugmsg +relay" to the commandline.
 233
 234     (In fact, we see that the filename has been returned by the GetTempFileName
 235      function above, but we check it anyway.)
 236
 237 |marcus@jet $ wine winword.exe -debugmsg +relay,+file -debug
 238 |.....much more debugoutput .....
 239 |
 240 |Call KERNEL.97: GETTEMPFILENAME(0x00c3,08a7:8350,0x0000,08a7:8234) ret=058f:09b1 ds=08a7
 241 |FILE_Create: 'C:~docd03d.tmp' 01b6 1
 242 |FILE_SetDosError: errno = 13
 243 |GetTempFileName: returning C:\~DOCD03D.TMP
 244 |Ret  KERNEL.97: GETTEMPFILENAME() retval=0xd03d ret=058f:09b1 ds=08a7
 245 |Call KERNEL.74: OPENFILE(08a7:8234,08a7:82c6,0x1012) ret=058f:09d8 ds=08a7
 246 |OpenFile: C:\~DOCD03D.TMP 1012
 247 |FILE_AllocTaskHandle: returning task handle 1, dos_file 0, file 1 of 254
 248 |FILE_Create: 'C:\~DOCD03D.TMP' 01b6 0
 249 |FILE_SetDosError: errno = 13
 250 |OpenFile(C:\~DOCD03D.TMP): return = HFILE_ERROR
 251 |FILE_FreeTaskHandle: dos=1 file=0
 252 |Ret  KERNEL.74: OPENFILE() retval=0xffff ret=058f:09d8 ds=08a7
 253
 254     The filename is "C:\~DOCD03D.TMP". Of course, C:\ is writeable for the
 255     superuser only, so the open fails for a normal user and OpenFile returns
 256     -1, which in turn generates this messagebox.
 257
 258
 259 Written by Marcus Meissner <msmeissn@cip.informatik.uni-erlangen.de>,
 260 additions welcome.