search

doitsujin / dxvk

Vulkan-based implementation of D3D8, 9, 10 and 11 for Linux / Wine
zlib License
13.1k stars 841 forks source link

Anno 2205 crashes if State Cache is enabled #686

Closed Shished closed 5 years ago

Shished commented 6 years ago

Anno 2205 (64bit DX11-only game) crashes if State Cache is enabled. It seems that if cache file does not exists, game will crash immediately after launch but will create cache file, on second launch game will load to menu and crash in it or after map loading. If State Cache is disabled with DXVK_STATE_CACHE=0 env variable, game works fine without crashes.

Software information

Anno 2205 Complete Edition from Ubisoft store.

System information

Log files

doitsujin commented 6 years ago

Can you post the full wine console output, and if possible, a stack trace from the crash?

I'd find it extremely weird if there were any game-specific bugs in the state cache because there's literally nothing game-specific about it.

Shished commented 6 years ago

https://pastebin.com/kp4RM0gH

doitsujin commented 6 years ago

DXVK is not in the stack trace, and the game seems to crash while waiting for a sync object in its own code, which means that either the stack trace caught the wrong thread for some reason or that this is not even my bug.

ryao commented 6 years ago

There is a chance that the game itself has a use-after-free that usually works because nothing else touches the memory before the wait finishes. When the state cache is enabled, DXVK is doing allocations in parallel and that can reinitialize the freed memory, clobbering the sync object. If this is the case, it is a bug in the game. The only thing DXVK could do to work around such a bug is to implement a separate heap for itself, but that could be a significant amount of work.

I imagine that implementing it and testing the change would confirm/refute the idea that use-after-free is happening in the game code. It might be better to figure out how to apply UBSAN or ASAN to a winelib build.

By the way, a bug like what I describe happened in the Linux kernel several years ago. It was absurdly difficult to track down and took dozens of people more than a year to find it:

https://lwn.net/Articles/575477/

I suggest keeping the possibility in mind when debugging this. It could save plenty of time.

ryao commented 6 years ago

It might be possible to get a different heap for DXVK via linker magic if a different malloc implementation is linked into DXVK. This assumes that C++ wraps the C malloc and the linker lets the game continue to use the wine malloc. Here is one option that could work:

https://github.com/rampantpixels/rpmalloc

It might help performance at the start of games when the state cache is used. The MIT / public domain licensing is also compatible with the licensing used in DXVK in terms of not adding additional restrictions.

macskay commented 5 years ago

@Shished How did you get the game workin in the first place? Every time I try to run it I get a

Fatal Python error: Py_Initialize: can't initialize sys standard streams
LookLookupError: unknown encoding: cp437

I tried setting the ENV but that didnt help.

set PYTHONIOENCODING=cp437
Shished commented 5 years ago

You need to set that env variable to utf8.

macskay commented 5 years ago

derp Of course, thanks!

Shatrico commented 5 years ago

for me it does not work the terminal gives me this: 0117:fixme:msvcrt:clean_type_info_names_internal (0x52ab678) stub 2018-11-23 22:23:20 [ 279] [DEBUG] Hooks.cpp (35) : --- Overlay started --- (C:\Program Files (x86)\Ubisoft\Ubisoft Game Launcher\games\Anno 2205\Bin\Win64\Anno2205.exe) 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'kernel32.dll' hooked 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'kernel32.dll' hooked 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'shell32.dll' hooked 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'dxgi.dll' hooked 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'd3d9.dll' hooked 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'user32.dll' hooked 2018-11-23 22:23:21 [ 279] [DEBUG] PlatformHooks.cpp (113) : 'kernel32.dll' hooked 2018-11-23 22:23:28 [ 279] [DEBUG] D3d10Render.cpp (275) : D3D10 device created 2018-11-23 22:23:34 [ 279] [DEBUG] D3d10Hooks.cpp (113) : Cleaned up rendering resources for device 76689904 2018-11-23 22:23:34 [ 279] [DEBUG] D3d10Render.cpp (275) : D3D10 device created 2018-11-23 22:23:34 [ 279] [DEBUG] Win32InputHooks.cpp (1059) : RenderWindow 262488 0117:fixme:msvcrt:clean_type_info_names_internal (0x1e3c2ed8) stub

