http://bugs.winehq.org/show_bug.cgi?id=27435
Summary: Duke Nukem Forever Demo (Steam) crashes on start Product: Wine Version: 1.3.21 Platform: x86 OS/Version: Linux Status: NEW Keywords: obfuscation Severity: normal Priority: P2 Component: -unknown AssignedTo: wine-bugs@winehq.org ReportedBy: austinenglish@gmail.com CC: focht@gmx.net
Created an attachment (id=35083) --> (http://bugs.winehq.org/attachment.cgi?id=35083) terminal output
Shows a steam/dnf crash dialog on start, without much info. Using -nobreakpad gets it slightly further, showing a backtrace (attached).
I'll get a relay,seh,tid trace.
http://bugs.winehq.org/show_bug.cgi?id=27435
Luke Bratch l_bratch@yahoo.co.uk changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |l_bratch@yahoo.co.uk
http://bugs.winehq.org/show_bug.cgi?id=27435
--- Comment #1 from Austin English austinenglish@gmail.com 2011-06-09 17:28:26 CDT --- Created an attachment (id=35084) --> (http://bugs.winehq.org/attachment.cgi?id=35084) relay,seh,tid
I ran WINEDEBUG=relay,seh,tid, which is about 1.1 GB. The game crashes twice, apparently relaunching itself after the first failure. For this log, I trimmed out the startup of steam all the way to the end of the first crash, and attached from the beggining of the second run until after the second failure (when I used wineserver -k).
That was rzip -9'ed, but was 1.3 MB, so I used split to break it into two files. This is part 1.
http://bugs.winehq.org/show_bug.cgi?id=27435
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Attachment #35084|0 |1 is obsolete| |
--- Comment #2 from Austin English austinenglish@gmail.com 2011-06-09 17:38:22 CDT --- Created an attachment (id=35085) --> (http://bugs.winehq.org/attachment.cgi?id=35085) relay,seh,tid - part 1
Attached wrong file, ignore.
http://bugs.winehq.org/show_bug.cgi?id=27435
--- Comment #3 from Austin English austinenglish@gmail.com 2011-06-09 17:38:41 CDT --- Created an attachment (id=35086) --> (http://bugs.winehq.org/attachment.cgi?id=35086) relay,seh,tid - part 2
http://bugs.winehq.org/show_bug.cgi?id=27435
--- Comment #4 from Anastasius Focht focht@gmx.net 2011-06-09 18:34:33 CDT --- Hello Austin,
next time please try "append" mode, some parts are hard to read due to interleaving messages.
From a quick look this seems to be the location where the problem starts:
--- snip --- ... 0029:Call ntdll.RtlAddVectoredExceptionHandler(00000001,009423a0) ret=009425bb 0029:Ret ntdll.RtlAddVectoredExceptionHandler() retval=00154260 ret=009425bb ... 0029:Ret KERNEL32.GetCurrentThreadId() retval=00000029 ret=00941b22 0029:trace:seh:raise_exception code=80000003 flags=0 addr=0x94290d ip=0094290e tid=0029 0029:trace:seh:raise_exception eax=0033ef40 ebx=0033f5f4 ecx=0033eb7c edx=574cb391 esi=00154290 edi=00000000 0029:trace:seh:raise_exception ebp=0033f180 esp=0033ef30 cs=0073 ds=007b es=007b fs=0033 gs=003b flags=00000282 0029:trace:seh:call_vectored_handlers calling handler at 0x9423a0 code=80000003 flags=0 ... 0029:Call KERNEL32.GetSystemDirectoryW(00000000,00000000) ret=0094fff1 0029:Ret KERNEL32.GetSystemDirectoryW() retval=00000014 ret=0094fff1 0029:Call KERNEL32.GetProcessHeap() ret=00950006 0029:Ret KERNEL32.GetProcessHeap() retval=00110000 ret=00950006 0029:Call ntdll.RtlAllocateHeap(00110000,00000008,00000234) ret=0095000d 0029:Ret ntdll.RtlAllocateHeap() retval=0015f4d0 ret=0095000d 0029:Call KERNEL32.GetSystemDirectoryW(0015f4d0,00000234) ret=00950017 0029:Ret KERNEL32.GetSystemDirectoryW() retval=00000013 ret=00950017 0029:Call KERNEL32.GetModuleHandleA(00adf650 "kernel32.dll") ret=0094b5ae 0029:Ret KERNEL32.GetModuleHandleA() retval=7b810000 ret=0094b5ae 0029:Call KERNEL32.GetProcAddress(7b810000,00adf630 "Wow64DisableWow64FsRedirection") ret=0094b5c4 0029:Ret KERNEL32.GetProcAddress() retval=7b826650 ret=0094b5c4 0029:Call KERNEL32.GetProcAddress(7b810000,00adf610 "Wow64RevertWow64FsRedirection") ret=0094b5d0 0029:Ret KERNEL32.GetProcAddress() retval=7b826668 ret=0094b5d0 0029:Call KERNEL32.Wow64DisableWow64FsRedirection(0033f1d0) ret=0094b5e3 0029:Ret KERNEL32.Wow64DisableWow64FsRedirection() retval=00000000 ret=0094b5e3 0029:Call KERNEL32.CreateFileW(0015f4d0 L"C:\windows\system32\",80000000,00000007,00000000,00000003,00000000,ffffffff) ret=0094cb34 0029:Ret KERNEL32.CreateFileW() retval=ffffffff ret=0094cb34 0029:Call KERNEL32.CreateFileW(0015f4d0 L"C:\windows\system32\",80000000,00000007,00000000,00000003,02000000,ffffffff) ret=0094cb53 0029:Ret KERNEL32.CreateFileW() retval=000001a0 ret=0094cb53 0029:Call KERNEL32.GetFileInformationByHandle(000001a0,0033f190) ret=0094cb81 0029:Ret KERNEL32.GetFileInformationByHandle() retval=00000001 ret=0094cb81 0029:trace:seh:raise_exception code=80000004 flags=0 addr=0x94ddf0 ip=0094ddf0 tid=0029 0029:trace:seh:raise_exception eax=00c5625d ebx=0033f698 ecx=00000000 edx=00000000 esi=0015f4d0 edi=000001a0 0029:trace:seh:raise_exception ebp=0033f1d8 esp=0033ef6c cs=0073 ds=007b es=007b fs=0033 gs=003b flags=00010202 0029:trace:seh:call_vectored_handlers calling handler at 0x9423a0 code=80000004 flags=0 0029:Call KERNEL32.GetCurrentThreadId() ret=00941a2a 0029:Ret KERNEL32.GetCurrentThreadId() retval=00000029 ret=00941a2a 0029:trace:seh:call_vectored_handlers handler at 0x9423a0 returned 0 0029:trace:seh:call_vectored_handlers calling handler at 0x7e0e55a0 code=80000004 flags=0 0029:trace:seh:call_vectored_handlers handler at 0x7e0e55a0 returned 0 0029:trace:seh:call_stack_handlers calling handler at 0x99b933 code=80000004 flags=0 0029:Call KERNEL32.GetLastError() ret=78543849 0029:Ret KERNEL32.GetLastError() retval=00000000 ret=78543849 0029:trace:seh:call_stack_handlers handler at 0x99b933 returned 1 0029:trace:seh:call_stack_handlers calling handler at 0x109101ad code=80000004 flags=0 0029:Call KERNEL32.GetLastError() ret=78543849 0029:Ret KERNEL32.GetLastError() retval=00000000 ret=78543849 0029:trace:seh:call_stack_handlers handler at 0x109101ad returned 1 0029:trace:seh:call_stack_handlers calling handler at 0x7bc87380 code=80000004 flags=0 0029:Call KERNEL32.UnhandledExceptionFilter(0033eae8) ret=7bc873cd 0029:Call KERNEL32.IsBadCodePtr(60001770) ret=03ad261d 0029:Ret KERNEL32.IsBadCodePtr() retval=00000000 ret=03ad261d 0029:Call dbghelp.SymGetOptions() ret=600029f5 0029:Ret dbghelp.SymGetOptions() retval=00000002 ret=600029f5 --- snip ---
That break instruction exception seen here (caused by int 3) is most likely used to modify own thread context from installed vectored SEH without the need of (Nt)Get/SetThreadContext().
"Most likely" because of that 0x80000004 exception that follows some calls later (hardware bp/singlestep). It would be interesting to have a look at debug register values at this point (dr0-dr3,dr6,dr7) but that requires a +server trace. One of them should reference the address 0x94ddf0 (break on execution).
That GetFileInformationByHandle() call might be some part of DRM scheme, remember this is steam. I think this was also the reason why this API was introduced in Wine (Left 4 Dead 2 DRM?). Though one needs to debug/disassemble the caller to actually find out what parts of the returned data are used and how. Maybe the index number because it's guaranteed to be unique across filesystems (FAT32, NTFS). "C:\windows\system32\" is a pretty "stable" path so the index number might only change if someone uses FAT and decides to defragment the disk.
At the point of IsBadCodePtr()/SymGetOptions() calls the things were already out of control... maybe some condition was not satisfied. Either the hw breakpoint(s) should never been hit/reached by "normal" execution paths or if they were to hit, the data gathered until that point was somehow considered bad (hence SEH chain no handler felt responsible).
Though that's pure speculation... it's like crystal ball reading when looking at such relay logs without actually live debugging that garbage. Guesswork because of similar patterns I remember/encountered in countless debug sessions of anti debug/protection crap.
Regards
http://bugs.winehq.org/show_bug.cgi?id=27435
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Attachment #35085|0 |1 is obsolete| | Attachment #35086|0 |1 is obsolete| |
--- Comment #5 from Austin English austinenglish@gmail.com 2011-06-09 18:53:13 CDT --- Created an attachment (id=35087) --> (http://bugs.winehq.org/attachment.cgi?id=35087) relay,seh,tid,server - part 1
I've attached a relay,seh,tid,server trace, this time in append mode :).
Here's part 1/2, rzip'ed then split.
http://bugs.winehq.org/show_bug.cgi?id=27435
--- Comment #6 from Austin English austinenglish@gmail.com 2011-06-09 18:54:26 CDT --- Created an attachment (id=35088) --> (http://bugs.winehq.org/attachment.cgi?id=35088) relay,seh,tid,server - part 2
http://bugs.winehq.org/show_bug.cgi?id=27435
--- Comment #7 from Anastasius Focht focht@gmx.net 2011-06-10 08:05:37 CDT --- Hello Austin,
--- quote --- I've attached a relay,seh,tid,server trace, this time in append mode :). --- quote ---
The log doesn't contain server trace messages. Make sure steam processes aren't already running in systray (wineserver -k).
Regards.
http://bugs.winehq.org/show_bug.cgi?id=27435
David davidsboogs@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |davidsboogs@gmail.com
http://bugs.winehq.org/show_bug.cgi?id=27435
--- Comment #8 from Austin English austinenglish@gmail.com 2011-06-10 17:45:05 CDT --- (In reply to comment #7)
Hello Austin,
--- quote --- I've attached a relay,seh,tid,server trace, this time in append mode :). --- quote ---
The log doesn't contain server trace messages. Make sure steam processes aren't already running in systray (wineserver -k).
Regards.
Verified that this one has everything :)
rather than trim it, I've put the full log on my website for now, 2 GB uncompressed. 32 MB compressed: http://austinenglish.com/logs/log2.txt.rz
if you'd rather the trimmed log, let me know.
http://bugs.winehq.org/show_bug.cgi?id=27435
Maarten Lankhorst m.b.lankhorst@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |RESOLVED CC| |m.b.lankhorst@gmail.com Resolution| |DUPLICATE
--- Comment #9 from Maarten Lankhorst m.b.lankhorst@gmail.com 2011-06-12 02:59:11 CDT --- exactly same issue as portal 2, they probably use the same copy protection
*** This bug has been marked as a duplicate of bug 26835 ***
http://bugs.winehq.org/show_bug.cgi?id=27435
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED
--- Comment #10 from Austin English austinenglish@gmail.com 2011-06-16 13:20:49 CDT --- Closing.