[Bug 33034] Multiple GFWL (Games For Windows Live) 3.x games crash or exit silently on startup (DiRT 2/3, GTA IV Steam)

wine-bugs at winehq.org wine-bugs at winehq.org
Sat May 31 06:44:20 CDT 2014


https://bugs.winehq.org/show_bug.cgi?id=33034

Anastasius Focht <focht at gmx.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Keywords|                            |obfuscation
                 CC|                            |focht at gmx.net
          Component|-unknown                    |ntdll
            Summary|DiRT 3 fails at launch      |Multiple GFWL (Games For
                   |                            |Windows Live) 3.x games
                   |                            |crash or exit silently on
                   |                            |startup (DiRT 2/3, GTA IV
                   |                            |Steam)

--- Comment #3 from Anastasius Focht <focht at gmx.net> ---
Hello Andrey,

it's Microsoft Games for Windows LIVE (GFWL) 3.x being the deal breaker here.

Your terminal output and the app behaviour (silent exit) indicates this.

--- snip ---
...
fixme:advapi:RegisterTraceGuidsA (0x143ce70, (nil),
{d5b9ac76-d546-4891-bb8c-bfd865e5c7d5}, 3, 0x1982b00, (null), (null),
0x198f850,): stub
fixme:advapi:RegisterEventSourceW ((null),L"XLive"): stub
fixme:advapi:ReportEventW
(0xcafe4242,0x0002,0x0000,0x80000002,(nil),0x0004,0x00000000,0x33cfb4,(nil)):
stub
fixme:advapi:DeregisterEventSource (0xcafe4242) stub
fixme:advapi:UnregisterTraceGuids 0: stub
--- snip ---

I bought 'DiRT 2' a few days ago which has the same issue and spent some hours
debugging it.

Tidbit: the game has SecuROM copy protection which works nicely with Wine.

--- snip ---
-=[ ProtectionID v0.6.5.5 OCTOBER]=-
(c) 2003-2013 CDKiLLER & TippeX
Build 31/10/13-21:09:09
Ready...
Scanning -> C:\Program Files\Codemasters\DiRT2\dirt2_game.exe
File Type : 32-Bit Exe (Subsystem : Win GUI / 2), Size : 22983984 (015EB530h)
Byte(s)
-> File Appears to be Digitally Signed @ Offset 015EA000h, size : 01530h /
05424 byte(s)
[File Heuristics] -> Flag : 00000100000000001001000000000100 (0x04009004)
[Entrypoint Section Entropy] : 6.49
[Debug Info]
Characteristics : 0x0 | TimeDateStamp : 0x4B042091 | MajorVer : 0 / MinorVer :
0 -> (0.0)
Type : 2 -> CodeView | Size : 0x4A (74)
AddressOfRawData : 0xFEBEB8 | PointerToRawData : 0xFEBEB8
CvSig : 0x53445352 | SigGuid 3CD8ECB5-3B2E-4742-B349A785D8FB0F84
Age : 0x1 | Pdb : d:\perforce\dirt2\programming\data\dirt2_game.pdb

[!] Games For Windows Live detected !
[CompilerDetect] -> Visual C++ 8.0 (Visual Studio 2005)
- Scan Took : 1.196 Second(s) [00000070Ch tick(s)] [533 scan(s) done]

Scanning -> C:\Program Files\Codemasters\DiRT2\dirt2.exe
File Type : 32-Bit Exe (Subsystem : Win GUI / 2), Size : 6055256 (05C6558h)
Byte(s)
-> File Appears to be Digitally Signed @ Offset 05C5000h, size : 01558h / 05464
byte(s)
[File Heuristics] -> Flag : 00000000000000000000000000000101 (0x00000005)
[Entrypoint Section Entropy] : 6.62
[!] SecuROM Detected - Version 07.40.0009
[!] Possible CD/DVD-Key or Serial Check -> Invalid serial
[CompilerDetect] -> Visual C++ 7.1 (Visual Studio 2003)
- Scan Took : 0.543 Second(s) [00000021Fh tick(s)] [533 scan(s) done] 
--- snip ---

The game installs .NET Framework 3.5 and GFWL 3.x on its own.

