[Bug 32515] Warhammer 40,000: Space Marine (Steam) fails to start

Wed Dec 4 10:43:48 CST 2013

http://bugs.winehq.org/show_bug.cgi?id=32515

--- Comment #10 from Anastasius Focht <focht at gmx.net> 2013-12-04 10:43:48 CST ---
Hello Gyb,

--- quote ---
Does it help reduce the size of a +relay log somewhat if I launch for example
an instance of notepad in a different terminal (before launching the actual
game/application)?
--- quote ---

depends on the case.

In most cases it makes sense to bootstrap the prefix ('warmup') using a Wine
builtin from separate terminal.
This avoids capturing unwanted log messages from builtins (services), prefix
updates (menubuilder) and the like.

There are other examples where this won't work hence a full bootstrap must be
done with logging from start.
For example if Steam is put in 'autorun' mode, e.g. started during prefix boot
you will not see debug output because the (already started) launcher parent
process which spawns app processes upon request (client) doesn't inherit
environment variables such as WINEDEBUG.

Anyway, the log looks good.
There are various exceptions (msvc thread name, softbp, single step traps)
which are on purpose because they are part of their DRM protection scheme.

There is one interesting thread tid=0x60 which causes 'bugsplat' trigger (seems
to be the equivalent of 'breakpad').

$ cat SpaceMarine_relay.log | grep 0060: > 0060.txt

