https://bugs.winehq.org/show_bug.cgi?id=56789
--- Comment #12 from jubilantjerry@gmail.com --- I've discovered that Wine can output more verbose logs, so I tried capturing the logs of a minimal crash scenario.
With the default logging verbosity, my scenario produces: ``` $ WINEPREFIX=/home/jubilantjerry/Downloads/wine-source/wineprefixbak wine64 regedit 002c:fixme:winediag:loader_init wine-staging 9.13 is a testing version containing experimental patches. 002c:fixme:winediag:loader_init Please mention your exact version when filing bug reports on winehq.org. 0080:fixme:wineusb:query_id Unhandled ID query type 0x5. 0080:fixme:wineusb:query_id Unhandled ID query type 0x5. 0080:fixme:wineusb:query_id Unhandled ID query type 0x5. 0080:fixme:wineusb:query_id Unhandled ID query type 0x5. X Error of failed request: XI_BadDevice (invalid Device parameter) Major opcode of failed request: 131 (XInputExtension) Minor opcode of failed request: 3 (X_OpenDevice) Device id in failed request: 0x249 Serial number of failed request: 248 Current serial number in output stream: 248 X Error of failed request: XI_BadDevice (invalid Device parameter) Major opcode of failed request: 131 (XInputExtension) Minor opcode of failed request: 3 (X_OpenDevice) Device id in failed request: 0x249 Serial number of failed request: 313 Current serial number in output stream: 313 ```
Nothing in this looks particularly strange to me, prior to the error.
I then tried with WINEDEBUG=+all,trace-all, comparing the release version of Wine 9.13 with my built from source Wine 9.13.
The logs near the crash in the release version look like: ``` 0138:warn:keyboard:X11DRV_InitKeyboard vkey 012C is being used by more than one keycode 0138:warn:keyboard:X11DRV_InitKeyboard vkey 01B4 is being used by more than one keycode 0138:warn:keyboard:X11DRV_InitKeyboard vkey 0003 is being used by more than one keycode 0138:warn:keyboard:X11DRV_InitKeyboard No more vkeys available! 0138:warn:file:NtCreateFile L"\??\C:\windows\uxtheme.dll" not found (c0000034) 0138:warn:file:NtCreateFile L"\??\C:\windows\ole32.dll" not found (c0000034) 0138:warn:file:NtCreateFile L"\??\C:\windows\combase.dll" not found (c0000034) 0138:warn:file:NtCreateFile L"\??\C:\windows\rpcrt4.dll" not found (c0000034) 0138:warn:file:NtCreateFile L"\??\C:\windows\coml2.dll" not found (c0000034) 0138:warn:gdi:handle_entry invalid handle 0x1 0138:warn:gdi:handle_entry invalid handle 0x1 0138:warn:file:NtCreateFile L"\??\C:\windows\msimg32.dll" not found (c0000034) 0138:warn:gdi:handle_entry invalid handle 0x130400a6 X Error of failed request: XI_BadDevice (invalid Device parameter) Major opcode of failed request: 131 (XInputExtension) Minor opcode of failed request: 3 (X_OpenDevice) Device id in failed request: 0x249 Serial number of failed request: 245 Current serial number in output stream: 245 X Error of failed request: XI_BadDevice (invalid Device parameter) Major opcode of failed request: 131 (XInputExtension) Minor opcode of failed request: 3 (X_OpenDevice) Device id in failed request: 0x249 Serial number of failed request: 313 Current serial number in output stream: 313 ```
The built from source version also has the warnings about "msimg32.dll not found" or "invalid handle 0x130400a6". Yet, the built from source version doesn't get the X Error crash. So these warnings also look like red herrings, unfortunately.
Finally, I tried capturing logs at maximum verbosity. The X Error now looks different, here are the logs around the crash: ``` 68408.293:0044:0070:trace:mountmgr:udisks_filter changed "/org/freedesktop/NetworkManager/Devices/3" 68408.309:0044:0070:trace:mountmgr:udisks_filter changed "/org/freedesktop/NetworkManager/Devices/3" 68408.309:0044:0070:trace:mountmgr:udisks_filter changed "/org/freedesktop/NetworkManager" 68408.486:0044:0070:trace:mountmgr:udisks_filter changed "/org/bluez/hci0" 68409.420:0044:0070:trace:mountmgr:udisks_filter changed "/org/freedesktop/login1" 68409.681:0064:0068:err:x11drv:error_handler X protocol error: serial=611, request_code=131 - breaking into debugger plorer.exe: dlls/winex11.drv/x11drv_main.c:296: error_handler: Assertion `0' failed. 68409.681:0064:0068:warn:virtual:virtual_setup_exception exception outside of stack limits addr 0x7f5b47b6a00b stack 0x1000ff1e0 (0x4d0000-0x4d2000-0x6d0000) 68409.681:0064:0068:trace:seh:dispatch_exception code=80000101 (EXCEPTION_WINE_ASSERTION) flags=1 addr=00007F5B47B6A00B 68409.681:0064:0068:trace:seh:dispatch_exception rip=00007f5b47b6a00b rsp=00000001000ff1e0 rbp=00007f5b47cdf588 eflags=00000246 68409.681:0064:0068:trace:seh:dispatch_exception rax=0000000000000000 rbx=00007f5b47b25f40 rcx=00007f5b47b6a00b rdx=0000000000000000 68409.681:0064:0068:trace:seh:dispatch_exception rsi=00000001000ff1e0 rdi=0000000000000002 r8=0000000000000000 r9=00000001000ff1e0 68409.681:0064:0068:trace:seh:dispatch_exception r10=0000000000000008 r11=0000000000000246 r12=00007f5b466e90f8 r13=0000000000000128 68409.681:0064:0068:trace:seh:dispatch_exception r14=00007f5b466eab3d r15=000055555693ea50 mxcsr=00001fa0 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind function 7f5b47b6a00b base 0x7f5b47b69f40 cie 0x7f5b47ceb590 len 14 id 0 version 1 aug 'zR' code_align 1 data_align -8 retaddr %rip 68409.681:0064:0068:trace:unwind:execute_cfa_instructions 7f5b47b69f40: DW_CFA_def_cfa %rsp, 8 68409.681:0064:0068:trace:unwind:execute_cfa_instructions 7f5b47b69f40: DW_CFA_offset %rip, -8 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind fde 0x7f5b47ceda70 len 18 personality (nil) lsda (nil) code 7f5b47b69f40-7f5b47b6a049 68409.681:0064:0068:trace:unwind:execute_cfa_instructions 7f5b47b69f40: DW_CFA_advance_loc 11 68409.681:0064:0068:trace:unwind:execute_cfa_instructions 7f5b47b69f4b: DW_CFA_def_cfa_offset 288 68409.681:0064:0068:trace:unwind:execute_cfa_instructions 7f5b47b69f4b: DW_CFA_advance_loc1 221 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind next function rip=00007f5b47b49859 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind rax=0000000000000000 rbx=00007f5b47b25f40 rcx=00007f5b47b6a00b rdx=0000000000000000 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind rsi=00000001000ff1e0 rdi=0000000000000002 rbp=00007f5b47cdf588 rsp=00000001000ff300 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind r8=0000000000000000 r9=00000001000ff1e0 r10=0000000000000008 r11=0000000000000246 68409.681:0064:0068:trace:unwind:dwarf_virtual_unwind r12=00007f5b466e90f8 r13=0000000000000128 r14=00007f5b466eab3d r15=000055555693ea50 68409.681:0064:0068:err:seh:call_seh_handlers invalid frame 00000001000FF1E0 (00000000004D2000-00000000006D0000) 68409.681:0064:0068:err:seh:NtRaiseException Exception frame is not in stack limits => unable to dispatch exception. 0068: terminate_process( handle=ffffffff, exit_code=1202507248 ) 010c: *killed* exit_code=1202507248 010c: *sent signal* signal=3 0110: *killed* exit_code=1202507248 0114: *killed* exit_code=1202507248 0068: terminate_process() = 0 { self=1 } 68409.691:0148:014c:trace:winstation:get_shared_queue lock 0x1000ffa40, queue_shm 0x1000ffa38 68409.691:0148:014c:trace:winstation:get_shared_queue lock 0x1000ffa40, queue_shm 0x1000ffa38 ```
Weirdly, the serial number is changed to 611 and it doesn't mention a Bad Device, but I think the root cause may be the same. Perhaps these logs can be used to narrow down to a specific line of code in Wine?
I've attached the warn logs from the crashing run, the warn logs from the working run, and the trace logs from the crashing run.