Debugging Wine

From Wine-Wiki.org
Jump to: navigation, search
This article is part of the HOWTO series.
Installing Wine Business Games Internet Multimedia System and Utilities
Education Other


Warning: This HOWTO comes with no explicit or implicit warranty whatsoever. Use at you own risk!



Contents

Introduction

Wine has good provisions for debugging to help you get going, but often it is just a case of not knowing where to start and sometimes you need a little hand to get going. List suggestions and ideas here. First of all, get the debugging version of wine, as some versions of wine supplied have the parts that help debugging removed. You can often find these as they are called wine-dbg or wine-devel in your package manager, though you may need to enable the repository with these. Not to worry, as you can always compile wine yourself and this will automatically include these. This is surprisingly easy, if you check the error messages and install the programs that you are informed are necessary.

This page focusses on obtaining and reading traces.

When your program doesnt work, P. Troller explains your first steps [Nov 05]:

  1. Start the program from a shell and look for the console output. Normally there are many warnings about function stubs and other, not every message is fatal but some of them may indicate the problem. However, for example when a wine debugger is started, it's a serious problem somewhere and the console output is the most valuable thing.
  2. [When filling out a bugzilla report or posting to the mailing list,] What does (or doesn't) the program do ? be specific:
    • It even doesn't open its initial window.
    • It opens the window but crashes/freezes later.
    • It performs some basic interaction with an user but is otherwise unusable (describe why, what's wrong)
    • It almost works but something serious disables its regular usage (unable to save its results etc.) wine archive

Occasionally when trying to debug wine, the wine crash information dialog box keeps appearing and if you are trying to concentrate on finding the fix, you can turn it off. (If you were just trying to run the software, you must file a bug if you want it fixed - please think of all those other users. Mum, Dad and Grandma are rarely up to the task of editing the registry so telling them about it does not help either. Help developers find and then fix the real bug).

Winehq Bugzilla entry 18645 H. Verbeet: You can add a DWORD value HKCU\Software\Wine\WineDbg\ShowCrashDialog with value 0 in the registry. (You can also find that at http://wiki.winehq.org/UsefulRegistryKeys).

Four Different Debugging Messages

To Start debugging your application we will need to explain a little about the debugging messages you see when running via a console:

Compiled from Wine User documentation 4.5.1. http://www.winehq.org/docs/wine-user.html#AEN1826 and Wine Developer Documention http://www.winehq.org/docs/wine-devel.html#DBG-CLASSES


The four types of debugging messages are: trace, fixme, warn, err.


Currently:

When you are trying to debug wine, often you dont want every message that can be output, (which can often be a huge list, difficult to understand, and make your program slow to a crawl). Usually you will want to see only the messages for a particular channel that applies to your debugging problem. The most prolific would be the debug channel, 'relay' which spits out a log message every time a win32 function is called, and 'win' which tracks windows message passing, and of the biggest is of course 'all' which outputs every single debug channel that exists.

V. Beron explained about the difference between relay an trace: relay and trace are two different things: relay is a debug channel dumping info at each (or almost) function call, while trace is a class of debug statements shown only when asked. relay is in the same league as dll, file, opengl, while trace is in the same league as fixme, err and message. Wine Archive Link

J. Lang highlighted an easy mistake with trace: [If using trace, it should be] WINEDEBUG=trace or WINEDEBUG=trace+all. I think +trace will have no effect, as trace isn't the name of a debug channel.May05 Wine Archive Link However Winehq Bugzilla entry 17467 feb 09 notes that +all is never usefull, start a bug report with attaching a back trace. [and try and provide a more targetted trace - some examples are provided in this wiki]

Demonstrating Debugging Traces

For example to check all the four messages (FIXME,ERR,WARN,TRACE) in the debug channel heap you could use this

WINEDEBUG=heap wine program_name

Howerver you may want to look only at the warn messages (WARN) in the debug channel heap, you could invoke wine like this:

WINEDEBUG=warn+heap wine program_name

And to hide the warn messages (so as to look at others) you would type

WINEDEBUG=warn-heap program_name

NOTE: WINEDEBUG options are case sensitive.

Another good Tutorial of using the Debug Channels to track down a bug is Wine Developer Wiki:Debugging Wild Metal Country

Watch out for when you use a '-' and '+'. To turn off the output use '-', wherease '+' turns the debugging traces on. This easy mistake was noted by: J. Hawkins [Dec 05]: You put 'trace-all' and 'fixme-all' so none of the traces or fixmes will show up in the output. [he then gave an example using +] WINEDEBUG="trace+all,warn+all,fixme+all" wine [wine archive http://www.winehq.org/pipermail/wine-users/2005-December/020048.html]

Faster debugging

Redirecting output

Often when running with traces on, the program slows to a crawl. You can often speed this up by redirecting the trace to a file. eg:

H. Verbeet: you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course.[this avoids some problems with traces]


A user suggested:WINEDEBUG=+ddraw,+d3d7 wine [myprogramname].exe > mywinelog Another suggested: it should be "> filename 2>&1" not only "> filename", as without "2>&1" only standard output, not standard error is written to the file.

M. Owens: It's 'command &> file' to take both the STDOUT and STDERR into a file. seems a bit messy to do 'command > file 2> &1' wine archive


O. Leidinger: As [these] files tend to become huge [when providing logs for bugzilla], it'd be good to extract only the last 1000 or 10000 lines (whatever is needed to see what's wrong). You can do this via

tail test.log -n 1000 > test2.log

and compress the output via bzip2

bzip2 test2.log

Or as one-liner

tail test.log -n 1000 | bzip2 > test2.log.bz2


A user wrote in Winehq Bugzilla entry 19443 there is a message which was printed in the terminal but did not get dumped into the file despite the &> redirection [-] that message reads simply "Segmentation fault".

V. Margolen: [Jul 09] Enable core dumping (ulimit -c unlimited) and make it crash again. Then load that core file under gdb (gdb core) and get the backtrace (bt).


Sometimes when reading the log it seems that the lines are corrupted. [Jan 10winedev] H. Verbeet: The problem isn't the file being overwritten, it's multiple threads writing (mostly unsynchronized) to the same file. Vitamin dec 10: It can't be fixed because separate threads can and do run in parallel, especially on multicore systems. Unless of course you want to break that and make Wine single-threaded, single-process beast. Or overcomplicate logging infrastructure to make it highly inefficient, slow, and prone to dead-locks.


M. Stefaniuc: The "overwrite" corruption is fixed by using ">>". So yes, when writting to a log file redirecting with ">>" is better. A. Julliard: Wine explicitly uses write(2) for debug output, and is careful about writing only complete lines precisely to avoid the interleaving issue. It does require O_APPEND to ensure that the writes don't step over each other, which is why you need ">>". It definitely makes a difference.

Winehq Bugzilla entry 21636 has an example of how to do this [of course replace the executable called MJ12node.ex with your program]:

WINEDEBUG=+tid,+seh,+relay wine MJ12node.exe >>log.txt 2&>1

Redirecting - What is it doing

A user asked jan 09:what is the meaning of the 2>&1 on the winedebug command line?

A. English: It redirects all terminal output to wherever STDOUT is going. More specifically

2 = STDERR
1 = STDOUT
> = redirect
& = and

so you're saying: redirect STDERR (2) to the same place as STDOUT (1)

Mac dual Core problems 2009

A bug was raised in 2009 about a Mac which had corrupted log files. A. Julliard: That's a kernel race. You can avoid it by redirecting in append mode (2>>logfile).Winehq Bugzilla entry 19125

Understanding and reading Debugging traces

When reading the traces note there is a difference between "retval" and "ret"

U. Bonnes [Nov 05]:wine archive ret means the address of the piece of code calling the function, retval is the actual return value of the function returning to the caller. [However you should be aware that] With a void function like ftime [...]it doesn't make sense:

time.c: * _ftime (MSVCRT.@)
time.c:void _ftime(struct MSVCRT__timeb *buf)

V. Margolen [Dec 05] then explained reading a trace.

005d:Call ntdll.RtlLeaveCriticalSection(41164de8) ret=4111a044

threadID(005d) function name called arguments return address(=4111a044)

005d:Ret  ntdll.RtlLeaveCriticalSection() retval=00000000 ret=4111a044

thread ID function name returning from return value return address


When you check the code for that function, and the return value of the function is not supposed to be void, it means there you may have found the problem. In Jun 08 [bug 13599]:

0064:Call opengl32.glGetString(00001f01) ret=1000cd58

D. Timoshkov ret=xxx above is the caller's address. When an API calls returns you see something like 0064:Ret ntdll.RtlUnwind() retval=00000000 ret=6034dc13

The user grasped: so the missing 'retval=' indicates a crash inside function ? I didn't know that one... Thank you for your hint ! ;-)

L. Lenders later wrote: Just to make sure the bug is really in glGetString: adding an exception handler by attached patch makes [the software] finish just fine.

Further Reading


Missing that extra piece

0x7f6a2540 PRINTDLG_WMCommandA+0x619 in comdlg32: movw  %ax,0x2e(%edx)

M. Bestefich [Jun 06] Neat stack trace, unfortunate that it lacks a source file and line number. Robert Shearman writes: tell the user to install a build with debug information. [Molle Added] Wine is built with debugging symbols per default if you download the source and build it yourself. wine archive

Processing debug Traces

One developer noted [Wine user May 2007]: letting the messages print to your terminal? That will likely slow things down too much to be useful. Better to redirect to a file: WINEDEBUG=+relay wine TrackLogsV3.exe &> wine.log That will still be slower than without debugging, but should be fast enough to be useful. The file can sometimes be vary large (>1GB) [...]

After the log is written to a file, I generally find it easier to chop into pieces:

split --bytes=20m wine.log

That will create files named xaa, xab ...


B. Okopnik [wineusr jan 09]: Speaking of useful bits of Perl - I threw this little hack together to analyze the logfiles produced by my troubleshooting: WINEDEBUG="+file,+comm,+serial" wine tsconfig.exe > tsconfig.LOG 2>&1

It keeps a list of whatever was reported as "not found" within the log, then drops any of the entries that get found later - thus reporting only the DLLs, etc. that were never found. Hopefully, some of you fine Wine folks here will find it useful.

---------------------------- missing_libs starts here -----------------
  1. !/usr/bin/perl -wl
  2. Created by Ben Okopnik on Wed Jan 14 17:43:01 CST 2009 use strict;
my %coll;
while (<>){
$coll{$1}++ if /"([^"]+)" not found/; delete $coll{$1} if
m{[\\\/]([^"\\\/]+)" ->} && exists $coll{$1};
}
print "Missing libs, etc.:\n==================="; print for sort keys
%coll;
------------------------------ missing_libs ends here ------------------

Make it executable, run it as "./missing_libs logfile", and watch the fun.

Tools for Working with Traces

Grep

shrinking a debug trace
V. Margolen [Jan 2006] demonstrated how to limit a debug trace using grep:

J. Stolk: [Jun 06] I usually start by removing the bulk of less interesting things from large +all logs: wine archive:

(Another way to reduce the log file is by disabling the logging of certain function using the wine registry settings.) egrep can be slower than the grep, but support searching for multiple strings separated by the | symbol.

Then I add line numbers, to make it possible to back-trace interesting finds to the original location in the log file. It also makes it possible re-sort the log file after combining the results from different greps.

add line numbering: (overwrites the original log)

Then filter out interesting things: (manually add more interesting finds later)

The -i option disables case-sensitive matching, so it will grep for both "fixme" and "FIXME". Using the line numbers, more information can be found in the all.txt log.

Note: Aug 08 a developer [missing name] suggested +all is usually a last resort, or used if the program crashes too early to see enough.

Find a Constant
L. Polzer [May 06] demonstrated how to find a Windows constant in Wine source code using grep, and showed its ensuing result

./include/winuser.h:3654:#define CF_TEXT 1

L. Polzer [May 06]: There's a better solution using grep to find constants:

This will also account for any (positive) amount and combination of tabs and spaces.

Finding the Start - Where did it go wrong
One developer commented on a trace [May 06]: I see a return from KERNEL32.UnhandledExceptionFilter() without the call. I think the program actually crashed somewhere before the call to that function. I often grep through the log for "xception" (without "E"/"e" so that case does not matter) to find the first place in the log where that word shows up.

Ok [0009]:KERNEL32.UnhandledExceptionFilter from 7c34c456 with none.

That is the actual place where an exception was caught. I typically check what a function does by going to http://msdn2.microsoft.com/en-us/library/default.aspx and plugging the function name into the search box. [...] It is a bit of a black art and one that I am not particularly good at. In this case, go through the relay trace prior to that UnhandledExceptionFilter call, and see if you can figure out what was happening. Or post a hundred lines or so of the relay trace prior to that call.

Indentation

E. Pouech [Jun 06]: tools/examine_relay [does indenting of traces], plus some other goodies (calls that didn't return...) IMO it's better to instrument the tools after the relay trace,

A developer noted [May 2007 WineUser list] If you are going through the relay traces, there is a tool in the wine tree that makes them easier to read (at least for me)

wine/tools/examine-relay xaa -f > xaa2

Now the file xaa2 will have the relay traces nicely indented. I often grep through the log for "xception" (without "E"/"e" so that case does not matter) to find the first place in the log where that word shows up.

D. Clark: it will indent in two slightly different formats. Add a flag to the end of the command line to get different formatting: tools/examine_relay wine.log -f


F. Nawothnig [Feb 2006 wine devel]: I wrote a Ruby/GTK2 tool to parse +message logs (along with other channels mixed in) and display them in a treeview - makes debugging message related problems much easier. I suppose others wrote similar scripts for their own use - but maybe someone will find it useful nevertheless: http://users.holycrap.org/flexo/spy.rb

Use like:

$ WINEDEBUG="+message" wine foo.exe 2>log $ ruby spy.rb log

Further Reading

General Debugging Tips

D. Clark noted an important change [Dec 05]: Wine recently changed from using system to system32 as the default directory for DLLs.[...] If there is no Wine version of a DLL, then Wine will automatically look for a native version. No override is necessary. In general, you should first try running the app with no overrides, and only add overrides if necessary for a specific app. About the only exception to that would be msvcrt.dll, where you are generally better off with a native version (though there has been quite a bit of work on this one lately. wine archive [Ed. If there is a difference between using native msvcrt and wine's version, the developers may be interested, so please post to one of the mailing list, include the name of the software and where it can be downloaded]


J. von Thadden [may 05]: [not all] 'WinXP DLLs will work with wine.' He then pointed out that when searching for a dll:

  1. Wine searches case insensitive. [ie. Capital or Lowercase dll names]
  2. Wine searches in \windows\system Wine archive Link


WINE_DEFAULT_DEBUG_CHANNEL(seh);

That means that most of the trace messages in that file will be triggered with the "seh" debug channel (or of course "all").


Occasionally when using WINEDEBUG, you will see "setting to (0xdeadbeef)".


Which traces to use

Winehq Bugzilla entry 17797 J. Zaroyko mar 09: the potentially helpful part of a +relay,+seh,+tid log is that you can see where the exceptions occur, after which calls and their return value.

Further Reading

Limiting the amount of Traces

This clever tip was shown in Apr 09 by A. English: Try with +relay,+seh,+tid (run wine notepad beforehand to reduce output). The user spotted what was being done: I guess the intention is to [avoid] clean up startup msgs. But how exactly do I make the same wine process run notepad and then the game? and then only redirect the output from the game? A. English [the] Easiest way is to open two terminals:

[Terminal Windows 1]:

wine notepad

[Terminal Window 2]:

WINEDEBUG=+relay,+seh,+tid wine game.exe &> /tmp/output.txt

Filling out a Bugreport

If you do fill out a bugzilla report, some have posted to the lists that they strongly prefer not to have the debug trace posted directly into the bug report's text - add the trace as an attachment. Note that a debug trace is different from a backtrace.

R. Klazes [Mar 06]: the backtraces are good to follow. [...Debug trace..] logs are mostly too large to post, but then most people already attach those. wine archive

Ed: this way, developers dont get caught out downloading a 2 Gigabyte bug report. These volunteers, some of whom may be using dial up, review all the new bug reports that pile in each day to wine. Sometimes it means they end up waiting for 30 minutes (or more!) for a bug page to display, which is very impolite. Please keep this in mind and avoid pasting large amounts of text directly into a bug report.

The developers sometimes have backtraces posted to the wine-devel list but T. Spear commented: would you mind including backtraces as an attachment? When I have to read my emails from the browser, gmail wraps the backtrace, which makes it difficult to read. wine archive

Obtaining a backtrack

Mar 09:So how do i compile wine to throw "right" backtraces ? We really should get simple guide for newbies with that...

A. English: It's regular gcc stuff, not particular to Wine. If you're running from the source tree, should work fine, unless you used --strip or messed with CFLAGS. [ed you might try installing the package for wine from your linux distribtuion with the suffix .dbg or with the word debug in the name]

WINEDLLOVERRIDES

At this stage in wine's developement wine sometimes needs native dlls. When debugging, you will try many different options and these changes are sometimes easier set using WINEDLLOVERRIDES on the command line.

Further Reading


Sometimes you see a message that a dll is required, but you know it is present. M. Hearn [Oct 05]: Look at the debugging guides we wrote on the [Official Wine] wiki. For this kind of bug, a +relay,+tid,+seh trace is a good start. Find the first seh: line and that'll show you where the exception was thrown.Wine Archive

Obtaining MS Windows

One developer suggested how he would obtain a windows license [Apr 06]: I'll buy a factory-sealed OEM version on eBay, accompanied by a piece of hardware.

relay trace

A. Julliard Aug 07 winedevel commenting on a patch for relayexclude that filters the relay trace: In most cases it makes the trace much more readable and manageable. If you want to know what's going on inside Wine code there are better debug channels to use than relay.

Relay16

Win16 relay messages have been moved to their own channel (relay16)

Filtering Relay Trace

Because the relay trace is so prolific, U. Bonnes [July 05] pointed out how to filter the relay trace making it easier to understand: For the relay log to be less mess, add e.g. in user.reg Wine Archive

User.reg:
[Software\\Wine\\debug] 1121071282
"RelayExclude"="RtlEnterCriticalSection;RtlLeaveCriticalSection;\_
EnterSysLevel;_LeaveSysLevel;_CheckNotSysLevel;gdi32.*;winex11.drv.*;ntdll.*"

V. Margolen suggested[Sept 05]: Wine Archive Add this to the user.reg file

User.reg:
[Software\\Wine\\Debug] 1125240062
"Relayexclude"="RtlEnterCriticalSection;RtlLeaveCriticalSection;_EnterSysLevel;_LeaveSysLevel;_CheckNotSysLevel;NtCurrentTeb;
LdrAccessResource;RtlUpperChar;kernel32.97;kernel32.98;TlsGetValue"


To reduce the calls such as "000b:Call kernel32.97(408b8880) ret=40891d49" from a relay log, add "kernel32.97;kernel32.98" to the "HKEY_CURRENT_USER/Software/Wine/debug/RelayExclude" string value Wine Archive

Relayfromexlude
A programmer noted: the main program from the Xilinx ISE suite ise.exe starts _pn.exe. If I understand right, "RelayFromInclude"="ise.exe" will track relay calls of ise.exe,but not from _pn.exe.

A. Julliard: "RelayFromInclude"="ise.exe;_pn.exe" will track both.

The programmer then highlighted a potential gotcha: this requires the user to first track what's going on, then change user.reg and restart. If the error happens in a dll, this dll has also to be included in RelayFromInclude inuser.reg. Xilinx ISE is polluted with Dlls [emphasis added] Wine Archive


D. Timoshkov:[Oct 06] Changelog: Update RelayExclude and add RelayFromExclude filter in order to avoid not useful APIs in the traces, and greatly reduce the size of the relay logs.

--- cvs/hq/wine/tools/wine.inf Mon Oct 09 15:33:50 2006
+++ wine/tools/wine.inf Thu Oct 19 08:30:03 2006 @@ -173,7 +173,8 @@

M. Hearn explained why Kernel was included: Kernel mainly calls into ntdll these days so you see a lot of wrapper API calls that don't add much useful info. wine archive

Further Reading

Browsing the Wine Source Code

A. Julliard [Dec 05]: the new git repository on WineHQ contains all the releases I have, going back to 1993. You can browse it at http://source.winehq.org/git, or see the GitWine page on the wiki for instructions on how to download it.

Anon:A better link for browsing may be here: http://source.winehq.org/git/?p=wine.git;a=tree

Further Reading


Finding the Source Code for a Call

A developer looking at GetClipboardData asked: How do I find the source code for that call?

D. Clark: I'll just add one other simple method, since others did not mention it.In: http://source.winehq.org/ident You can just type in GetClipboardData, and it will find it for you.

M. Hearn: The Wine source tree is a labyrinth, mostly because it follows the layout of Windows itself. Believe it or not, it used to be far worse. These days nearly all the code for the APIs is under dlls/ so if you know where an API is implemented in Windows then you can find it there. In this case "user32.GetClipboardData" means it's in user32.dll, which is implemented in dlls/user (a historical quirk, normally they map 1:1)

[...]all Windows constants, defined in a header file that can be found in the include/ directory. Usually the best way is to use grep or alternatively MSDN will tell you which header file it's probably in.[...]

I navigate the tree by using etags, which plugs into emacs. If you use emacs or vi then etags/ctags can be very handy to jump around the tree. Run "make etags" or "make ctags" (or maybe it's make tags, I forget) in the source root to generate the file. wine archive

Deciphering the cause of a crash

A programmer posted his crash info..

Unhandled exception: page fault on read access to 0x00000004 in 32-bit code (0x41d551de).
In 32 bit mode.
fixme:dbghelp:elf_load_debug_info_from_map Alpha-support for Dwarf2 information for irc<elf>
Register dump:
 CS:0073 SS:007b DS:007b ES:007b FS:174f GS:0033
 EIP:41d551de ESP:43510adc EBP:43510af8 EFLAGS:00210206(   - 00      - RIP1)
 EAX:00000004 EBX:41db6434 ECX:00000000 EDX:7c0cbe30
 ESI:00000000 EDI:41c14f10
Stack dump:
 0x43510adc:  41d5514e 01000000 4f4d2e6c 41db6434
 0x43510aec:  7c126a38 4017c0d4 41db6434 43510b28
 0x43510afc:  41d9b4b5 7c126a38 00000000 00000000
 0x43510b0c:  41d9b45c 401f6b31 407bdbd0 4078f8e0
 0x43510b1c:  41d55142 7c126a38 407d4528 43510b40
 0x43510b2c:  407c9e31 4078f8e0 41d9b450 4078f8e0
 02e9: sel=174f base=41c14000 limit=00001fff 32-bit rw-
Backtrace:
=>1 0x41d551de in irc (+0x51de) (0x41d551de)
  2 0x41d9b4b5 in irc (+0x4b4b5) (0x41d9b4b5)
  3 0x407c9e31 in msvcrt (+0x29e31) (0x407c9e31)
  4 0x404ebbfb in kernel32 (+0x6bbfb) (0x404ebbfb)
  5 0x401d6cd3 in ntdll (+0x36cd3) (0x401d6cd3)
  6 0x40051297 start_thread+0x87 in libpthread.so.0 (0x40051297)
  7 0x4011c37e __clone+0x5e in libc.so.6 (0x4011c37e)
0x41d551de: movl        0x0(%eax),%eax

He then queried if: the dump well is due to a problem in __clone function trying to access 0x00000004 (eax). Am I right?

V. Margolen: Nope you looking at the wrong end. The address at fault is 0x41d551de which is frame 1. Also it looks like you have stripped wine libs. That's why you don't see function names nor their parameters.

Another posted a problem and asked why they didnt get the line number to the source file:

fixme:commdlg:PRINTDLG_SetUpPrinterListComboA Can't find '(null)' in
printer list so trying to find default wine: Unhandled page fault on
write access to 0x0000002e at address 0x7f6a2540 (thread 0009),
starting debugger... Backtrace:
=>1 0x7f6a2540 PRINTDLG_WMCommandA+0x619 in comdlg32 (0x7f6a2540)
  2 0x7f6a2fb6 in comdlg32 (+0x32fb6) (0x7f6a2fb6)
[snip!]
0x7f6a2540 PRINTDLG_WMCommandA+0x619 in comdlg32: movw  %ax,0x2e(%edx)

could one of you guys please tell me how to convert this: PRINTDLG_WMCommandA+0x619 into a proper line number reference to the source file?

R. Shearman: If you don't strip comdlg32 then winedbg will pick up the debug information from the .dll.so and give you a filename and line number. So tell the user to install a build with debug information. wine archive


Further Reading

Out of Memory

It would appear that some programs decide there isn't enough free memory available for their tasks (EG, Train Simulator's CAB extraction process[...]

U. Bonnes: This is an old issue. Some programs find _some_error and decide to report it as "out-of-memory" error. Mostly totally misleading... Look for the first error and cure it.


However in Feb 09 J. Drescher noted that not all memory errors refer to the system memory. A user provided a Winehq Bugzilla entry 17140 with an example of a trace: d3d9:IDirect3DDevice9Impl_CreateVertexDeclaration Allocation of memory failed, returning D3DERR_OUTOFVIDEOMEMORY.J. Drescher: This problem looks to be out of video memory and not system ram

Further Reading

Further Debugging Tips

Difficult to obtain traces

Maybe you can do:

wine wc3.exe 2>&1 | tee ~/log

Then when you reboot, the errors should go to ~/log. I've tried this with xkill'ing the terminal I run it in, and I'm not sure if this works for a crash, but it's worth a try ;) Wine Archive Link

A. Mistry pointed out some tell tale symptoms of getting into a hard lock: numlock doesn't work and can't ssh in. Wine Archive thread Link


A programmer reported [Dec 05] that Wine would segfault whenever he tried to debug using the relay trace: M. Hearn: We have a hack in CrossOver's Wine to avoid crashes in +relay. This might help you see what's happening after the point of the crash in Wine. See the attached patch. [He then posted the patch] wine archive


builtin vs native
R. Cohen posted: Here is a implementation that can exclude relay calls from builtin dlls. I used '<builtin>' as the magic word because '%' is possible in file names. Wine Archive

Turning Traces On and off

Wine's taskmgr has in the Processes tab a context menu entry "Edit Debug Channels ...".

V. Margolen [aug 08]: You can only enable/disable debug channels from there that were enabled with WINEDEBUG env var at the start of the program. This is [an] optimization AJ put in place a long time ago.

Debugging with Native Dlls

S. Leichter: WINEDEBUG=+snoop [...] will give you the call and ret of the native dlls. wine archive


Splash Screen Hung

M. Hearn: If it hangs on the splash screen it may have deadlocked or gone into an infinite loop. Activation contexts are to do with supporting .NET/DLL sideloading and can almost certainly be ignored, they aren't available on several Windows versions.

Memory

A user looking at a backtrace wrote: I can't find any way to back-map this address to a memory region, so I don't know who "owns" this address. Its not in wine itself, its not in the PE's region (400000...) and its none of the DLLs (which are mapped after the PE itself).

D. Skorka [sept 06]: You propably already found this out on your own, but /proc/nnnn/maps will tell you which process has what memory regions mapped.

Comparing with Windows

A user asked: would it be possible to do the same startup on a Windows machine, and compare its relay to the relay from Wine. If this is possible, how would I go about this?

D Timoskov: Get Debugging Tools for Windows and use logger.exe to get a log similar to Wine relay log. Use +relay,+seh debug switches to create a log under Wine, +loaddll is not useful at all for your purposes. wine archive

[Ed A Google Search for "Debugging Tools for Windows" may help.]


Profiling Wine - (making it go faster)

Winehq Bugzilla entry 20951 D Kegel noted you can build a dll with -pg option: just don't build the preloader with those flags. (See e.g. http://www.winehq.org/pipermail/wine-devel/2005-March/034329.html ) You can build just the dll you want to profile, and it'll probably work.

On Ubuntu, you can use oprofile just fine, fwiw. I use it all the time for flat profiling of unmodified wine. It probably would be nice to have a configure option to build wine for profiling... we tried to do something like that a while ago, but it was rejected as not being generally useful. See http://www.winehq.org/pipermail/wine-patches/2004-November/013673.html <end quote>



A programmer queried wine devel jun 08: what's the procedure being used to profile Wine's code. More specifically, I want to try to track down slowdowns in some applications, which requires profiling to identify where the bottlenecks are.

S. Dossinger: I am using oprofile every now and then to profile Games, but it is only of limited use. It really depends on the sort of Application you want to profile, and you should use specific tools for this. If your app mainly utilizes the CPU, oprofile will be suitable. If it uses 3D graphics, you may be more happy with things like the NVPerfkit or the MacOS OpenGL profiler(on osx of course). Disk and Memory functionality may have their own profiler as well.

The bottom line is that performance and efficiency isn't a linear scale, so there is no ultimate tool for it.

T. Kho: Here's some Wine + DTrace activity I dug up:

O. Stieber posted [nov 05] : I've got a patch that displays timings between debug messages with TRACE+interval enabled that I'm using for some profiling and thought someone else may be interested. The patch is against dlls/ntdll. wine archive

Further Developer Tips

Winedebug

A user gave an example of using winedebug [Sept 06 wine user]

wine winedbg [myprog.exe]

You'll be presented with a prompt, just type 'cont'. When the program crashes, you should se this prompt again. At this point, type 'bt' and post the output.

M. Zalewski gave a suggestion for finding a backtrace when your program hangs [Sept 07 wine user]: You should try to get a stack backtrace of the programs when they are hung:

Such a backtrace could give some more details what's happening.


This was also suggested in Winehq Bugzilla entry 15534

You should be able to get [ a backtrace] by doing this:

When it crashes, winedbg should automatically stop the program and print out a backtrace. This can take a while to finish, so be sure to wait for "WineDbg>" prompt to return before assuming it's done.

H. Leung winedev feb 10: Curly brackets delimit blocks of code but do not correspond to any machine instructions themselves, and is hence removed during compilation and execution. So debuggers are supposed to skip over them and behaves as if they don't exist during code inspection.

Debug Symbols in Winedebug

Markus asked [winedevel sept 08]: is it possible to take advantage of the mfc42d.dll/mfc42d.map/mfc42d.pdb file trio to get debug symbols in winedbg? Or perhaps even in generic gdb? If yes, where would I put these files or how would I load their tables into the debugger?

E. Pouceh: in short:

Further Reading

Using another Debugger

A programmer posted: Is winedbg the only method of debugging applications being developed for Windows on Wine? For instance, assume a program developed with Visual Studio in C or C++, and I needed to debug it on Linux?

D, Kegel [winedevel 08 Aug]: If winedbg doesn't work for you, we should fix it. Same goes for other debuggers.For instance,

Please file bugs for any problems you run into.


[A post asked about using a] visual debugger much like VC/C++ , Eclipse, Borland C++ or the like... Where you can step through the code (seeing the whole thing like any visual debugger). Then when looking at stacks you click on a variable or stack and it either winds it back or display's it.

S. Dossinger Aug 08 winedevel: You can attach any debugger to a Win32 process running in Wine. This includes Linux debuggers like gdb, or any graphical frontends, as well as Windows debuggers like visual studio. If you built wine from source, the Linux debuggers will see the Wine source. Probably they can also read the Windows apps source if you have it. I'm not sure if Windows debuggers can access the Wine source, but maybe dbghelp.dll can do that

E. Pouch: dbghelp supports both linux debug formats (stabs, dwarf) as well as microsoft's one so any debugger using dbghelp as it's debug info provide should debug with all bells & whistles native & builtin applications I had some success with windbg (with a an 'e' between n & d ;-)

Further Reading

gdb

It seems that gdb is not essential, as winedbg should handle it fine Winehq Bugzilla entry 18963

[update Mar 09] a developer added to the documentation here Archived-At: <http://permalink.gmane.org/gmane.comp.emulators.wine.devel/68265>

M. Hitter Aug 08 winedevel: My tries to break not into the preloader, but [instead break into] the actual Windows application weren't successful so far, gdb's console appears to lock up somehow when setting follow-fork-mode & friends.[..] As you see, listing appears to work in principle, while symbol lookup doesn't. It's no secret Wine runs multiple processes and Windows applications run multiple threads, so you might want to look up how to handle this in gdb: http://sources.redhat.com/gdb/current/onlinedocs/gdb_5.html

First, start gdb in the C: directory

[homepath]/.wine/drive_c$ gdb GNU gdb 6.8-debian
Copyright [...] This GDB was configured as "x86_64-linux-gnu". 
(gdb) file wine
Reading symbols from /usr/local/bin/wine...done. (gdb) directory [...]/wine/ Source directories searched: [..]/home/mah/wine:$cdir:$cwd (gdb)

Then, run the app

(gdb) run windows/notepad.exe
Starting program: /usr/local/bin/wine windows/notepad.exe [Thread debugging using libthread_db enabled] [New Thread 0xf7c628c0 (LWP 793)]
[New Thread 0xf7c61b90 (LWP 796)]
[Thread 0xf7c61b90 (LWP 796) exited]
[New process 793]
Executing new program: /usr/local/bin/wine-preloader warning: Cannot initialize thread debugging library:
generic error warning: Cannot initialize thread debugging library:
generic error [New process 793] 
Fontconfig warning: "/etc/fonts/conf.d/53-monospace-lcd-filter.conf", line 17: invalid constant used : lcdlegacy 
Fontconfig warning: "/etc/fonts/conf.d/53-monospace-lcd-filter.conf", line 17: invalid constant used : lcdlegacy 
Fontconfig warning: "/etc/fonts/conf.d/53-monospace-lcd-filter.conf", line 17: invalid constant used : lcdlegacy

Notepad should be running here. Interrupt it from the command line to have a look:

^C
Program received signal SIGINT, Interrupt. 0xf7fec430 in ?? () 
(gdb) bt
#0  0xf7fec430 in ?? ()
#1  0x00000008 in ?? ()
#2  0x7bc76516 in ?? ()
#3  [...]
(gdb) list
1	/*
2	 * Preloader for ld.so
3	 *
4	 * Copyright (C) [...]


M. Meissner: [To avoid breaking in the preloader...] Easy to do for most applications you use wine-pthread for debugging:

$ gdb wine-pthread
(gdb) break CreateWindowExW
Function "CreateWindowExW" not defined. Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (CreateWindowExW) pending. 
(gdb) r notepad.exe
Starting program: /usr/bin/wine-pthread notepad.exe [Thread debugging using libthread_db enabled] 
[New Thread 0xf7d106c0 (LWP 9202)]
[Switching to Thread 0xf7d106c0 (LWP 9202)]
Breakpoint 1, CreateWindowExW (exStyle=0, className=0x7fcf7c70,windowName=0x7fcf7c60, style=13565952, x=1, y=2, width=729, height=546, parent=0x0, menu=0x0, instance=0x7fcf0000, data=0x0) at win.c:1401 1401 cs.lpCreateParams = data;
(gdb)

M. Hitter reported success with this method.

WINELOADERNOEXEC

These days (wine 1.1.24), you have to set the environment variable WINELOADERNOEXEC=1 to debug wine with gdb, otherwise gdb gets mixed up with the wine-loader.

troubleshooting

(no debugging symbols found)
You need wine debugging symbols, probably under wine-dbg or wine-dev in your package manager.

Valgrind

Valgrind works with wine, and you can use wine to access this amazing tool for debugging your windows application. D. Kegel has been steadily working away at this for some time. However there are of course some limitations Winehq Bugzilla entry 21503 Alexandre Julliard 2010-01-27Use of +heap together with Valgrind is questionable. Doing all the extra validation work is a waste of time since the accesses would have been caught already, and toggling Valgrind permissions all the time is going to make the Valgrind checks less reliable.

Mixed Traces

200142:fixme:ntdll:RtlNtStatusToDosErrorNoTeb no mapping for c0000119
200143:0011: get_handle_fd( handle=0xc, access=00000002 )
200144:0011: get_handle_fd() = 0 { fd=9, removable=0, flags=0 }
200145:Backtrace:
^^^^^^^^^^^^^^^
200146:0011: get_handle_fd( handle=0xc, access=00000002 ) 
200147:0011:get_handle_fd() = 0 { fd=9, removable=0, flags=0 } 200148:=>1 0xffffe002 (0xffffe002)
200149:0009:Ret  ntdll.NtDelayExecution() retval=00000000 ret=4037416a
200150:0009:Ret  kernel32.Sleep() retval=00000000 ret=408fc345
200151:0009:Call ntdll.NtQuerySystemInformation(0000000b,00000000,00000000,4072ef3c) ret=408fc296

M. Hearn [Jun 06]: Hmm seems like you are seeing a mixed debugger/app trace there ... gotta be careful of that!

Further checking, the developer noted: Ah, yes that's it. it seems one of the threads is bailing out somewhere.[After a while he then noted] I think i found the cause further up in the log. wine archive

The backtrace can be reconstructed from the mixed log by deleting all lines that start with '00xx:'

The word "Backtrace:" is actually in the middle of the returned debug info. the complete set contains the following sections:

Register dump:
 CS:0023 SS:002b DS:002b ES:002b FS:003b GS:0033
 EIP:4062e62c ESP:4074fc1c EBP:4074fe08 EFLAGS:00010206(   - 00      - RIP1)
<...> 
Stack dump:
0x4074fc1c:  406231fc 00000020 4074fd80 00000078
0x4074fc2c:  00000000 fbad8001 00000003 400d03af
0x4074fc3c:  400d03af 400d03af 400d03cd 400d0787
<...> 
Backtrace:
=>1 0x4062e62c ImagePath+0x4da in ntoskrnl (0x4062e62c)
  2 0x406226f4 __wine_spec_exe_entry+0x14c(peb=0x400d07a0) [ntoskrnl.c:92] in ntoskrnl (0x406226f4)
<...> 
Modules:
Module	Address			Debug info	Name (41 modules)
ELF	0x40605000-4063f000	Stabs           ntoskrnl<elf>
  \-PE	0x40610000-4063f000	\               ntoskrnl
<...> 
Threads:

Buffer Overruns

Debugging a Buffer Overrun


Using a Windows Partition
What is this trace?

fixme:reg_nt_dump_lf unknown winXP node id 0x686c: do we need to add support for it? 

M. Hearn [May 05]: It means, "don't try and run Wine against a Windows XP install".


Threads and their Locks

[Aug 05] In several RPG I have been testing, I have found deadlocks on the sound thread - the sound loops on and on, and the program freezes. At the same time, I see messages like the following:

fixme:ddraw:Main_DirectDraw_SetCooperativeLevel=20(0x7fe32708)->(00010022,00000008)
err:dsound:DSOUND_MixOne underrun on sound buffer 0x7fe82310
err:dsound:DSOUND_MixOne underrun on sound buffer 0x7fe82880
err:wave:DSDB_MMAPCopy mmap partially failed.
err:ntdll:RtlpWaitForCriticalSection section 0x7fe3336c "?" wait timed out in thread 000a, blocked by 0000, retrying (60 sec)
err:ntdll:RtlpWaitForCriticalSection section 0x7fe3336c "?" wait timed out in thread 0009, blocked by 0000, retrying (60 sec)
err:ntdll:RtlpWaitForCriticalSection section 0x7fe3336c "?" wait timed out in thread 000a, blocked by 0000, retrying (60 sec)
err:ntdll:RtlpWaitForCriticalSection section 0x7fe3336c "?" wait timed out in thread 0009, blocked by 0000, retrying (60 sec)

I thought that DirectSound was not performing locking properly, until I noticed the following: all the times I see this deadlock, the thread ID "responsible" for the deadlock is 0000. From a little digging in the code, I see that 0 is the value used in the critical section when it is not held by any thread. So these are potentially cases where a previous thread frees the critical section, but somehow the critical section remains locked

A. Julliard: The most likely cause is that a thread got killed while trying to release the section. If you see calls to TerminateThread that would be a prime suspect.Wine Archive


A user noted [Dec 05]: [a problem] occurs with the installer for Delorme Street Atlas 5 - on my 2GHz Athlon desktop it runs without a hitch, but on my oooooold slow laptop [..] the program locks up 100% of the time at startup, with 2 threads trying to take different critical section locks and dying. It looks like the standard deadlock condition: [...] on the fast CPU the deadlock does not happen because thread 1 gets everything done before thread 2 starts. On the slow machine, thread 2 starts while thread 1 is still doing stuff. Are there any tricks to identifying who locked what where and in what order?

R.Shearman: [Dec 05] Yep, example of what not to do in concurrent programming. [...] Unless the installer is using TryEnterCriticalSection, I would expect CPU utilisation to be 0% when deadlocking. Relay logs generally give the best clues in this kind of situation. [...]

You should make a note of the order in which locks are taken and always take the locks in that order and always release them in the opposite order.

You have several options from here:

  1. File a bug report with the maker of the application.
  2. Find a function that B uses just before it locks that A doesn't use and add a Sleep call. Obviously this kind of fix won't be accepted into Wine.
  3. Do tests to try to find a function that A uses that is much slower on Wine and try to fix it.wine archive

GUID

D. Riekenberg Found a big online GUID-List [Jul 06]:

Debugging by Stepping through a Windows application

A developer queried [Oct 06]: I would like to know if there is some sort of 'ptrace' like API which will allow me to attach to a windows executable single step through the program and obtain the contents of the registers and the instruction pointer as the single stepping proceeds. I know I could manually single step via winedbg but I would like to automate this process.

M. Hearn: WineDbg just uses the debugger APIs like any other app. So you could write your own program that uses the debugger APIs to do this. wine archive


Anton Matosov: Another way to do this is to use a MS Visual Studio with a Remote Debugger launched on WINE. For most applications this works w/o any problems. Tested on VS2008.

Links

Unofficial Wine Links

Personal tools
Namespaces
Variants
Actions
Navigation
Toolbox