After startup it silently exits at the point where XLive is being initialized.

--- snip ---
$ pwd
/home/focht/.wine/drive_c/Program Files/Codemasters/DiRT2

$ WINEDEBUG=+tid,+seh,+relay,+server,+snoop wine ./dirt2.exe >>log.txt 2>&1
...
0009:Call KERNEL32.CreateProcessW(00000000,7ffc0000 L"\"dirt2_game.exe\"
",00000000,00000000,00000001,00000204,00000000,0091e0f0 L"C:\\Program
Files\\Codemasters\\DiRT2",0091fb74,0040fd40) ret=004022c5 
...
002c: init_process_done() = 0 
...
0009:Ret  KERNEL32.CreateProcessW() retval=00000001 ret=004022c5 
...
002c:Call KERNEL32.OpenFileMappingW(00000004,00000000,0033d854
L"-=[SMS_dirt2_game.exe_SMS]=-") ret=00b062de
...
002c:Ret  KERNEL32.OpenFileMappingW() retval=00000140 ret=00b062de 
...
002c:Call PE DLL (proc=0x1c6a924,module=0x1c20000
L"xlive.dll",reason=PROCESS_ATTACH,res=0x1)
...
002c:CALL xlive.5297(<unknown, check return>) ret=006af424
002c:Call
advapi32.RegisterTraceGuidsA(01d372c6,00000000,01c260ec,00000003,02281aa4,00000000,00000000,0228d1a0)
ret=01d3734b
002c:fixme:advapi:RegisterTraceGuidsA (0x1d372c6, (nil),
{d5b9ac76-d546-4891-bb8c-bfd865e5c7d5}, 3, 0x2281aa4, (null), (null),
0x228d1a0): stub
002c:Ret  advapi32.RegisterTraceGuidsA() retval=00000000 ret=01d3734b 
...
002c:Call KERNEL32.CreateEventW(00000000,00000001,00000000,00162830
L"Global\\XLive-S-1-5-21-0-0-0-1000") ret=01d16843 
...
002c:Call KERNEL32.CreateFileW(0033defc
L"C:\\windows\\system32\\xlive.dll.CAT",80000000,00000001,00000000,00000003,00000080,00000000)
ret=01d086c5 
...
002c:Call KERNEL32.CreateFileW(0033dcf4
L"C:\\windows\\system32\\xlive.dll",80000000,00000001,00000000,00000003,00000080,00000000)
ret=01d08103 
...
002c:Call KERNEL32.K32GetModuleInformation(ffffffff,01c20000,0033da38,0000000c)
ret=01d08374 
...
002c:Ret  KERNEL32.K32GetModuleInformation() retval=00000001 ret=01d08374 
...
002c:Call KERNEL32.K32EnumProcessModules(ffffffff,0033d8d8,000003fc,0033dce4)
ret=0225a64c 
...
002c:Ret  KERNEL32.K32EnumProcessModules() retval=00000001 ret=0225a64c 
...
002c:Call KERNEL32.CreateFileW(0033dcf8 L"C:\\Program
Files\\Codemasters\\DiRT2\\dirt2_game.exe.CAT",80000000,00000001,00000000,00000003,00000080,00000000)
ret=01d086c5 
...
002c:Call KERNEL32.CreateFileW(0033df00 L"C:\\Program
Files\\Codemasters\\DiRT2\\dirt2_game.exe.CFG",80000000,00000001,00000000,00000003,00000080,00000000)
ret=01d2dfa7 
...
002c:Call oleaut32.SysAllocString(001c6970
L"<Liveconfig>\r\n\t<titleid>434D0820</titleid>\r\n\t<titleversion>10000085</titleversion>\r\n\t<enableCrossPlatformSystemLink>false</enableCrossPlatformSystemLink>\r\n\t<SSA>1</SSA>\r\n\t<lankey>xxxxx</lankey>\r\n\t<OriginalXliveTarget>3.1.0089.0</OriginalXliveTarget>\r\n\t<"...)
ret=01d35c18 
...
002c: load_dll( mapping=0000, base=7cf90000, name=001c9b60, size=790528,
dbg_offset=0, dbg_size=0, filename=L"C:\\windows\\system32\\msxml3.dll" )
002c: load_dll() = 0 
...
002c:Call KERNEL32.CreateFileW(0033df00 L"C:\\Program
Files\\Codemasters\\DiRT2\\dirt2_game.exe",80000000,00000001,00000000,00000003,00000080,00000000)
ret=01d08103 
...
002c:Call KERNEL32.CreateFileW(0033dcf8 L"C:\\Program
Files\\Codemasters\\DiRT2\\dirt2_game.exe.CAT",80000000,00000001,00000000,00000003,00000080,00000000)
ret=01d08a91 
...
002c:Call KERNEL32.LoadLibraryW(0033d634 L"C:\\Program
Files\\Codemasters\\DiRT2\\dirt2_game.exe") ret=01d0a6fb
002c:Ret  KERNEL32.LoadLibraryW() retval=00400000 ret=01d0a6fb
002c:Call KERNEL32.lstrcmpiW(001a48fe L"dirt2_game.exe",01c22f10
L"shimeng.dll") ret=01d0a019
002c:Ret  KERNEL32.lstrcmpiW() retval=ffffffff ret=01d0a019 
...
--- snip ---

xlive.5297 API entry = XLiveInitializeEx()

Xlive validates certain executables on disk and in memory (process module list)
as part of anti-tampering measure (digital signature).

The problem is not really visible in trace log and disguised due to the way
these large encrypted code sections work, which are part of the DRM protection
scheme.
The difficulty here is that even errors are propagated through a number of
"asm" continuations/thunks which consist of dynamically decrypting executable
code.
Lots of code with no win32 API usage at all and values being hidden in
intermediate memory locations.

Furthermore, error paths are sometimes disguised by additional checks/API calls
that are also present in "working" case, hence no linear "error out" exit code
path.

For example the creation of a debugger "zapper" thread which seemed suspicious
but in the end turned out to be perfectly fine:

--- snip ---
...
002c:Call
KERNEL32.CreateThread(00000000,00000000,01e175f8,00000154,00000000,0033e144)
ret=02278d2c
002c: *fd* 14 <- 124
002c: new_thread( access=001fffff, attributes=00000000, suspend=1,
request_fd=14 )
002c: new_thread() = 0 { tid=002d, handle=0164 }
002c: resume_thread( handle=0164 )
002c: resume_thread() = 0 { count=1 }
002d: *fd* 18 <- 139
002c:Ret  KERNEL32.CreateThread() retval=00000164 ret=02278d2c
002d: *fd* 20 <- 141
002d: init_thread( unix_pid=19894, unix_tid=19896, debug_level=1, teb=7ffd4000,
entry=01e175f8, reply_fd=18, wait_fd=20, cpu=x86 )
002c:Call KERNEL32.WaitForSingleObject(00000164,ffffffff) ret=0227af5c 
...
002d:Starting thread proc 0x1e175f8 (arg=0x154)
002d:Call KERNEL32.SuspendThread(00000154) ret=01e1761e
002d: suspend_thread( handle=0154 )
002c: *sent signal* signal=10
002d: suspend_thread() = 0 { count=0 }
002d:Ret  KERNEL32.SuspendThread() retval=00000000 ret=01e1761e
002d:Call KERNEL32.GetThreadContext(00000154,0440e788) ret=01e1763b
002c: set_suspend_context(
context={cpu=x86,eip=f77b742e,esp=0033dca4,ebp=0033dcf8,eflags=00200296,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=00000003,ebx=00000006,ecx=0033dcd8,edx=00000010,esi=0033e0c0,edi=0033e108,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,fp.ctrl=ffff027f,fp.status=ffff0020,fp.tag=ffffffff,fp.err_off=7ce96bde,fp.err_sel=00000023,fp.data_off=7cf7b2b8,fp.data_sel=ffff002b,fp.cr0npx=00000020,fp.reg0=0,fp.reg1=0.660168,fp.reg2=0.961903,fp.reg3=0.85725,fp.reg4=0.5,fp.reg5=0,fp.reg6=0,fp.reg7=-0,extended={...}
)
002c: set_suspend_context() = 0
002d: get_thread_context( handle=0154, flags=00000010, suspend=1 )
002c: *signal* signal=19
002d: get_thread_context() = 0 { self=0,
context={cpu=x86,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000}
}
002c: select( flags=2, cookie=7ffdb33c, timeout=0, prev_apc=0000, result={},
data={} )
002d:Ret  KERNEL32.GetThreadContext() retval=00000001 ret=01e1763b
002c: select() = PENDING { timeout=1cf7c3475b620f0 (+0.0000000),
call={APC_NONE}, apc_handle=0000 }
002d:Call KERNEL32.ResumeThread(00000154) ret=01e17677
002d: resume_thread( handle=0154 )
002c: *wakeup* signaled=258
002d: resume_thread() = 0 { count=1 }
002d:Ret  KERNEL32.ResumeThread() retval=00000001 ret=01e17677
002d:Call KERNEL32.CloseHandle(00000154) ret=01e1767e
002c: get_suspend_context( )
002c: get_suspend_context() = 0 {
context={cpu=x86,eip=f77b742e,esp=0033dca4,ebp=0033dcf8,eflags=00200296,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=00000003,ebx=00000006,ecx=0033dcd8,edx=00000010,esi=0033e0c0,edi=0033e108,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,fp.ctrl=ffff027f,fp.status=ffff0020,fp.tag=ffffffff,fp.err_off=7ce96bde,fp.err_sel=00000023,fp.data_off=7cf7b2b8,fp.data_sel=ffff002b,fp.cr0npx=00000020,fp.reg0=0,fp.reg1=0.660168,fp.reg2=0.961903,fp.reg3=0.85725,fp.reg4=0.5,fp.reg5=0,fp.reg6=0,fp.reg7=-0,extended=...}
}
002d: close_handle( handle=0154 )
002d: close_handle() = 0
002d:Ret  KERNEL32.CloseHandle() retval=00000001 ret=01e1767e
002d: terminate_thread( handle=fffffffe, exit_code=-206558064 )
002d: terminate_thread() = 0 { self=1, last=0 }
...
002d: *killed* exit_code=-206558064
002c: *wakeup* signaled=0
002c:Ret  KERNEL32.WaitForSingleObject() retval=00000000 ret=0227af5c
002c:Call KERNEL32.GetExitCodeThread(00000164,0033e14c) ret=0227af67
002c: get_thread_info( handle=0164, tid_in=0000 )
002c: get_thread_info() = 0 { pid=002b, tid=002d, teb=7ffd4000,
affinity=0000000f, creation_time=1cf7c3475b5f9a4 (-0.0020170),
exit_time=1cf7c3475b644b8 (-0.0000950), exit_code=-206558064, priority=0,
last=1 }
002c:Ret  KERNEL32.GetExitCodeThread() retval=00000001 ret=0227af67
002c:Call KERNEL32.CloseHandle(00000164) ret=01d1747a
002c: close_handle( handle=0164 )
002c: close_handle() = 0
002c:Ret  KERNEL32.CloseHandle() retval=00000001 ret=01d1747a 
--- snip ---

The "helper" thread explained in a nutshell:

1) suspends main thread
2) examines debug control register dr7, sets thread exit code accordingly
3) zeroes dr0-dr7 unconditionally
4) resumes main thread

The thread exit code -206558064 is the "good" one (no HW breakpoint usage
detected).

A short time later one comes across this:

--- snip ---
002c:Call advapi32.RegisterEventSourceW(00000000,01c25ebc) ret=01d3fd1d
002c:fixme:advapi:RegisterEventSourceW ((null),L"XLive"): stub
002c:Ret  advapi32.RegisterEventSourceW() retval=cafe4242 ret=01d3fd1d
002c:Call
advapi32.ReportEventW(cafe4242,00000002,00000000,80000002,00000000,00000004,00000000,0033d090,00000000)
ret=01d3fd5d
002c:fixme:advapi:ReportEventW
(0xcafe4242,0x0002,0x0000,0x80000002,(nil),0x0004,0x00000000,0x33d090,(nil)):
stub
002c:Ret  advapi32.ReportEventW() retval=00000001 ret=01d3fd5d
002c:Call advapi32.DeregisterEventSource(cafe4242) ret=01d3fd7d
002c:fixme:advapi:DeregisterEventSource (0xcafe4242) stub
002c:Ret  advapi32.DeregisterEventSource() retval=00000001 ret=01d3fd7d 
--- snip ---

Wine doesn't decode/trace the Event API parameters, debugger dumped values:

--- snip ---
0033D090   0033DA54  UNICODE "dirt2_game.exe"
0033D094   0033E0EC  UNICODE "1, 0, 0, 0"
0033D098   0033DC5C  UNICODE "3.1.0099.0 (WGX_XLIVE_V3.01_RTM.091106-1035)
C:\windows\system32\xlive.dll"
0033D09C   0013FD90  UNICODE "0x80004005 Games for Windows - LIVE DLL
C:\windows\system32\msidcrl40.dll 5.000.737.6"
--- snip ---

Finally XLive entry point returns with generic 0x80004005 error code:

--- snip ---
002c:RET  xlive.5297(0033e87c,31005900) retval=80004005 ret=006af424
--- snip ---

After some hours of debugging this garbage I found the problem.

Certain mapped modules (main executable, xlive dlls) are examined as part of
in-memory tampering validation (PE headers/sections populated).
Before that, general image information is retrieved from OS loader (PEB/ldr
structures) using 'K32GetModuleInformation': mapped image base address, image
size, entry point address

--- snip ---
002c:Call KERNEL32.K32GetModuleInformation(ffffffff,00400000,0033d61c,0000000c)
ret=01d08374
002c: get_process_info( handle=ffffffff )
002c: get_process_info() = 0 { pid=002b, ppid=0008, affinity=0000000f,
peb=7ffdf000, start_time=1cf7c3475214200 (-0.9735880), end_time=0,
exit_code=259, priority=2, cpu=x86, debugger_present=0 }
002c: read_process_memory( handle=ffffffff, addr=7ffdf00c )
002c: *signal* signal=19
002c: read_process_memory() = 0 { data={c0,d2,ce,7b} }
002c: read_process_memory( handle=ffffffff, addr=7bced2cc )
002c: *signal* signal=19
002c: read_process_memory() = 0 { data={d8,55,11,00} }
002c: read_process_memory( handle=ffffffff, addr=001155d8 )
002c: *signal* signal=19
002c: read_process_memory() = 0 {
data={58,01,11,00,cc,d2,ce,7b,38,e8,11,00,b0,c1,11,00,c8,a0,1c,00,80,4a,13,00,00,00,40,00,00,00,00,00,00,f0,81,01,62,00,64,00,38,56,11,00,1c,00,1e,00,7e,56,11,00,00,00,08,00,ff,ff,00,00,00,00,00,00,00,00,00,00,00,00,00,00,00,00,00,00}
}
002c:Ret  KERNEL32.K32GetModuleInformation() retval=00000001 ret=01d08374 
...
--- snip ---

Unfortunately there is a little thing missing that will do the harm later: the
ldr module structure for the main executable doesn't have the entry point
member set ('ldr.EntryPoint' -> NULL).
Little thing can make a big impact. ;-)

Before you quick-hack Wine's loader: be careful, there is code that _relies_ on
the main exe module entry point member being NULL to have loader notifications
work (and other nasty surprises).

Anyway, I tested a fix and it made GFWL work.
Unfortunately I own very few GFWL games to play with but it made _all_ of them
work (with GFWL in-game logins).

No native overrides, no XLiveless replacements and/or other Wine hacks in
WINEPREFIX.

* DiRT 2 (you need 'directx forcedx9="true"' game config file setting to work
around DirectX11 insufficiency)

* GTA IV Steam (without my fix you would get the infamous "XNetStartup failed -
Please re-boot your system and/or re-install the game 10093" message + crash)

NOTE: There is a delay of several seconds on startup due to GFWL - this is
expected (shortly after 'C:\\windows\\system32\\XLive\\sqmapi.dll' is loaded
and harmless 'winhttp' fixme message is shown in terminal).

$ wine --version
wine-1.7.19-71-g94ccd61

Regards

-- 
Do not reply to this email, post in Bugzilla using the
above URL to reply.
You are receiving this mail because:
You are watching all bug changes.



More information about the wine-bugs mailing list