2nd instance of Guild Wars 2 failes to display

[jdmcmillian]

I have a custom myth box that loads Myth directly before any desktop environment. I do this by call startx with the mythfrontend, along with appropriate parameters as the environment.
Then through Myth, I execute a script written to start Guild Wars 2 (gw2) automatically without user interaction.
The 1st instance of gw2 started runs the updater. The script then waits for the the PID of that instance to terminate, at which point the 2nd instance is executed.
This is where the problem begins. about 50% of the time, the 2nd instance hangs. According to the output, and multiple FIXME lines reported from the execution of the 2nd instances, the following 2 scenarios occur.
The first is that gw2 starts fine and takes me to the selection screen as it should, and the game is perfectly playable. This is of course the ideal result.
The second is that gw2 execution begins and hangs after "fixme:crypt:CryptProtectMemory (0x1b28890 512 00000000): stub" is displayed, up to this output, both scenarios are exactly the same. The next FIXME line, according to scenario 1, is "fixme:win:EnumDisplayDevicesW ((null),0,0x3c0dc08,0x00000000), stub!" followed by another "fixme:win:EnumDisplayDevicesW ((null),0,0x3c0de68,0x00000000), stub!"

My suspicion is that because I am using a low level Xserver only, and not an overlaying desktop, there is a race condition occuring. But I have tried everything else that I know to do, and I am looking to get this corrected.

Its important to note that if GW2 is run interactivly, IE without the command line switches to automate the update and autologin, then GW2 always run fine. But since this is a shared machine in a house full of kids, revealing the login credentials or repairing the login credentials routinely is not an option. IE, the need to run updates and login automatically.

If the updates are not executed, GW2 loads and runs without issues.

this is the startup script used: gw2-auto.sh

Code: Select all

#!/bin/sh

LOG="/home/mediacenter/log/games/GuildWars2.log"
DAT="autologin.dat"
USERDAT="Guild Wars 2 (AutoLogin)"
EMAIL="[email protected]"
PASSWORD="mygwpassword"

TARGETGW="Guild Wars 2"
TARGETAL="AddressLookupWnd"

env WINEPREFIX="/home/mediacenter/.wine" 

## Update DAT file
/usr/bin/wine "C:/Program Files (x86)/Guild Wars 2/Gw2.exe" -dx9single -image -email "$EMAIL" -password "$PASSWORD" -dat "C:\\Program Files (x86)\\Guild Wars 2\\$DAT"&
GWPID=$!
wait $GWPID

## Begin Game
/usr/bin/wine "c:/Program Files (x86)/Guild Wars 2/Gw2.exe" -dx9single -email "$EMAIL" -password "$PASSWORD" -nopatchui -dat "C:\\Program Files (x86)\\Guild Wars 2\\$DAT"&
GWPID=$!
GWWINID=$(xdotool search --sync -all --pid $GWPID --name "$TARGETGW")
ALWINID=$(xdotool search --sync -all --pid $GWPID --name "$TARGETAL")

xdotool windowmove $ALWINID 0 0
xdotool windowraise $ALWINID

wait $GWPID
wineserver --kill
exit 0

[Bob Wya]

Wine has to startup and shutdown it's environment cleanly... So have you tried manually starting the background wineserver process and then waiting for that to exit?? That should eliminate any suspected race conditions...

Sort of like:

Code: Select all

...
## Update DAT file
/usr/bin/wineserver
WSPID=$!
/usr/bin/wine "C:/Program Files (x86)/Guild Wars 2/Gw2.exe" -dx9single -image -email "$EMAIL" -password "$PASSWORD" -dat "C:\\Program Files (x86)\\Guild Wars 2\\$DAT"&
wait $WSPID

## Begin Game
/usr/bin/wine "c:/Program Files (x86)/Guild Wars 2/Gw2.exe" -dx9single -email "$EMAIL" -password "$PASSWORD" -nopatchui -dat "C:\\Program Files (x86)\\Guild Wars 2\\$DAT"&
...

Bob

[jdmcmillian]

Thanks for the tip, but it didn't work. I even tried to wrap both wine calls inside of separate wineserver/wait WSPID commands.. The effect is the same, sometimes the 2nd instance works fine, sometimes it hangs.

I'm still at a loss for the cause of this problem.

Can someone direct me so I get more information from wine so I can find what function it is hanging on?