at this point, i have a black screen and nothing happens

Update: now i got this error: 0173:fixme:msvcrt:type_info_name_internal_method type_info_node parameter ignored Fatal Python error: Py_Initialize: can't initialize sys standard streams LookupError: unknown encoding: cp850 0041:fixme:win:GetDisplayConfigBufferSizes (0x2 0xcacf55c 0xcacf558): stub

Does it matter if the OS language is german?

macskay commented 5 years ago

@Shatrico This is the same error I posted earlier. Just add the environment variable PYTHONIOENCODING and set it to utf8. I got it working pretty decently and my OS is german as well, so problem there. Add the variable under System options in Lutris when you right-click on Uplay and choose Configure.

Here's a proof, that it works fine:

anno2205

Shatrico commented 5 years ago

ah thx now it works. on which settings do you run it because i had all on high but my pc freezes after some time and it only happens with anno

macskay commented 5 years ago

@Shatrico: We went a bit off-topic here. Let's talk somewhere else to not spam the ticket too much. The actual problem OP had was a crash when DXVK_STATE_CACHE was active not running the game after all.

doitsujin commented 5 years ago

@Shished Is the original bug actually still an issue? If so I'm just going to blacklist the game because there are no obvious bugs in the state cache implementation.

Shished commented 5 years ago

This bug still presented in .92, I cannot test it right now in .93. This is not only my problem, reports on protonDB also mentions it.

doitsujin commented 5 years ago

The state cache should now be disabled for this game. Not sure what's going on, but since this is the only game that has issues with it, I doubt there is a general bug in the implementation.

Thaodan commented 5 years ago

Shouldn't the bug still be open until the issue is fixed? I think a tag like workaround applied would be better.

doitsujin commented 5 years ago

This issue cannot be fixed, and it might not even be a DXVK bug.

Every single game works just fine with the state cache, none of them have any synchronization issues no matter how eratically they create and destroy D3D11 devices or do whatever nonsense they come up with... except this one. For all I care, blacklisting it is enough of a fix.

That said, if you know why the state cache crashes this game, feel free to share your findings, but I'm not going to invest any more time in it.

Thaodan commented 5 years ago

I don't said its not a good fix. I just thought it would be better to let it open in terms of showing known issues.

sorry for ot: but from which anime is your github avatar?

ghost commented 5 years ago

@Thaodan is 2B from the game Nier:Automata

doitsujin commented 5 years ago

It's actually A2.

Shatrico commented 5 years ago

I think there is a regression with Anno 2205 with the newest dxvk release:

