Difficulty getting debuggers to work, dll load/init issue

Questions about Wine on Linux
Locked
Veyrdite
Newbie
Newbie
Posts: 3
Joined: Fri Apr 26, 2019 6:23 am

Difficulty getting debuggers to work, dll load/init issue

Post by Veyrdite »

I have an old game mod (ECW) that doesn't run under wine. The game's logs think one particular mod-provided DLL is failing to load:

Code: Select all

[bhs.dll] Failed to load, error 998. No access to memory location.
Looking at the assembly it seems that this error path is taken if GetLastError after LoadLibraryA returns something amiss; in this case ERROR_NOACCESS (=998):
bhsdll_load.png
bhsdll_load.png (15.45 KiB) Viewed 4664 times
I tried manually patching this check out of the binary, but that just leads to other DLLs complaining about things being missing. It's definitely required.

Unfortunately the community lost the source to this DLL years ago and the game works without this problem on Windows (so there's nothing to try and debug there). Most of the community has moved onto a much newer codebase for their mods, which works perfectly fine under Wine (as does the base game), but this one particular mod is stuck on an old codebase due to some non-derivative license/cultural restrictions put in place by previous authors.

I've been trying to get this mod running under Wine for well over a year (on and off) across wine versions from the 3.x era up to 4.6. Throughout I've had the same debugger issues, none of this is due to a recent change as far as I can tell.

For reference however:
- Current Wine version: 4.6
- Current Platform: x86_64 Void Linux 4.19.30_1
- 32bit wine prefix

WINEDEBUG=+relay and +all
I have not been able to notice anything useful in here using my feeble logreading skills. The game seems to catch whatever fault is occurring and gracefully bring a MessageBox up.

Download link for log files (9.3M compressed)

Landmark 1: line 1009245 in allog.txt:

Code: Select all

14561.530:0008:0009:Ret  KERNEL32.LoadLibraryA() retval=00000000 ret=110025c2
14561.530:0008:0009:Call KERNEL32.GetLastError() ret=110025c9
14561.530:0008:0009:Ret  KERNEL32.GetLastError() retval=000003e6 ret=110025c9
14561.530:0008:0009:Call KERNEL32.CreateFileA(1128a154 "dllload.txt",40000000,00000003,0034d6c0,00000004,00000080,00000000) ret=1123f889
This is where the issue occurs (GetLastError's return value of 0x3e6 = 998). The dllload.txt logfile is then opened and the words "No access to memory location" written to it. I suspect that the LoadLibraryA call leads to the DLL being initialised in another thread that I don't have seem to have WINEDEBUG insight into.

Landmark 2: "there was an error loading bhs.dll" message box. This happens far after the fault itself.

winedbg

Code: Select all

winedbg --gdb Game300.exe 
The game starts, notices the error and displays its message box. During none of this does winedbg notice anything astray.

I'm not aware of a winedbg feature to get it to trip on this fault.. I might be missing something here.

winedbg --gdb

This immediately fails:

Code: Select all

winedbg --gdb Game300.exe 
0039:003a: create process 'C:\w3dhub\games\ecw-testing\Game300.exe'/0x1107c8 @0x78f4ef (0<0>)
winedbg: Internal crash at 0x7e97ae8f
winedbg --gdb works fine on other applications, just not this one.

Call me green, but I have no clue where to start when it comes to debugging a debugger :(

gdb with workarounds

This is the best I've been able to come up with so far:

1. Run "wine Game300.exe" in a terminal, and then immediately hit Ctrl+Z to suspend it
2. gdb -p $(pgrep Game300.exe)
3. "fg" in the game's terminal

The game will still stay suspended because of gdb being attached to it; but I have found it is important to run the 'fg' to get it out of STOP mode otherwise it's unreliable to start up again from inside gdb.

4. gdb: catch syscall clone
5. gdb: cont

The first call of 'cont' will provide a notice about the process having received a SIGCONT (from typing 'fg' in the terminal).

If I keep cont'ing then after the 12th thread starts and closes I hit a segfault. GDB actually detects this segfault and halts program execution.

I think this segfault is normally being masked/hidden/something during normal execution (so the game can provide its error log + dialog box). I'm not an expert on DLL loading (I'm a Linux person) so I'm not sure what the conventions are here.


Throughout this process GDB is clueless as to what files each frame is in. Example:

Code: Select all

(gdb) info threads  
Id   Target Id              Frame 
* 1    LWP 4739 "Game300.exe" 0xf7c4f9b4 in ?? ()
  2    LWP 4836 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  5    LWP 4852 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  7    LWP 4858 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  8    LWP 4863 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  9    LWP 4866 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  10   LWP 4885 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  11   LWP 4890 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()
  12   LWP 4901 "Game300.exe" 0xf7f29df9 in __kernel_vsyscall ()  # newest one 

(gdb) thread 12
(gdb) bt
#0  0xf7f29df9 in __kernel_vsyscall ()
#1  0xf7d2e147 in ?? ()
#2  0x7bc9360d in ?? ()
#3  0x7bc4e49e in ?? ()
#4  0x7bc98ffa in ?? ()
#5  0x7bc94aa4 in ?? ()
The backtraces only provides addresses, which don't seem to coincide with actual locations in the binaries (numbers are too big), so I'm left lost as to where to look at the dissassembly/binaries. If I could find a way of mapping these addresses to actual locations in files I would be really happy, and it looks like that's what's normally done if running "winedbg --gdb" works.

At the time of the segfault the program has jumped somewhere weird that I presume isn't supposed to be code:

Code: Select all

> 0xec83f0e4      add    %al,(%eax)
  0xec83f0e6      add    %al,(%eax)
  0xec83f0e8      add    %al,(%eax)
  0xec83f0ea      add    %al,(%eax)
  0xec83f0ec      add    %al,(%eax)
  0xec83f0ee      add    %al,(%eax)
  0xec83f0f0      add    %al,(%eax)
  0xec83f0f2      add    %al,(%eax)
  0xec83f0f4      add    %al,(%eax)
  0xec83f0f6      add    %al,(%eax)
...etc for a very long time...
GDB's reversible debugging spits the dummy and causes all sorts of problems if I try to use it, including GDB itself crashing horribly.

I'm not sure of a way to reliably break before the error occurs. If I try to single-step the game (stepi): then I get no-where. The game runs in a loop that prioritises filling the audio buffer above everything else, so even if I run "stepi 10000" over and over again I still don't progress toward the crash.

VS2005 and VC2008
(Visual studio 2005 was used to compile the culprit DLL)

After lots of wrangling I managed to get 2005 (and 2008 on another attempt) to install; however they completely fail to be able to debug processes. Even simpler ones that normally work with windbg.

Other 3rd party debuggers

ollydbg110: crashes when I try to open the exe
ollydbg200: loads and analyses the exe, but hangs when trying to start the debugging process
x64dbg (32-bit version): fails to open any & analyse any exe file, seems broken under Wine despite the winehq page saying otherwise.
dependency walker: thinks all of the system dlls have missing exports (probably due to them being dummies under wine) and seems blinded because of it.


Questions

(1) Is there an easier way to debug DLL loading in Wine? Ie debug the init funcs of a DLL, or WINEDEBUG for newly spawned threads only?
(2) Is there a way to get winedbg --gdb working? When this works I at least get more useful backtraces, because gdb knows what the files are.
(3) Am I doing something horribly wrong? Can anyone suggest some easier or better alternative paths?
bernhardu
Level 2
Level 2
Posts: 11
Joined: Thu Jan 31, 2013 4:08 pm

Re: Difficulty getting debuggers to work, dll load/init issu

Post by bernhardu »

I found this topic interesting and tries to gather some information.
Unfortunately I got w3dhub not running, received just

Code: Select all

Error details: Invalid URI: The hostname could not be parsed.
Therefore it would be handy to have direct downloads of the files in question, if they are free to download.

What you might face here is that bsh.dll is "load-time-linked" into the exe.
This might not be possible to debug with winedbg as here gets the process
created and all dlls loaded before winedbg gives you control. That way for each
dll a DllMain function is called before the exe reaches its main function.

To break things down I created a smaller test program that does "run-time-linking":

Code: Select all

/* i686-w64-mingw32-gcc -g -o main.exe main.c */

#include <windows.h>
#include <stdio.h>

int main(int argc, char** argv)
{
    HMODULE h;

    SetLastError(0xdeadbeef);
    h = LoadLibrary(argv[1]);
    printf("LoadLibrary(\"%s\") returned 0x%x, GetLastError=0x%x\n", argv[1], h, GetLastError());
    
    return 0;
}

Code: Select all

WINEDEBUG=+module,+seh wine main.exe bhs.dll
That gives me the lastError 0x3e6. And also shows that bhs.dll seems to depend on shaders.dll.
Executing "wine main.exe shaders.dll" gives the same 0x3e6 - so I guess that dll loading is
the problematic one. Also visible is there that a crash happens in DllMain.

In my test that small program could be loaded in "winedbg" and "winedbg --gdb".
Unfortunately the backtrace when the segmentation fault is reached is not very helpful.
One could start a debug session here:

Code: Select all

$ wine winedbg --gdb main.exe shaders.dll
b MODULE_InitDLL if wm->ldr.EntryPoint < 0x70000000
cont
print wm->ldr.EntryPoint
b * $1
cont
display/i $pc
stepi
...
In your alllog.txt is this exception already visible:

Code: Select all

1009097	14561.524:0008:0009:trace:process:NtQueryInformationProcess (0xffffffff,0x00000022,0x34cbdc,0x00000004,(nil))
1009098	14561.524:0008:0009:trace:seh:raise_exception code=c0000005 flags=0 addr=0xec83f0e4 ip=ec83f0e4 tid=0009
1009099	14561.524:0008:0009:trace:seh:raise_exception  info[0]=00000000
1009100	14561.524:0008:0009:trace:seh:raise_exception  info[1]=ec83f0e4
1009101	14561.524:0008:0009:trace:seh:raise_exception  eax=7c551a80 ebx=00000000 ecx=7c536b90 edx=ec83f0e4 esi=05178dac edi=00000000
1009102	14561.524:0008:0009:trace:seh:raise_exception  ebp=1283868c esp=0034cf5c cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00210206
1009103	14561.524:0008:0009:trace:seh:call_stack_handlers calling handler at 0x1282a80c code=c0000005 flags=0
...
1009129	14561.524:0008:0009:exception c0000005 in PE entry point (proc=0x1281ac50,module=0x12800000,reason=PROCESS_ATTACH,res=(nil))
1009133	14561.524:0008:0009:warn:module:process_attach Initialization of L"shaders.dll" failed
1009137	14561.524:0008:0009:trace:module:process_attach (L"shaders.dll",(nil)) - END
1009146	14561.525:0008:0009:trace:module:process_attach (L"bhs.dll",(nil)) - END
1009148	14561.525:0008:0009:trace:module:LdrUnloadDll (L"bhs.dll") - START
Are you running some precompiled wine binaries or is it self built?
Happy debugging :wink:
bernhardu
Level 2
Level 2
Posts: 11
Joined: Thu Jan 31, 2013 4:08 pm

Re: Difficulty getting debuggers to work, dll load/init issu

Post by bernhardu »

Found this issue too interesting to stay away and I think I found something for your winedbg --gdb crash.
You can just debug the debugger by "wine winedbg winedbg --gdb Game300.exe" :)
This gives a quite informative backtrace. I opened bug 47203 for it that
has a hack attached to avoid this crash and enabled winedbg --gdb to continue.
bernhardu
Level 2
Level 2
Posts: 11
Joined: Thu Jan 31, 2013 4:08 pm

Re: Difficulty getting debuggers to work, dll load/init issu

Post by bernhardu »

And for the initial issue: "Unfortunately, there was an error loading bhs.dll. Please report this bug!"
When I configured a library override via winecfg to take native d3d8.dll this message was also gone,
like described in this bug.
Veyrdite
Newbie
Newbie
Posts: 3
Joined: Fri Apr 26, 2019 6:23 am

Re: Difficulty getting debuggers to work, dll load/init issu

Post by Veyrdite »

Oh wow, thankyou so much bernhardu.

I've been trying to override the wrong d3d dlls (d3d9*), no wonder I have not gotten anywhere.

The game now launches and I can join the server. Unfortunately I'm seeing some networking issues (extremely low and sparse packet replies from the server) but they might be hosting related, not Wine related.

I'll writeup the workaround onto the W3Dhub forums as soon as I can.
Are you running some precompiled wine binaries or is it self built?
Binaries from the Void Linux repositories. Build template link.

Any particular reason you are asking?
bernhardu wrote:I found this topic interesting and tries to gather some information.
Unfortunately I got w3dhub not running, received just
Code:
Error details: Invalid URI: The hostname could not be parsed.
The W3Dhub launcher? Unfortunately it's a dotnet4.6 + WPF application, so you have to be running the right version of wine and spend some time doing the workarounds to get dotnet4.6 working. I wrote up a =https://w3dhub.com/forum/topic/417270- ... tion here.
Therefore it would be handy to have direct downloads of the files in question, if they are free to download.
Unfortunately you can only (currently) get versions of the game through the W3Dhub launcher.

I believe this is partly due to the distribution of parts of Renegade with the game, which is only possible to do for free as part of the W3Dhub's community arrangements with EA. I'm not an expert on the details here, so I may be wrong.
bernhardu
Level 2
Level 2
Posts: 11
Joined: Thu Jan 31, 2013 4:08 pm

Re: Difficulty getting debuggers to work, dll load/init issu

Post by bernhardu »

Veyrdite wrote:
bernhardu wrote:Are you running some precompiled wine binaries or is it self built?
Binaries from the Void Linux repositories. Build template link.
Any particular reason you are asking?
Chances might be that winedbg is not yet prepared to pick up debug information if they got
split out into separate dbgsym packages like it is done in debian - but I have not tested this.
Locked