[Bob Wya]

...

Can someone direct me so I get more information from wine so I can find what function it is hanging on?

Well then you are looking at selectively enabling the Wine debugging channels ...

If you don't enable stuff (like +relay that just blows your output up to Mbyte sized logs) - then the output is pretty readable.

I managed to help a guy on the Gentoo forums recently... Turned out Wine thought his (misconfigured) X Display was 0 x 0 sized. It was drawing a winecfg window correctly - just a very, very infinitely tiny one. All of which was immediately obvious from the Wine console logs...

If GW2 hangs with a crypt fixme consistently (or whatever the case might be) - then you might try enabling each of the crypt* debug channels selectively... It could be a real slog - with little payback though...

Is the hang dependent on a particular command line parameter (i.e. add them one by one)?

If you think the hang is timing dependent. Then try adding some sleep statements - say at the start of the script (if you're spawning an X-Session with the script say). Or even just spawn an xterm at the start of the script. Anything that might change the conditions of potential failure slightly.

Are you saving date+time stamped logs from the script runs - to weed out successful runs from failed ones?

Do you really need to fork off the wine commands as background processes?

If you can't fix the problem then you've really got to get some consistent failure point in the Wine console output - or a bug report will not get much attention... I'd need to see some full console logs to be able to help any more... Both failed and successful runs.

[jdmcmillian]

Thanks again, I tried your suggestions, the sleep statements made no bearing on the situation, as for the command line options, the same options are present whether it hangs or not.

your X display configuration recollection has me thinking in that direction now.

Failure with either no debugging flags or just +crypt results in BLOCK A
Success results in BLOCK A+B, in the case of +crypt, a lot of crypt messages appear in BLOCK B

BLOCK A, appears during failure and success

Code: Select all

fixme:heap:RtlSetHeapInformation 0x110000 0 0x32fda4 4 stub
fixme:heap:RtlSetHeapInformation 0x110000 1 (nil) 0 stub
fixme:heap:RtlSetHeapInformation 0x20f0000 0 0x32fde8 4 stub
fixme:heap:RtlSetHeapInformation 0x20f0000 1 (nil) 0 stub
fixme:process:SetProcessDEPPolicy (1): stub
fixme:ver:GetCurrentPackageId (0x2bbea08 (nil)): stub
fixme:thread:SetThreadStackGuarantee (0x2cbe9d0): stub
fixme:imm:ImmDisableTextFrameService Stub
fixme:winsock:WS_getsockopt WS_SO_CONNECT_TIME - faking results
fixme:crypt:CryptProtectMemory (0x1b28890 512 00000000): stub
fixme:d3d9:D3DPERF_GetStatus (void) : stub
fixme:ntdll:NtQueryInformationJobObject stub: 0x1c8 2 0x3c0ce98 48 (nil)
fixme:ntdll:NtQueryInformationJobObject stub: 0x1c8 9 0x3c0ce28 112 (nil)
fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
fixme:process:SetProcessDEPPolicy (3): stub
fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
fixme:imm:ImmDisableTextFrameService Stub
fixme:thread:GetThreadPreferredUILanguages 56, 0x33f624, (nil) 0x33f620
fixme:winsock:WSALookupServiceBeginW (0x33f690 0x00000ff0 0x33f6d8) Stub!
fixme:iphlpapi:NotifyAddrChange (Handle 0x33f568, overlapped 0x2bf9b88): stub
fixme:win:RegisterDeviceNotificationW (hwnd=0x1006e, filter=0x33f748,flags=0x00000000) returns a fake device notification handle!
fixme:win:RegisterDeviceNotificationW (hwnd=0x1006e, filter=0x33f748,flags=0x00000000) returns a fake device notification handle!
fixme:win:EnumDisplayDevicesW ((null),0,0x33edb4,0x00000000), stub!
fixme:advapi:RegisterTraceGuidsW (0x495320, 0x24ef248, {3dada31d-19ef-4dc1-b345-037927193422}, 1, 0x24a4f04, (null), (null), 0x24ef260): stub
fixme:advapi:RegisterTraceGuidsW   register trace class {00000000-0000-0000-0000-000000000000}
fixme:winsock:WSALookupServiceBeginW (0x33dba0 0x00000ff0 0x33dbe8) Stub!
fixme:win:UnregisterDeviceNotification (handle=0xcafeaffe), STUB!
fixme:win:UnregisterDeviceNotification (handle=0xcafeaffe), STUB!
fixme:iphlpapi:CancelIPChangeNotify (overlapped 0x2bf9b88): stub
fixme:advapi:UnregisterTraceGuids deadbeef: stub
fixme:heap:RtlSetHeapInformation 0x110000 0 0x32fda4 4 stub
fixme:heap:RtlSetHeapInformation 0x110000 1 (nil) 0 stub
fixme:heap:RtlSetHeapInformation 0x20f0000 0 0x32fde8 4 stub
fixme:heap:RtlSetHeapInformation 0x20f0000 1 (nil) 0 stub
fixme:process:SetProcessDEPPolicy (1): stub
fixme:ver:GetCurrentPackageId (0x2bbea08 (nil)): stub
fixme:thread:SetThreadStackGuarantee (0x2cbe9d0): stub
fixme:winsock:WS_getsockopt WS_SO_CONNECT_TIME - faking results
fixme:crypt:CryptProtectMemory (0x1b28890 512 00000000): stub
fixme:win:EnumDisplayDevicesW ((null),0,0x3c0e238,0x00000000), stub!
fixme:wbemprox:wbem_services_CreateInstanceEnum unsupported flags 0x00000030
fixme:wbemprox:enum_class_object_Next timeout not supported
fixme:win:EnumDisplayDevicesW ((null),0,0x3c0d0a8,0x00000000), stub!
fixme:win:EnumDisplayDevicesW ((null),0,0x3c0ce98,0x00000000), stub!
fixme:ddraw:ddraw7_Initialize Ignoring guid {aeb2cdd4-6e41-43ea-941c-8361cc760781}.
fixme:devenum:DEVENUM_ICreateDevEnum_CreateClassEnumerator Category {33d9a761-90c8-11d0-bd43-00a0c911ce86} not found
fixme:devenum:DEVENUM_ICreateDevEnum_CreateClassEnumerator Category {cc7bfb41-f175-11d1-a392-00e0291f3959} not found
fixme:devenum:DEVENUM_ICreateDevEnum_CreateClassEnumerator Category {cc7bfb46-f175-11d1-a392-00e0291f3959} not found
fixme:imm:ImmDisableTextFrameService Stub
fixme:wtsapi:WTSRegisterSessionNotification Stub 0x30054 0x00000000
fixme:crypt:CryptUnprotectMemory (0x1b28890 512 00000000): stub
fixme:crypt:CryptProtectMemory (0x1b28890 512 00000000): stub

BLOCK B, follows A only upon success

Code: Select all

fixme:win:EnumDisplayDevicesW ((null),0,0x3c0dc08,0x00000000), stub!
fixme:win:EnumDisplayDevicesW ((null),0,0x3c0de68,0x00000000), stub!
fixme:avrt:AvSetMmThreadCharacteristicsW (L"Audio",0x8aee9a8): stub
fixme:d3d:wined3d_swapchain_set_gamma_ramp Ignoring flags 0x1.
fixme:d3d:wined3d_swapchain_set_gamma_ramp Ignoring flags 0x1.
fixme:d3d:wined3d_swapchain_set_gamma_ramp Ignoring flags 0x1.
fixme:d3d9:D3DPERF_GetStatus (void) : stub
fixme:ntdll:NtQueryInformationJobObject stub: 0x2c4 2 0x3c0ce30 48 (nil)
fixme:ntdll:NtQueryInformationJobObject stub: 0x2c4 9 0x3c0cdc0 112 (nil)
fixme:d3d:wined3d_swapchain_set_gamma_ramp Ignoring flags 0x1.
fixme:d3d:wined3d_swapchain_set_gamma_ramp Ignoring flags 0x1.
fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
fixme:process:SetProcessDEPPolicy (3): stub
fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
fixme:imm:ImmDisableTextFrameService Stub
fixme:thread:GetThreadPreferredUILanguages 56, 0x33f624, (nil) 0x33f620
fixme:winsock:WSALookupServiceBeginW (0x33f690 0x00000ff0 0x33f6d8) Stub!
fixme:iphlpapi:NotifyAddrChange (Handle 0x33f568, overlapped 0x2bf9b88): stub
fixme:win:RegisterDeviceNotificationW (hwnd=0x1006e, filter=0x33f748,flags=0x00000000) returns a fake device notification handle!
fixme:win:RegisterDeviceNotificationW (hwnd=0x1006e, filter=0x33f748,flags=0x00000000) returns a fake device notification handle!
fixme:win:EnumDisplayDevicesW ((null),0,0x33edb4,0x00000000), stub!
fixme:win:FlashWindowEx 0x3c0e3e4 - semi-stub
fixme:advapi:RegisterTraceGuidsW (0x495320, 0x24ef248, {3dada31d-19ef-4dc1-b345-037927193422}, 1, 0x24a4f04, (null), (null), 0x24ef260): stub
fixme:advapi:RegisterTraceGuidsW   register trace class {00000000-0000-0000-0000-000000000000}
fixme:winsock:WSALookupServiceBeginW (0x33dba0 0x00000ff0 0x33dbe8) Stub!
fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
fixme:process:SetProcessDEPPolicy (3): stub
fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
fixme:advapi:RegisterTraceGuidsW (0x495320, 0x24ef248, {3dada31d-19ef-4dc1-b345-037927193422}, 1, 0x24a4f04, (null), (null), 0x24ef260): stub
fixme:advapi:RegisterTraceGuidsW   register trace class {00000000-0000-0000-0000-000000000000}
fixme:gdi:GdiInitializeLanguagePack stub
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
fixme:winsock:WSALookupServiceBeginW (0x3cde0a0 0x00000ff0 0x3cde0e8) Stub!
fixme:win:UnregisterDeviceNotification (handle=0xcafeaffe), STUB!
fixme:win:UnregisterDeviceNotification (handle=0xcafeaffe), STUB!
fixme:iphlpapi:CancelIPChangeNotify (overlapped 0x2bf9b88): stub
fixme:advapi:UnregisterTraceGuids deadbeef: stub

This got me thinking about the WIN message that shows up at the first entry in BLOCK B.

I was unable to upload the log files for both +win and +crypt both for success and failure, so what should I be looking for in them?

[Bob Wya]

@jdmcmillian,

That's great - a known reproduceable failure point is essential - if you / a-n-other has to diff very large Wine debug logs (i.e. debugging all channels). Even though it's not clear what the exact failure is ... yet (!!) That's the sort of Wine bug that gets a response - because the failure condition can be pin-pointed very precisely...

It'd be super helpful to triage the obvious stuff - before going down into the weeds!!

Perhaps you could answer the follow questions...

1. What Linux distro are you running?
2. Graphics card vendor and model?
3. Graphics card driver version?
4. What version of Wine are using?
5. Is it vanilla Wine or Wine + Staging?
6. Are any other patches applied?

Probably we haven't missed anything obvious - but you never know!

[jdmcmillian]

@Bob Wya

Sorry for the late reply, work got busy.

1. Ubuntu 15.10(Server) Linux mediacenter 4.2.0-22-generic #27-Ubuntu SMP Thu Dec 17 22:57:08 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
2. The Motherboard is an "MSI A88XM GAMING" with onboard HDMI video
The chipset is : AMD A-10-7850K APU with Radeon(TM) R7 Graphics
2.1 more hardware info: 8GB ram,
3. Advanced Micro Devices, Inc. [AMD/ATI]: Kaveri [Radeon R7 Graphics] is using X.Org X Server -- AMD/ATI display driver wrapper from xserver-xorg-video-ati (open source, tested), typically running at 1920x1080
3.1 OpenGL Renderer : Gallium 0.4 on llvmpipe (LLVM 3.6, 128 bits)
4. wine-1.9.3 , from this repo: "deb http://ppa.launchpad.net/wine/wine-builds/ubuntu wily main"
5. winehq-devel from repository (see #4 and below)
6. No patches applied that I can remember
7. systemd was activated(as the primary init system) and (initd was affectively removed)

The following packages have been installed:
ubuntu-restricted-extras padevchooser fceux jstest-gtk joystick xboxdrv chromium chromium-browser chromium-chromedriver chromium-codecs-ffmpeg pepflashplugin-installer pepperflashplugin-nonfree browser-plugin-freshplayer-pepperflash xdotool lib32nss-mdns hwinfo winbind

--install-recommends winehq-devel

Playing around with it, it seems that it does start the second instance, but the loading screen is left as an artificact, and almost as though the 2nd instance is running in the background unable be displayed.