--- snip ---
...
0060:Call advapi32.RegOpenKeyExW(80000002,01541dc0
L"Software\\Valve\\Steam",00000000,00020019,060de6b4) ret=00e6b736
0060:Ret  advapi32.RegOpenKeyExW() retval=00000000 ret=00e6b736
0060:Call advapi32.RegQueryValueExW(000007f0,01541da8
L"InstallPath",00000000,060de6b0,060de6c0,060de6bc) ret=00e6b765
0060:Ret  advapi32.RegQueryValueExW() retval=000000ea ret=00e6b765
0060:Call ntdll.RtlAllocateHeap(00110000,00000008,0000023a) ret=00e6b78c
0060:Ret  ntdll.RtlAllocateHeap() retval=0668f228 ret=00e6b78c
0060:Call advapi32.RegQueryValueExW(000007f0,01541da8
L"InstallPath",00000000,060de6b0,0668f228,060de6bc) ret=00e6b7ac
0060:Ret  advapi32.RegQueryValueExW() retval=00000000 ret=00e6b7ac
0060:Call advapi32.RegCloseKey(000007f0) ret=00e6b7ea
0060:Ret  advapi32.RegCloseKey() retval=00000000 ret=00e6b7ea
0060:Call KERNEL32.GetModuleHandleA(0147c064 "kernel32.dll") ret=00e48eee
0060:Ret  KERNEL32.GetModuleHandleA() retval=7b810000 ret=00e48eee
0060:Call KERNEL32.GetProcAddress(7b810000,01541d88
"Wow64DisableWow64FsRedirection") ret=00e48f04
0060:Ret  KERNEL32.GetProcAddress() retval=7b82597c ret=00e48f04
0060:Call KERNEL32.GetProcAddress(7b810000,01541d68
"Wow64RevertWow64FsRedirection") ret=00e48f10
0060:Ret  KERNEL32.GetProcAddress() retval=7b825994 ret=00e48f10
0060:Call KERNEL32.Wow64DisableWow64FsRedirection(060de970) ret=00e48f23
0060:Ret  KERNEL32.Wow64DisableWow64FsRedirection() retval=00000000
ret=00e48f23
0060:Call KERNEL32.CreateFileW(0668f228 L"C:\\Program
Files\\Steam\\package",80000000,00000007,00000000,00000003,00000000,ffffffff)
ret=00e4d09a
0060:Ret  KERNEL32.CreateFileW() retval=ffffffff ret=00e4d09a
0060:Call KERNEL32.CreateFileW(0668f228 L"C:\\Program
Files\\Steam\\package",80000000,00000007,00000000,00000003,02000000,ffffffff)
ret=00e4d0b9
0060:Ret  KERNEL32.CreateFileW() retval=000007f0 ret=00e4d0b9
0060:Call KERNEL32.GetFileInformationByHandle(000007f0,060de930) ret=00e4d0e7
0060:Ret  KERNEL32.GetFileInformationByHandle() retval=00000001 ret=00e4d0e7
0060:Call msvcrt.memcpy(060de6b8,060de710,00000008) ret=00e6d14a
0060:Ret  msvcrt.memcpy() retval=060de6b8 ret=00e6d14a
0060:Call msvcrt.memset(060de6c1,00000000,0000002f) ret=00e6d1b7
0060:Ret  msvcrt.memset() retval=060de6c1 ret=00e6d1b7
0060:Call KERNEL32.CloseHandle(000007f0) ret=00e4d103
0060:Ret  KERNEL32.CloseHandle() retval=00000001 ret=00e4d103 
...
--- snip ---

Pretty much the standard Steam DRM/integrity scheme where local
folder/filesystem/volume info (GetFileInformationByHandle -> inode numbers) is
used to generate and validate PE images and locally 'bind' them to a machine.

Unfortunately the 'integrity checker' thread dies with unexpected fault shortly
after this sequence:

--- snip ---
0060:Call KERNEL32.InterlockedCompareExchange(01b171ec,00000001,00000001)
ret=00e57d38
0060:Ret  KERNEL32.InterlockedCompareExchange() retval=00000000 ret=00e57d38
0060:Call KERNEL32.InterlockedExchange(01b171ec,00000001) ret=00e57d5e
0060:Ret  KERNEL32.InterlockedExchange() retval=00000000 ret=00e57d5e
0060:trace:seh:raise_exception code=c0000005 flags=0 addr=0x9c0047 ip=009c0047
tid=0060
0060:trace:seh:raise_exception  info[0]=00000001
0060:trace:seh:raise_exception  info[1]=c1ceb97c
0060:trace:seh:raise_exception  eax=10561b70 ebx=10566d30 ecx=0000002a
edx=00000900 esi=105667f0 edi=2c5e2783
0060:trace:seh:raise_exception  ebp=060dea2c esp=060de9e0 cs=0073 ds=007b
es=007b fs=0033 gs=003b flags=00010216
0060:trace:seh:call_vectored_handlers calling handler at 0xe550c0 code=c0000005
flags=0
0060:trace:seh:call_vectored_handlers handler at 0xe550c0 returned 0
0060:trace:seh:call_stack_handlers calling handler at 0x121706e code=c0000005
flags=0
0060:trace:seh:call_stack_handlers handler at 0x121706e returned 1
060:trace:seh:call_stack_handlers calling handler at 0xe6f9f4 code=c0000005
flags=0
0060:Call msvcrt._except_handler3(060de988,060dea48,060de6bc,060de60c)
ret=7bc7be8d
0060:trace:seh:_except_handler3 exception c0000005 flags=0 at 0x9c0047
handler=0xe6f9f4 0x60de6bc 0x60de60c semi-stub
0060:trace:seh:_except_handler3 level 0 prev -1 filter 0x9b0d6d
0060:trace:seh:_except_handler3 filter returned CONTINUE_SEARCH
0060:trace:seh:_except_handler3 reached TRYLEVEL_END, returning
ExceptionContinueSearch
0060:Ret  msvcrt._except_handler3() retval=00000001 ret=7bc7be8d
0060:trace:seh:call_stack_handlers handler at 0xe6f9f4 returned 1
0060:trace:seh:call_stack_handlers calling handler at 0x7bc923c0 code=c0000005
flags=0
0060:Call KERNEL32.UnhandledExceptionFilter(060de548) ret=7bc92405 
...
0060:Call KERNEL32.CreateFileA(060de31c
"C:\\users\\gyebro\\Temp\\bugsplat.log",c0000000,00000000,060de17c,00000004,00000080,00000000)
ret=10027825
0060:Ret  KERNEL32.CreateFileA() retval=000007f0 ret=10027825 
...
0060:Call
KERNEL32.CreateThread(00000000,00000000,1000e191,0246ac80,00000000,060de470)
ret=1000e29b
0060:Ret  KERNEL32.CreateThread() retval=000007f4 ret=1000e29b
0060:Call KERNEL32.WaitForSingleObject(000007f4,00007530) ret=10005fad
0060:Ret  KERNEL32.WaitForSingleObject() retval=00000000 ret=10005fad
0060:Call KERNEL32.TerminateProcess(ffffffff,fffffffd) ret=10005fd1
0060:Call PE DLL (proc=0xb4d6c080,module=0xb4d60000
L"imm32.dll",reason=PROCESS_DETACH,res=(nil))
0060:Call KERNEL32.TlsFree(0000000b) ret=b4d69fa2
0060:Ret  KERNEL32.TlsFree() retval=00000001 ret=b4d69fa2
0060:Call user32.UnregisterClassW(b4d6d48c L"IME",00000000) ret=b4d69fbb
0060:Call winex11.drv.CreateDesktopWindow(00010020) ret=7ec91cfc
0060:Ret  winex11.drv.CreateDesktopWindow() retval=00000001 ret=7ec91cfc
0060:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main
process heap section" wait timed out in thread 0060, blocked by 0063, retrying
(60 sec) 
--- snip ---

The critsec timeout/borked shutdown sequence is definitely another issue to be
looked at.

The reason for the fault isn't obvious to me.
Can you try to validate the local files?
It's called "verify integrity of game cache" in game properties/settings.

If anything fails, it will be re-downloaded.
Additionally this forces some PE binaries to be re-signed/updated with actual
filesystem metadata.
Make sure the game install is 100% valid before launching the game (try to
validate multiple times) ... this could be one reason for weird behaviour.

Regards

-- 
Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email
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.