Debugging Wine
Debug Messages
written by Dimitrie O. Paun dimi@cs.toronto.edu, 28 Mar 1998
(Extracted from wine/documentation/debug-msgs)
The new debugging interface can be considered to be
stable, with the exception of the in-memory message
construction functions. However, there is still a lot of
work to be done to polish things up. To make my life
easier, please follow the guidelines described in this
document.
Read this document before writing new code. DO NOT USE
fprintf (or
printf) to output things. Also, instead
of writing FIXMEs in the source, output a FIXME message if
you can.
At the end of the document, there is a "Style Guide" for
debugging messages. Please read it.
Debugging classes
There are 4 types (or classes) of debugging messages:
FIXME
Messages in this class relate to behavior of Wine that
does not correspond to standard Windows behavior and
that should be fixed.
Examples: stubs, semi-implemented features, etc.
ERR
Messages in this class relate to serious errors in
Wine. This sort of messages are close to asserts --
that is, you should output an error message when the
code detects a condition which should not happen. In
other words, important things that are not warnings
(see below), are errors.
Examples: unexpected change in internal state, etc.
WARN
These are warning messages. You should report a
warning when something unwanted happen but the
function behaves properly. That is, output a warning
when you encounter something unexpected (ex: could not
open a file) but the function deals correctly with the
situation (that is, according to the docs). If you do
not deal correctly with it, output a fixme.
Examples: fail to access a resource required by the
app, etc.
TRACE
These are detailed debugging messages that are mainly
useful to debug a component. These are usually turned
off.
Examples: everything else that does not fall in one of
the above mentioned categories and the user does not
need to know about it.
The user has the capability to turn on or off messages of a
particular type. You can expect the following patterns of
usage (but note that any combination is possible):
when you debug a component, all types
(TRACE, WARN,
ERR, FIXME) will
be enabled.
during the pre-alpha (maybe alpha) stage of Wine, most
likely the TRACE class will be
disabled by default, but all others
(WARN, ERR,
FIXME) will be enabled by default.
when Wine will become stable, most likely the
TRACE and WARN
classes will be disabled by default, but all
ERRs and FIXMEs
will be enabled.
in some installations that want the smallest footprint
and where the debug information is of no interest, all
classes may be disabled by default.
Of course, the user will have the runtime ability to
override these defaults. However, this ability may be turned
off and certain classes of messages may be completely
disabled at compile time to reduce the size of Wine.
Debugging channels
Also, we divide the debugging messages on a component basis.
Each component is assigned a debugging channel. The
identifier of the channel must be a valid C identifier but
note that it may also be a reserved word like
int or static.
Examples of debugging channels:
reg
updown
string
We will refer to a generic channel as xxx.
for those who know the old interface, the channel/type is
what followed the _ in the
dprintf_xxx statements. For example,
to output a message on the debugging channel
reg in the old interface you would had
to write:
dprintf_reg(stddeb, "Could not access key!\n");
In the new interface, we drop the
stddeb as it is implicit. However, we
add an orthogonal piece of information to the message: its
class. This is very important as it will allow us to
selectively turn on or off certain messages based on the
type of information they report. For this reason it is
essential to choose the right class for the message.
Anyhow, suppose we figured that this message should belong
in the WARN class, so in the new
interface, you write:
WARN(reg, "Could not access key!\n");
How to use it
So, to output a message (class YYY) on
channel xxx, do:
#include "debug.h"
....
YYY(xxx, "<message>", ...);
Some examples from the code:
#include "debug.h"
...
TRACE(crtdll, "CRTDLL_setbuf(file %p buf %p)", file, buf);
WARN(aspi, "Error opening device errno=%d", save_error);
If you need to declare a new debugging channel, use it in
your code and then do:
%tools/make_debug
in the root directory of Wine. Note that this will result in
almost complete recompilation of Wine.
Please pay attention to which class you assign the
message. There are only 4 classes, so it is not hard.
The reason it is important to get it right is that too
much information is no information. For example, if
you put things into the WARN class
that should really be in the TRACE
class, the output will be too big and this will force
the user to turn warnings off. But this way he will
fail to see the important ones. Also, if you put
warnings into the TRACE class lets
say, he will most likely miss those because usually
the TRACE class is turned off. A
similar argument can be made if you mix any other two
classes.
All lines should end with a newline. If you can NOT
output everything that you want in the line with only
one statement, then you need to build the string in
memory. Please read the section below "In-memory
messages" on the preferred way to do it. PLEASE USE
THAT INTERFACE TO BUILD MESSAGES IN MEMORY. The reason
is that we are not sure that we like it and having
everything in one format will facilitate the
(automatic) translation to a better interface.
Are we debugging?
To test whether the debugging output of class
yyy on channel xxx is
enabled, use:
TRACE_ON to test if TRACE is enabled
WARN_ON to test if WARN is enabled
FIXME_ON to test if FIXME is enabled
ERR_ON to test if ERR is enabled
Examples:
if(TRACE_ON(atom)){
...blah...
}
You should normally need to test only if
TRACE_ON. At present, none of the other
3 tests (except for ERR_ON which is
used only once!) are used in Wine.
In-memory messages
If you NEED to build the message from multiple calls, you
need to build it in memory. To do that, you should use the
following interface:
declare a string (where you are allowed to declare C
variables) as follows:
dbg_decl_str(name, len);
where name is the name of the
string (you should use the channel name on which you
are going to output it)
print in it with:
dsprintf(name, "<message>", ...);
which is just like a sprintf
function but instead of a C string as first parameter it
takes the name you used to declare it.
obtain a pointer to the string with: dbg_str(name)
reset the string (if you want to reuse it with):
dbg_reset_str(name);
Example (modified from the code):
void some_func(tabs)
{
INT32 i;
LPINT16 p = (LPINT16)tabs;
dbg_decl_str(listbox, 256); /* declare the string */
for (i = 0; i < descr->nb_tabs; i++) {
descr->tabs[i] = *p++<<1;
if(TRACING(listbox)) /* write in it only if
dsprintf(listbox, "%hd ", descr->tabs[i]); /* we are gonna output it */
}
TRACE(listbox, "Listbox %04x: settabstops %s",
wnd->hwndSelf, dbg_str(listbox)); /* output the whole thing */
}
If you need to use it two times in the same scope do like
this:
void some_func(tabs)
{
INT32 i;
LPINT16 p = (LPINT16)tabs;
dbg_decl_str(listbox, 256); /* declare the string */
for (i = 0; i < descr->nb_tabs; i++) {
descr->tabs[i] = *p++<<1;
if(TRACING(listbox)) /* write in it only if
dsprintf(listbox, "%hd ", descr->tabs[i]); /* we are gonna output it */
}
TRACE(listbox, "Listbox %04x: settabstops %s\n",
wnd->hwndSelf, dbg_str(listbox)); /* output the whole thing */
dbg_reset_str(listbox); /* !!!reset the string!!! */
for (i = 0; i < descr->extrainfo_nr; i++) {
descr->extrainfo = *p+1;
if(TRACING(listbox)) /* write in it only if
dsprintf(listbox,"%3d ",descr->extrainfo); /* we are gonna output it */
}
TRACE(listbox, "Listbox %04x: extrainfo %s\n",
wnd->hwndSelf, dbg_str(listbox)); /* output the whole thing */
}
As I already stated, I do not think this will be the
ultimate interface for building in-memory debugging
messages. In fact, I do have better ideas which I hope to
have time to implement for the next release. For this
reason, please try not to use it. However, if you need to
output a line in more than one
dprintf_xxx calls, then USE THIS
INTERFACE. DO NOT use other methods. This way, I will
easily translate everything to the new interface (when it
will become available). So, if you need to use it, then
follow the following guidelines:
wrap calls to dsprintf with a
if(YYY(xxx))
dsprintf(xxx,...);
Of course, if the call to
dsprintf is made from within a
function which you know is called only if
YYY(xxx) is true, for example if
you call it only like this:
if(YYY(xxx))
print_some_debug_info();
then you need not (and should not) wrap calls to
dsprintf with the before
mentioned if.
name the string EXACTLY like the debugging channel on
which is going to be output. Please see the above
example.
Resource identifiers
Resource identifiers can be either strings or numbers. To
make life a bit easier for outputting these beasts (and to
help you avoid the need to build the message in memory), I
introduced a new function called debugres.
The function is defined in debugstr.h
and has the following prototype:
LPSTR debugres(const void *id);
It takes a pointer to the resource id and returns a nicely
formatted string of the identifier. If the high word of the
pointer is 0, then it assumes that the
identifier is a number and thus returns a string of the
form:
#xxxx
where xxxx are 4 hex-digits representing
the low word of id.
If the high word of the pointer is not 0,
then it assumes that the identifier is a string and thus
returns a string of the form:
'<identifier>'
Thus, to use it, do something on the following lines:
#include "debug.h"
...
YYY(xxx, "resource is %s", debugres(myresource));
The --debugmsg command line option
So, the --debugmsg command line
option has been changed as follows:
the new syntax is: --debugmsg
[yyy]#xxx[,[yyy1]#xxx1]* where
# is either + or
-
when the optional class argument (yyy)
is not present, then the statement will
enable(+)/disable(-)
all messages for the given channel (xxx)
on all classes. For example:
--debugmsg +reg,-file
enables all messages on the reg
channel and disables all messages on the
file channel. This is same as the old
semantics.
when the optional class argument (yyy)
is present, then the statement will enable
(+)/disable(-)
messages for the given channel (xxx)
only on the given class. For example:
--debugmsg trace+reg,warn-file
enables trace messages on the reg
channel and disables warning messages on the
file channel.
also, the pseudo-channel all is also supported and it
has the intuitive semantics:
--debugmsg +all -- enables all debug messages
--debugmsg -all -- disables all debug messages
--debugmsg yyy+all -- enables debug messages for class yyy on all
channels.
--debugmsg yyy-all -- disables debug messages for class yyy on all
channels.
So, for example:
--debugmsg warn-all -- disables all warning messages.
Also, note that at the moment:
the FIXME and ERR
classes are enabled by default
the TRACE and
WARN classes are disabled by
default
Compiling Out Debugging Messages
To compile out the debugging messages, provide
configure with the following options:
--disable-debug -- turns off TRACE, WARN, and FIXME (and DUMP).
--disable-trace -- turns off TRACE only.
This will result in an executable that, when stripped, is
about 15%-20% smaller. Note, however, that you will not be
able to effectively debug Wine without these messages.
This feature has not been extensively tested--it may subtly
break some things.
A Few Notes on Style
This new scheme makes certain things more consistent but
there is still room for improvement by using a common style
of debug messages. Before I continue, let me note that the
output format is the following:
yyy:xxx:fff <message>
where:
yyy = the class (fixme, err, warn, trace)
xxx = the channel (atom, win, font, etc)
fff = the function name
these fields are output automatically. All you have to
provide is the <message> part.
So here are some ideas:
do NOT include the name of the function: it is included automatically
if you want to output the parameters of the function, do
it as the first thing and include them in parentheses,
like this:
YYY(xxx, "(%d,%p,etc)...\n", par1, par2, ...);
for stubs, you should output a FIXME
message. I suggest this style:
FIXME(xxx, "(%x,%d...): stub\n", par1, par2, ...);
That is, you output the parameters, then a : and then a string
containing the word "stub". I've seen "empty stub", and others, but I
think that just "stub" suffices.
output 1 and ONLY 1 line per message. That is, the format
string should contain only 1 \n and it
should always appear at the end of the string. (there are
many reasons for this requirement, one of them is that
each debug macro adds things to the beginning of the line)
if you want to name a value, use = and
NOT :. That is, instead of saying:
FIXME(xxx, "(fd: %d, file: %s): stub\n", fd, name);
say:
FIXME(xxx, "(fd=%d, file=%s): stub\n", fd, name);
use : to separate categories.
try to avoid the style:
FIXME(xxx, "(fd=%d, file=%s): stub\n", fd, name);
but use:
FIXME(xxx, "(fd=%d, file=%s): stub\n", fd, name);
The reason is that if you want to grep
for things, you would search for FIXME
but in the first case there is no additional information
available, where in the second one, there is (e.g. the word
stub)
if you output a string s that might contain control
characters, or if s may be
NULL, use
debugstr_a (for ASCII strings, or
debugstr_w for Unicode strings) to
convert s to a C string, like this:
HANDLE32 WINAPI YourFunc(LPCSTR s)
{
FIXME(xxx, "(%s): stub\n", debugstr_a(s));
}
if you want to output a resource identifier, use debugres to
convert it to a string first, like this:
HANDLE32 WINAPI YourFunc(LPCSTR res)
{
FIXME(xxx, "(res=%s): stub\n", debugres(s));
}
if the resource identifier is a SEGPTR, use
PTR_SEG_TO_LIN to get a
liner pointer first:
HRSRC16 WINAPI FindResource16( HMODULE16 hModule, SEGPTR name, SEGPTR type )
{
[...]
TRACE(resource, "module=%04x name=%s type=%s\n",
hModule, debugres(PTR_SEG_TO_LIN(name)),
debugres(PTR_SEG_TO_LIN(type)) );
[...]
}
for messages intended for the user (specifically those that
report errors in wine.conf), use the
MSG macro. Use it like a
printf:
MSG( "Definition of drive %d is incorrect!\n", drive );
However, note that there are very few
valid uses of this macro. Most messages are debugging
messages, so chances are you will not need to use this
macro. Grep the source to get an idea where it is
appropriate to use it.
For structure dumps, use the DUMP
macro. Use it like a printf, just like
the MSG macro. Similarly, there are only
a few valid uses of this macro. Grep the source to see when
to use it.
Using the Wine Debugger
written by Marcus Meissner msmeissn@cip.informatik.uni-erlangen.de,
additions welcome.
(Extracted from wine/documentation/debugging)
This file describes where to start debugging Wine. If at any
point you get stuck and want to ask for help, please read the
file documentation/bugreports for
information on how to write useful bug reports.
Crashes
These usually show up like this:
|Unexpected Windows program segfault - opcode = 8b
|Segmentation fault in Windows program 1b7:c41.
|Loading symbols from ELF file /root/wine/wine...
|....more Loading symbols from ...
|In 16 bit mode.
|Register dump:
| CS:01b7 SS:016f DS:0287 ES:0000
| IP:0c41 SP:878a BP:8796 FLAGS:0246
| AX:811e BX:0000 CX:0000 DX:0000 SI:0001 DI:ffff
|Stack dump:
|0x016f:0x878a: 0001 016f ffed 0000 0000 0287 890b 1e5b
|0x016f:0x879a: 01b7 0001 000d 1050 08b7 016f 0001 000d
|0x016f:0x87aa: 000a 0003 0004 0000 0007 0007 0190 0000
|0x016f:0x87ba:
|
|0050: sel=0287 base=40211d30 limit=0b93f (bytes) 16-bit rw-
|Backtrace:
|0 0x01b7:0x0c41 (PXSRV_FONGETFACENAME+0x7c)
|1 0x01b7:0x1e5b (PXSRV_FONPUTCATFONT+0x2cd)
|2 0x01a7:0x05aa
|3 0x01b7:0x0768 (PXSRV_FONINITFONTS+0x81)
|4 0x014f:0x03ed (PDOXWIN_@SQLCURCB$Q6CBTYPEULN8CBSCTYPE+0x1b1)
|5 0x013f:0x00ac
|
|0x01b7:0x0c41 (PXSRV_FONGETFACENAME+0x7c): movw %es:0x38(%bx),%dx
Steps to debug a crash. You may stop at any step, but please
report the bug and provide as much of the information
gathered to the newsgroup or the relevant developer as
feasible.
Get the reason for the crash. This is usually an access to
an invalid selector, an access to an out of range address
in a valid selector, popping a segmentregister from the
stack or the like. When reporting a crash, report this
whole crashdump even if it doesn't
make sense to you.
(In this case it is access to an invalid selector, for
%es is 0000, as
seen in the register dump).
Determine the cause of the crash. Since this is usually
a primary/secondary reaction to a failed or misbehaving
Wine function, rerun Wine with -debugmsg
+relay added to the commandline. This will
generate quite a lot of output, but usually the reason is
located in the last call(s). Those lines usually look like
this:
|Call KERNEL.90: LSTRLEN(0227:0692 "text") ret=01e7:2ce7 ds=0227
^^^^^^^^^ ^ ^^^^^^^^^ ^^^^^^ ^^^^^^^^^ ^^^^
| | | | | |Datasegment
| | | | |Return address
| | | |textual parameter
| | |
| | |Argument(s). This one is a win16 segmented pointer.
| |Function called.
|The module, the function is called in. In this case it is KERNEL.
|Ret KERNEL.90: LSTRLEN() retval=0x0004 ret=01e7:2ce7 ds=0227
^^^^^^
|Returnvalue is 16 bit and has the value 4.
If you have found a misbehaving function, try to find out
why it misbehaves. Find the function in the source code.
Try to make sense of the arguments passed. Usually there is
a TRACE(<channel>,"(...)\n"); at
the beginning of the function. Rerun wine with
-debugmsg +xyz,+relay added to the
commandline.
Additional information on how to debug using the internal
debugger can be found in
debugger/README.
If this information isn't clear enough or if you want to
know more about what's happening in the function itself,
try running wine with -debugmsg
+all, which dumps ALL included debug
information in wine.
If even that isn't enough, add more debug output for
yourself into the functions you find relevant. See
documentation/debug-msgs. You might
also try to run the program in gdb
instead of using the WINE-debugger. If you do that, use
handle SIGSEGV nostop noprint to
disable the handling of seg faults inside
gdb (needed for Win16). If you don't use
the --desktop or
--managed option, start the WINE
process with --sync, or chances are
good to get X into an unusable state.
You can also set a breakpoint for that function. Start wine
with the --debug option added to the
commandline. After loading the executable wine will enter
the internal debugger. Use break
KERNEL_LSTRLEN (replace by function you want
to debug, CASE IS RELEVANT) to set a breakpoint. Then use
continue to start normal
program-execution. Wine will stop if it reaches the
breakpoint. If the program isn't yet at the crashing call
of that function, use continue again
until you are about to enter that function. You may now
proceed with single-stepping the function until you reach
the point of crash. Use the other debugger commands to
print registers and the like.
Program hangs, nothing happens
Switch to UNIX shell, get the process-ID using ps -a |
grep wine, and do a kill -HUP
<pid> (without the < and >). Wine will
then enter its internal debugger and you can proceed as
explained above. Also, you can use
--debug switch and then you can get into
internal debugger by pressing
CtrlC in
the terminal where you run Wine.
Program reports an error with a Messagebox
Sometimes programs are reporting failure using more or
less nondescript messageboxes. We can debug this using the
same method as Crashes, but there is one problem... For
setting up a message box the program also calls Wine
producing huge chunks of debug code.
Since the failure happens usually directly before setting up
the Messagebox you can start wine with
--debug added to the commandline, set a
breakpoint at MessageBoxA (called by win16
and win32 programs) and proceed with
continue. With --debugmsg
+all Wine will now stop directly before setting
up the Messagebox. Proceed as explained above.
You can also run wine using wine -debugmsg +relay
program.exe 2>&1 | less -i and in
less search for MessageBox
.
Disassembling programs:
You may also try to disassemble the offending program to
check for undocumented features and/or use of them.
The best, freely available, disassembler for Win16 programs is
Windows Codeback, archivename
wcbxxx.zip, which usually can be found in
the Cica-Mirror subdirectory on the WINE
ftpsites. (See ANNOUNCE).
Disassembling win32 programs is possible using
Windows Disassembler 32, archivename
something like w32dsm87.zip (or similar)
on ftp.winsite.com
and mirrors. The shareware version does not allow saving of
disassembly listings. You can also use the newer (and in the
full version better) Interactive
Disassembler (IDA) from the ftp sites mentioned
at the end of the document. Understanding disassembled code is
mostly a question of exercise.
Most code out there uses standard C function entries (for it
is usually written in C). Win16 function entries usually
look like that:
push bp
mov bp, sp
... function code ..
retf XXXX <--------- XXXX is number of bytes of arguments
This is a FAR function with no local
storage. The arguments usually start at
[bp+6] with increasing offsets. Note, that
[bp+6] belongs to the
rightmost argument, for exported win16
functions use the PASCAL calling convention. So, if we use
strcmp(a,b) with a
and b both 32 bit variables
b would be at [bp+6]
and a at [bp+10].
Most functions make also use of local storage in the stackframe:
enter 0086, 00
... function code ...
leave
retf XXXX
This does mostly the same as above, but also adds
0x86 bytes of stackstorage, which is
accessed using [bp-xx]. Before calling a
function, arguments are pushed on the stack using something
like this:
push word ptr [bp-02] <- will be at [bp+8]
push di <- will be at [bp+6]
call KERNEL.LSTRLEN
Here first the selector and then the offset to the passed
string are pushed.
Sample debugging session:
Let's debug the infamous Word SHARE.EXE
messagebox:
|marcus@jet $ wine winword.exe
| +---------------------------------------------+
| | ! You must leave Windows and load SHARE.EXE|
| | before starting Word. |
| +---------------------------------------------+
|marcus@jet $ wine winword.exe -debugmsg +relay -debug
|CallTo32(wndproc=0x40065bc0,hwnd=000001ac,msg=00000081,wp=00000000,lp=00000000)
|Win16 task 'winword': Breakpoint 1 at 0x01d7:0x001a
|CallTo16(func=0127:0070,ds=0927)
|Call WPROCS.24: TASK_RESCHEDULE() ret=00b7:1456 ds=0927
|Ret WPROCS.24: TASK_RESCHEDULE() retval=0x8672 ret=00b7:1456 ds=0927
|CallTo16(func=01d7:001a,ds=0927)
| AX=0000 BX=3cb4 CX=1f40 DX=0000 SI=0000 DI=0927 BP=0000 ES=11f7
|Loading symbols: /home/marcus/wine/wine...
|Stopped on breakpoint 1 at 0x01d7:0x001a
|In 16 bit mode.
|Wine-dbg>break MessageBoxA <---- Set Breakpoint
|Breakpoint 2 at 0x40189100 (MessageBoxA [msgbox.c:190])
|Wine-dbg>c <---- Continue
|Call KERNEL.91: INITTASK() ret=0157:0022 ds=08a7
| AX=0000 BX=3cb4 CX=1f40 DX=0000 SI=0000 DI=08a7 ES=11d7 EFL=00000286
|CallTo16(func=090f:085c,ds=0dcf,0x0000,0x0000,0x0000,0x0000,0x0800,0x0000,0x0000,0x0dcf)
|... <----- Much debugoutput
|Call KERNEL.136: GETDRIVETYPE(0x0000) ret=060f:097b ds=0927
^^^^^^ Drive 0 (A:)
|Ret KERNEL.136: GETDRIVETYPE() retval=0x0002 ret=060f:097b ds=0927
^^^^^^ DRIVE_REMOVEABLE
(It is a floppy diskdrive.)
|Call KERNEL.136: GETDRIVETYPE(0x0001) ret=060f:097b ds=0927
^^^^^^ Drive 1 (B:)
|Ret KERNEL.136: GETDRIVETYPE() retval=0x0000 ret=060f:097b ds=0927
^^^^^^ DRIVE_CANNOTDETERMINE
(I don't have drive B: assigned)
|Call KERNEL.136: GETDRIVETYPE(0x0002) ret=060f:097b ds=0927
^^^^^^^ Drive 2 (C:)
|Ret KERNEL.136: GETDRIVETYPE() retval=0x0003 ret=060f:097b ds=0927
^^^^^^ DRIVE_FIXED
(specified as a harddisk)
|Call KERNEL.97: GETTEMPFILENAME(0x00c3,0x09278364"doc",0x0000,0927:8248) ret=060f:09b1 ds=0927
^^^^^^ ^^^^^ ^^^^^^^^^
| | |buffer for fname
| |temporary name ~docXXXX.tmp
|Force use of Drive C:.
|Warning: GetTempFileName returns 'C:~doc9281.tmp', which doesn't seem to be writeable.
|Please check your configuration file if this generates a failure.
Whoops, it even detects that something is wrong!
|Ret KERNEL.97: GETTEMPFILENAME() retval=0x9281 ret=060f:09b1 ds=0927
^^^^^^ Temporary storage ID
|Call KERNEL.74: OPENFILE(0x09278248"C:~doc9281.tmp",0927:82da,0x1012) ret=060f:09d8 ds=0927
^^^^^^^^^^^^^^^^ ^^^^^^^^^ ^^^^^^^
|filename |OFSTRUCT |open mode:
OF_CREATE|OF_SHARE_EXCLUSIVE|OF_READWRITE
This fails, since my C: drive is in
this case mounted readonly.
|Ret KERNEL.74: OPENFILE() retval=0xffff ret=060f:09d8 ds=0927
^^^^^^ HFILE_ERROR16, yes, it failed.
|Call USER.1: MESSAGEBOX(0x0000,0x09278376"Sie mussen Windows verlassen und SHARE.EXE laden bevor Sie Word starten.",0x00000000,0x1030) ret=060f:084f ds=0927
And MessageBox'ed.
|Stopped on breakpoint 2 at 0x40189100 (MessageBoxA [msgbox.c:190])
|190 { <- the sourceline
In 32 bit mode.
Wine-dbg>
The code seems to find a writeable harddisk and tries to create
a file there. To work around this bug, you can define
C: as a networkdrive, which is ignored
by the code above.
Debugging Tips
Here are some useful debugging tips, added by Andreas Mohr:
If you have a program crashing at such an early loader phase that you can't
use the Wine debugger normally, but Wine already executes the program's
start code, then you may use a special trick. You should do a
wine --debugmsg +relay program
to get a listing of the functions the program calls in its start function.
Now you do a
wine --debug winfile.exe
This way, you get into Wine-dbg. Now you
can set a breakpoint on any function the program calls in
the start function and just type c
to bypass the eventual calls of Winfile to this function
until you are finally at the place where this function gets
called by the crashing start function. Now you can proceed
with your debugging as usual.
If you try to run a program and it quits after showing an error messagebox,
the problem can usually be identified in the return value of one of the
functions executed before MessageBox().
That's why you should re-run the program with e.g.
wine --debugmsg +relay <program name> &>relmsg
Then do a more relmsg and search for the
last occurrence of a call to the string "MESSAGEBOX". This is a line like
Call USER.1: MESSAGEBOX(0x0000,0x01ff1246 "Runtime error 219 at 0004:1056.",0x00000000,0x1010) ret=01f7:2160 ds=01ff
In my example the lines before the call to
MessageBox() look like that:
Call KERNEL.96: FREELIBRARY(0x0347) ret=01cf:1033 ds=01ff
CallTo16(func=033f:0072,ds=01ff,0x0000)
Ret KERNEL.96: FREELIBRARY() retval=0x0001 ret=01cf:1033 ds=01ff
Call KERNEL.96: FREELIBRARY(0x036f) ret=01cf:1043 ds=01ff
CallTo16(func=0367:0072,ds=01ff,0x0000)
Ret KERNEL.96: FREELIBRARY() retval=0x0001 ret=01cf:1043 ds=01ff
Call KERNEL.96: FREELIBRARY(0x031f) ret=01cf:105c ds=01ff
CallTo16(func=0317:0072,ds=01ff,0x0000)
Ret KERNEL.96: FREELIBRARY() retval=0x0001 ret=01cf:105c ds=01ff
Call USER.171: WINHELP(0x02ac,0x01ff05b4 "COMET.HLP",0x0002,0x00000000) ret=01cf:1070 ds=01ff
CallTo16(func=0117:0080,ds=01ff)
Call WPROCS.24: TASK_RESCHEDULE() ret=00a7:0a2d ds=002b
Ret WPROCS.24: TASK_RESCHEDULE() retval=0x0000 ret=00a7:0a2d ds=002b
Ret USER.171: WINHELP() retval=0x0001 ret=01cf:1070 ds=01ff
Call KERNEL.96: FREELIBRARY(0x01be) ret=01df:3e29 ds=01ff
Ret KERNEL.96: FREELIBRARY() retval=0x0000 ret=01df:3e29 ds=01ff
Call KERNEL.52: FREEPROCINSTANCE(0x02cf00ba) ret=01f7:1460 ds=01ff
Ret KERNEL.52: FREEPROCINSTANCE() retval=0x0001 ret=01f7:1460 ds=01ff
Call USER.1: MESSAGEBOX(0x0000,0x01ff1246 "Runtime error 219 at 0004:1056.",0x00000000,0x1010) ret=01f7:2160 ds=01ff
I think that the call to MessageBox()
in this example is not caused by a
wrong result value of some previously executed function
(it's happening quite often like that), but instead the
messagebox complains about a runtime error at
0x0004:0x1056.
As the segment value of the address is only
4, I think that that is only an internal
program value. But the offset address reveals something
quite interesting: Offset 1056 is
very close to the return address of
FREELIBRARY():
Call KERNEL.96: FREELIBRARY(0x031f) ret=01cf:105c ds=01ff
^^^^
Provided that segment 0x0004 is indeed segment
0x1cf, we now we can use IDA (available at
ftp://ftp.uni-koeln.de/pc/msdos/programming/assembler/ida35bx.zip) to
disassemble the part that caused the error. We just have to find the address of
the call to FreeLibrary(). Some lines before that the
runtime error occurred. But be careful! In some cases you don't have to
disassemble the main program, but instead some DLL called by it in order to find
the correct place where the runtime error occurred. That can be determined by
finding the origin of the segment value (in this case 0x1cf).
If you have created a relay file of some crashing
program and want to set a breakpoint at a certain
location which is not yet available as the program loads
the breakpoint's segment during execution, you may set a
breakpoint to GetVersion16/32 as
those functions are called very often.
Then do a c until you are able to
set this breakpoint without error message.
Some useful programs:
IDA:
ftp://ftp.uni-koeln.de/pc/msdos/programming/assembler/ida35bx.zip
*Very* good DOS disassembler ! It's badly needed
for debugging Wine sometimes.
XRAY:
ftp://ftp.th-darmstadt.de/pub/machines/ms-dos/SimTel/msdos/asmutil/xray15.zip
Traces DOS calls (Int 21h, DPMI, ...). Use it with
Windows to correct file management problems etc.
pedump:
http://oak.oakland.edu/pub/simtelnet/win95/prog/pedump.zip
Dumps the imports and exports of a PE (Portable
Executable) DLL.
Some basic debugger usages:
After starting your program with
wine -debug myprog.exe
the program loads and you get a prompt at the program
starting point. Then you can set breakpoints:
b RoutineName (by outine name) OR
b *0x812575 (by address)
Then you hit c (continue) to run the
program. It stops at the breakpoint. You can type
step (to step one line) OR
stepi (to step one machine instruction at a time;
here, it helps to know the basic 386
instruction set)
info reg (to see registers)
info stack (to see hex values in the stack)
info local (to see local variables)
list <line number> (to list source code)
x <variable name> (to examine a variable; only works if code
is not compiled with optimization)
x 0x4269978 (to examine a memory location)
? (help)
q (quit)
By hitting Enter, you repeat the last
command.
How to do regression testing using Cvs
written by Gerard Patel (???)
(Extracted from wine/documentation/bugreports)
A problem that can happen sometimes is 'it used to work
before, now it doesn't anymore...'. Here is a step by step
procedure to try to pinpoint when the problem occured. This is
*NOT* for casual users.
Get the 'full cvs' archive from winehq. This archive is
the cvs tree but with the tags controling the versioning
system. It's a big file (> 15 meg) with a name like
full-cvs-<last update date> (it's more than 100mb
when uncompressed, you can't very well do this with
small, old computers or slow Internet connections).
untar it into a repository directory:
cd /home/gerard
tar -zxffull-cvs-2000-05-20.tar.gz
mv wine repository
extract a new destination directory. This directory must
not be in a subdirectory of the repository else
cvs will think it's part of the
repository and deny you an extraction in the repository:
cd /home/gerard
mv wine wine_current (-> this protects your current wine sandbox, if any)
export CVSROOT=/home/gerard/repository
cd /home/gerard
cvs -d $CVSROOT checkout wine
Note that it's not possible to do a checkout at a given
date; you always do the checkout for the last date where
the full-cvs-xxx snapshot was generated.
you will have now in the ~/wine
directory an image of the cvs tree, on the client side.
Now update this image to the date you want:
cd /home/gerard/wine
cvs -d $CVSROOT update -D "1999-06-01"
The date format is YYYY-MM-DD.
Many messages will inform you that more recent files have
been deleted to set back the client cvs tree to the date
you asked, for example:
cvs update: tsx11/ts_xf86dga2.c is no longer in the repository
cvs update is not limited to upgrade to
a *newer* version as I have believed for far too long :-(
Now proceed as for a normal update:
./configure
make depend && make
When you have found the exact date when a bug was added to
the cvs tree, use something like :
cvs -d $CVSROOT diff -D "1999-07-10" -D "1999-07-12"
to get all the differences between the last cvs tree
version known to work and code that first displayed the
misbehavior.
I did not include flags for diff
since they are in my .cvsrc file:
cvs -z 3
update -dPA
diff -u
From this diff file, particularly the file names, and the
ChangeLog, it's usually possible to
find the different individual patches that were done at
this time.
If any non-programmer reads this, the fastest method to get
at the point where the problem occured is to use a binary
search, that is, if the problem occured in 1999, start at
mid-year, then is the problem is already here, back to 1st
April, if not, to 1st October, and so on.
The next step is to start from the last working version
and to dig the individual contributions from
http://www.integrita.com/cgi-local/lwgate.pl/WINE-PATCHES/
(where the Wine patches mailing list is archived)
If the patch was done by the Wine maintainer or if it was
sent directly to his mail address without going first through
wine-patches,
you are out of luck as you will never find the patch in
the archive. If it is, it's often possible to apply the
patches one by one to last working cvs snapshot, compile and test.
If you have saved the next candidate as
/home/gerard/buggedpatch1.txt:
cd /home/gerard/wine
patch -p 0 < /home/gerard/buggedpatch1.txt
Beware that the committed patch is not always identical to
the patch that the author sent to wine-patches, as
sometimes the Wine maintainer changes things a bit.
If you find one patch that is getting the cvs source tree to
reproduce the problem, you have almost won; post the problem on
comp.emulators.windows.wine and there
is a chance that the author will jump in to suggest a fix; or
there is always the possibility to look hard at the patch until
it is coerced to reveal where is the bug :-)