2018-12-16 10:57:37 [ 468] [DEBUG] PlatformHooks.cpp (113) : 'shell32.dll' hooked
01d4:fixme:ntdll:NtQueryInformationToken QueryInformationToken( ..., TokenSessionId, ...) semi-stub
01d6:fixme:kernelbase:AppPolicyGetProcessTerminationMethod 0xfffffffffffffffa, 0x23fd00
01cc:fixme:ntdll:NtQueryInformationJobObject stub: 0x90 9 0x74f884 112 (nil)
01d4:fixme:thread:create_user_shared_data_thread Creating user shared data update thread.
01d4:fixme:ntdll:NtQueryInformationToken QueryInformationToken( ..., TokenSessionId, ...) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23fb40 63 ) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makexloc (0x23fb40 63 0x4ad6720 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makewloc (0x23fb40 63 0x4ad6720 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makeushloc (0x23fb40 63 0x4ad6720 (nil)) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23fb00 63 German_Germany.1252) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makexloc (0x23fb00 63 0x4ad68a0 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makewloc (0x23fb00 63 0x4ad68a0 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makeushloc (0x23fb00 63 0x4ad68a0 (nil)) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23f9d0 63 ) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makexloc (0x23f9d0 63 0x4adb8c0 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makewloc (0x23f9d0 63 0x4adb8c0 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makeushloc (0x23f9d0 63 0x4adb8c0 (nil)) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23f990 63 German_Germany.1252) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makexloc (0x23f990 63 0x4ad7d90 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makewloc (0x23f990 63 0x4ad7d90 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makeushloc (0x23f990 63 0x4ad7d90 (nil)) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23f040 1 C) semi-stub
2018-12-16 10:57:40 [ 483] [DEBUG] Hooks.cpp (36) : --- Overlay started --- (C:\windows\system32\dxdiag.exe)
2018-12-16 10:57:40 [ 483] [INFO ] Hooks.cpp (47) : UI disabled via command line
2018-12-16 10:57:41 [ 483] [DEBUG] PlatformHooks.cpp (113) : 'kernel32.dll' hooked
2018-12-16 10:57:41 [ 483] [DEBUG] PlatformHooks.cpp (113) : 'kernel32.dll' hooked
2018-12-16 10:57:41 [ 483] [DEBUG] PlatformHooks.cpp (113) : 'shell32.dll' hooked
01e3:fixme:ntdll:NtQueryInformationToken QueryInformationToken( ..., TokenSessionId, ...) semi-stub
01d4:fixme:ntdll:NtQueryInformationToken QueryInformationToken( ..., TokenSessionId, ...) semi-stub
01e3:fixme:wbemprox:wbem_services_CreateInstanceEnum unsupported flags 0x00000030
01d4:fixme:ntdll:NtQueryInformationToken QueryInformationToken( ..., TokenSessionId, ...) semi-stub
01e3:fixme:wbemprox:enum_class_object_Next timeout not supported
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23ef00 1 C) semi-stub
01e3:fixme:ddraw:ddraw7_Initialize Ignoring guid {aeb2cdd4-6e41-43ea-941c-8361cc760781}.
01e3:err:winediag:MIDIMAP_drvOpen No software synthesizer midi port found, Midi sound output probably won't work.
01e3:err:dxdiag:output_text_information File creation failed, last error 3
01d4:fixme:win:RegisterTouchWindow (0x505b6 00000003): stub
01d4:fixme:imm:ImmReleaseContext (0x505b6, 0x66d14f0): stub
01d4:fixme:msctf:ThreadMgr_ActivateEx Unimplemented flags 0x4
01d4:fixme:msctf:ThreadMgrSource_AdviseSink (0x66d1390) Unhandled Sink: {ea1ea136-19df-11d7-a6d2-00065b84435c}
01d4:fixme:imm:NotifyIME NI_CLOSECANDIDATE
01d4:fixme:msctf:ThreadMgrSource_AdviseSink (0x66d1390) Unhandled Sink: {ea1ea136-19df-11d7-a6d2-00065b84435c}
01d4:fixme:msvcp:_Mtx_init_in_situ unknown flags ignored: 2
info:  Game: Anno2205.exe
info:  DXVK: v0.94
warn:  OpenVR: Failed to locate module
info:  Enabled instance extensions:
info:    VK_KHR_get_physical_device_properties2
info:    VK_KHR_surface
info:    VK_KHR_win32_surface
info:  AMD RADV POLARIS10 (LLVM 7.0.0):
info:    Driver: 18.3.1
info:    Vulkan: 1.1.70
info:    Memory Heap[0]: 
info:      Size: 7936 MiB
info:      Flags: 0x1
info:      Memory Type[0]: Property Flags = 0x1
info:    Memory Heap[1]: 
info:      Size: 256 MiB
info:      Flags: 0x1
info:      Memory Type[2]: Property Flags = 0x7
info:    Memory Heap[2]: 
info:      Size: 8192 MiB
info:      Flags: 0x0
info:      Memory Type[1]: Property Flags = 0x6
info:      Memory Type[3]: Property Flags = 0xe
info:  D3D11CoreCreateDevice: Probing D3D_FEATURE_LEVEL_11_0
info:  D3D11CoreCreateDevice: Using feature level D3D_FEATURE_LEVEL_11_0
info:  Enabled device extensions:
info:    VK_EXT_shader_viewport_index_layer
info:    VK_EXT_transform_feedback
info:    VK_EXT_vertex_attribute_divisor
info:    VK_KHR_dedicated_allocation
info:    VK_KHR_descriptor_update_template
info:    VK_KHR_driver_properties
info:    VK_KHR_get_memory_requirements2
info:    VK_KHR_image_format_list
info:    VK_KHR_maintenance1
info:    VK_KHR_maintenance2
info:    VK_KHR_sampler_mirror_clamp_to_edge
info:    VK_KHR_shader_draw_parameters
info:    VK_KHR_swapchain
01d4:fixme:vulkan:wine_vk_device_convert_create_info Application requested a linked structure of type 0x3b9db032.
01d4:fixme:vulkan:wine_vk_device_convert_create_info Application requested a linked structure of type 0x3b9b3760.
info:  DXVK: Read 494 valid state cache entries
info:  DXVK: Using 4 compiler threads
warn:  DXGI: VK_FORMAT_D24_UNORM_S8_UINT -> VK_FORMAT_D32_SFLOAT_S8_UINT
info:  Presenter: Actual swap chain properties:
  Format:       VK_FORMAT_B8G8R8A8_UNORM
  Present mode: VK_PRESENT_MODE_IMMEDIATE_KHR
  Buffer size:  1912x1053
  Image count:  2
warn:  DXGI: MakeWindowAssociation: Ignoring flags
0075:fixme:win:GetDisplayConfigBufferSizes (0x2 0xc97f54c 0xc97f548): stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23ea60 1 C) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23ebd0 1 C) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23e4b0 1 C) semi-stub
01d4:fixme:msvcrt:type_info_name_internal_method type_info_node parameter ignored
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23db10 1 C) semi-stub
01d4:fixme:msvcp:_Locinfo__Locinfo_ctor_cat_cstr (0x23ee10 63 German) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makexloc (0x23ee10 63 0x7f4cb30ca7b0 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makewloc (0x23ee10 63 0x7f4cb30ca7b0 (nil)) semi-stub
01d4:fixme:msvcp:locale__Locimp__Makeushloc (0x23ee10 63 0x7f4cb30ca7b0 (nil)) semi-stub
01d4:fixme:heap:RtlSetHeapInformation (nil) 1 (nil) 0 stub
01d4:fixme:ntdll:EtwEventRegister ({d2d578d9-2936-45b6-a09f-30e32715f42d}, 0x7a8300, 0x40663a0, 0x414f7f0) stub.
[1216/105747:ERROR:main_delegate.cc(722)] Could not load locale pak for en-US
[1216/105747:ERROR:main_delegate.cc(746)] Could not load cef_100_percent.pak
003a:fixme:nls:GetThreadPreferredUILanguages 00000038, 0x67b5f960, (nil) 0x67b5f968
003a:fixme:nls:get_dummy_preferred_ui_language (0x38 0x67b5f960 (nil) 0x67b5f968) returning a dummy value (current locale)
003a:fixme:nls:GetThreadPreferredUILanguages 00000038, 0x67b5f960, 0x7f4c800f4ce0 0x67b5f968
003a:fixme:nls:get_dummy_preferred_ui_language (0x38 0x67b5f960 0x7f4c800f4ce0 0x67b5f968) returning a dummy value (current locale)
003a:fixme:winsock:WSALookupServiceBeginW (0x67b5f580 0x00000ff0 0x67b5f578) Stub!
[1216/105747:ERROR:network_change_notifier_win.cc(153)] WSALookupServiceBegin failed with: 8
003a:fixme:iphlpapi:NotifyAddrChange (Handle 0x67b5f850, overlapped 0x7f4c800f65a0): stub
003a:fixme:win:RegisterDeviceNotificationW (hwnd=0x2059c, filter=0x67b5f800,flags=0x00000000) returns a fake device notification handle!
003a:fixme:win:RegisterDeviceNotificationW (hwnd=0x2059c, filter=0x67b5f800,flags=0x00000000) returns a fake device notification handle!
003f:fixme:ver:GetCurrentPackageId (0x7fffff65f530 (nil)): stub
[1216/105747:ERROR:proxy_service_factory.cc(132)] Cannot use V8 Proxy resolver in single process mode.
01d4:fixme:ole:CoInitializeSecurity ((nil),-1,(nil),(nil),0,3,(nil),0,(nil)) - stub!
01d4:fixme:wbemprox:client_security_SetBlanket 0x7f4ca80ee240, 0x7f4c801d33f0, 10, 0, (null), 3, 3, (nil), 0x00000000
01d4:fixme:wbemprox:client_security_Release 0x7f4ca80ee240
info:  Presenter: Actual swap chain properties:
  Format:       VK_FORMAT_B8G8R8A8_UNORM
  Present mode: VK_PRESENT_MODE_IMMEDIATE_KHR
  Buffer size:  1920x1080
  Image count:  2
warn:  DXGI: MakeWindowAssociation: Ignoring flags
info:  DXGI: Setting display mode: 1920x1080@144
0075:fixme:win:GetDisplayConfigBufferSizes (0x2 0xc97f54c 0xc97f548): stub
info:  Presenter: Actual swap chain properties:
  Format:       VK_FORMAT_B8G8R8A8_UNORM
  Present mode: VK_PRESENT_MODE_IMMEDIATE_KHR
  Buffer size:  1920x1080
  Image count:  2
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 0.00fps, total 0.00fps
004f:fixme:winhttp:get_system_proxy_autoconfig_url no support on this platform
004f:fixme:winhttp:WinHttpDetectAutoProxyConfigUrl discovery via DHCP not supported
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 375.66fps, total 376.32fps
0202:fixme:toolhelp:CreateToolhelp32Snapshot Unimplemented: heap list snapshot
0202:fixme:toolhelp:Heap32ListFirst : stub
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 503.66fps, total 439.59fps
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 823.45fps, total 567.01fps
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 904.73fps, total 651.17fps
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 854.10fps, total 691.65fps
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 699.73fps, total 693.00fps
01d4:trace:fps:X11DRV_vkQueuePresentKHR 0x7dcb8ac0 @ approx 912.06fps, total 724.23fps
AL lib: (EE) ReleaseThreadCtx: Context 0x7dc2e7d0 current for thread being destroyed, possible leak!
AL lib: (EE) ReleaseThreadCtx: Context 0x7f4c44001f50 current for thread being destroyed, possible leak!
AL lib: (EE) ReleaseThreadCtx: Context 0x7dc2e7d0 current for thread being destroyed, possible leak!

After starting the game is on the screen where it says he is loading and then the game crashed and also closed uplay

doitsujin commented 5 years ago

So does it work with 0.93? If so, please bisect, and when you did, open a new issue.

Shatrico commented 5 years ago

sry, but my English is not the best, what you mean with "bisect"?

doitsujin commented 5 years ago

First of all, please check if it works with 0.93.

Shatrico commented 5 years ago

Its starting but then its crashing during playing the game: AL lib: (EE) ReleaseThreadCtx: Context 0x7e4cbca0 current for thread being destroyed, possible leak! AL lib: (EE) ReleaseThreadCtx: Context 0x7e4cbca0 current for thread being destroyed, possible leak! AL lib: (EE) ReleaseThreadCtx: Context 0x7f6a7400abc0 current for thread being destroyed, possible leak!

doitsujin commented 5 years ago

Then please bisect DXVK following this tutorial.

Shished commented 5 years ago

This bug does not reproduces for me anymore. I launched game with wine 4.0-rc1 and DXVK 0.94 with State Cache force enabled, and it didn't crashed. A 500kb cache file was created and DXVK actually loaded it.

info:  DXVK: Read 267 valid state cache entries
info:  DXVK: Using 9 compiler threads

Then i tried 0.93 and 0.92 and they also worked. I think it was a wine or Linux problem, not from DXVK.

Shatrico commented 5 years ago

Tomorrow or so I will take a look into bisect, it looks very complicated, but i can exclude a wine problem because i switched the versions and it still happens

doitsujin commented 5 years ago

@Shished weird. Can you test 0.93 just to rule it out?

Also, does this game require any sort of winetricks magic? If it works for you then I don't see why the issue @Shatrico has would be a DXVK bug.

Shatrico commented 5 years ago

because with 0.94 I already crashes when I start the game and with 0.93 I can run the game select a save go into a map and crashes then between 5-10 min. And if it would be a Linux problem then no DX11 would run and that's not the case.

Shished commented 5 years ago

I tried to play this game with DXVK 0.92 and 0.93, now it does not crashes but crashed last time when i tested it before.

I installed vcrun2012 from winetricks so game wont complain about msvcp in terminal, also i disabled overlay64.dll in winecfg - that's uplay overlay.

Shatrico commented 5 years ago

I tried to play this game with DXVK 0.92 and 0.93, now it does not crashes but crashed last time when i tested it before.

I installed vcrun2012 from winetricks so game wont complain about msvcp in terminal, also i disabled overlay64.dll in winecfg - that's uplay overlay.

Tried it and did not help