https://bugs.winehq.org/show_bug.cgi?id=49049
Bug ID: 49049 Summary: iLok License Manager daemon 'LDSvc.exe' crashes on shutdown Product: Wine Version: 5.7 Hardware: x86-64 OS: Linux Status: NEW Severity: normal Priority: P2 Component: ntdll Assignee: wine-bugs@winehq.org Reporter: focht@gmx.net Distribution: ---
Hello folks,
after fixing bug 49043, the license daemon/service still crashes - on shutdown/teardown.
Service process creation, thread 0060 is a client side RPC service thread.
--- snip --- $ WINEDEBUG=+seh,+relay,+loaddll,+process,+server,+ntdll,+sync wineboot
log.txt 2>&1
003c:Call KERNEL32.CreateProcessW(00000000,0011fd30 L"C:\Program Files (x86)\Common Files\PACE\Services\LicenseServices\LDSvc.exe -u https://activation.paceap.com/InitiateActivation%22,00000000,00000000,100000...) ret=14000672a ... 0048:Call ntdll.__wine_make_process_system() ret=7e6b056d 0048:Ret ntdll.__wine_make_process_system() retval=0000008c ret=7e6b056d 0048:Call kernelbase.CreateThread(00000000,00000000,7e6ad610,06521d20,00000000,00000000) ret=7e6b0589 0048:Call ntdll.RtlCreateUserThread(ffffffff,00000000,00000001,00000000,00000000,00000000,7e6ad610,06521d20,0031fa40,0031fa34) ret=7b0434a6 ... 003c:trace:process:CreateProcessInternalW started process pid 0044 tid 0048 .... 0048: new_thread( process=ffffffff, access=001fffff, suspend=1, request_fd=8, objattr={} ) 0048: new_thread() = 0 { tid=0060, handle=0090 } ... 0060: *fd* 10 <- 109 0060: *fd* 13 <- 110 0060: init_thread( unix_pid=12060, unix_tid=12066, debug_level=1, teb=7ffd4000, entry=7e6ad610, reply_fd=10, wait_fd=13, cpu=x86 ) 0060: init_thread() = 0 { pid=0044, tid=0060, server_start=1d61e123e9d65ca (-1.3890170), info_size=0, version=602, all_cpus=00000003, suspend=0 } ... 0060:Starting thread proc 0x7e6ad610 (arg=0x6521d20) 0060:Call kernelbase.ReadFile(00000084,069dff1c,00000010,069dff14,00000000) ret=7e6ad721 0060:Call ntdll.NtReadFile(00000084,00000000,00000000,00000000,069dfe78,069dff1c,00000010,00000000,00000000) ret=7b013972 0060:trace:ntdll:NtReadFile (0x84,(nil),(nil),(nil),0x69dfe78,0x69dff1c,0x00000010,(nil),(nil)) 0060: get_handle_fd( handle=0084 ) 0060: get_handle_fd() = BAD_DEVICE_TYPE { type=0, cacheable=1, access=00000000, options=00000000 } 0060: read( async={handle=0084,event=0000,iosb=069dfe78,user=06522a90,apc=00000000,apc_context=00000000}, pos=00000000 ) 0060: read() = 0 { wait=0094, options=00000060, data={45,4e,49,57,66,00,00,00,15,00,00,00,00,00,00,00} } 0060: select( flags=2, cookie=069df3d4, timeout=infinite, size=8, prev_apc=0000, result={}, data={WAIT_ALL,handles={0094}}, context={} ) 0060: select() = 0 { call={APC_NONE}, apc_handle=0000, context={} } 0060:Ret ntdll.NtReadFile() retval=00000000 ret=7b013972 0060:Ret kernelbase.ReadFile() retval=00000001 ret=7e6ad721 ... 0060:Call rpcrt4.NdrClientInitializeNew(069dfb4c,069dfbd0,7e6c76a0,00000010) ret=7e6b8382 0060:Ret rpcrt4.NdrClientInitializeNew() retval=069d0000 ret=7e6b8382 .... 0060:Call kernelbase.ReadFile(00000084,069dff1c,00000010,069dff14,00000000) ret=7e6ad721 0060:Call ntdll.NtReadFile(00000084,00000000,00000000,00000000,069dfe78,069dff1c,00000010,00000000,00000000) ret=7b013972 0060:trace:ntdll:NtReadFile (0x84,(nil),(nil),(nil),0x69dfe78,0x69dff1c,0x00000010,(nil),(nil)) 0060: read( async={handle=0084,event=0000,iosb=069dfe78,user=06522d20,apc=00000000,apc_context=00000000}, pos=00000000 ) 0060: read() = PENDING { wait=0098, options=00000060, data={} } ... 0060: select( flags=2, cookie=069df3d4, timeout=infinite, size=8, prev_apc=0000, result={}, data={WAIT_ALL,handles={0098}}, context={} ) 0060: select() = PENDING { call={APC_NONE}, apc_handle=0000, context={} } ... --- snip ---
--- snip --- ... 0064:Ret KERNEL32.CreateRemoteThread() retval=000000a0 ret=004486d6 ... 0068: init_thread( unix_pid=12060, unix_tid=12068, debug_level=1, teb=7ffcc000, entry=00447580, reply_fd=19, wait_fd=21, cpu=x86 ) 0068: init_thread() = 0 { pid=0044, tid=0068, server_start=1d61e123e9d65ca (-1.3962840), info_size=0, version=602, all_cpus=00000003, suspend=1 } --- snio ---
App thread 0068 creates pipe serving thread 0168.
--- snip --- 0068:Call ucrtbase._beginthreadex(00000000,00000000,004969c0,0652c750,00000004,0652c770) ret=00496955 0068:Call KERNEL32.CreateRemoteThread(ffffffff,00000000,00000000,004969c0,0652c750,00000004,0652c770) ret=004486d6 0068:Call kernelbase.CreateRemoteThread(ffffffff,00000000,00000000,004969c0,0652c750,00000004,0652c770) ret=7bc9f474 0068:Call ntdll.RtlCreateUserThread(ffffffff,00000000,00000001,00000000,00000000,00000000,004969c0,0652c750,06bff370,06bff364) ret=7b0434a6 0068: *fd* 172 <- 304 0068: new_thread( process=ffffffff, access=001fffff, suspend=1, request_fd=172, objattr={} ) 0068: new_thread() = 0 { tid=0168, handle=02ec } ... 0168: *fd* 176 <- 305 0168: *fd* 178 <- 307 0168: init_thread( unix_pid=12060, unix_tid=12133, debug_level=1, teb=7ff2c000, entry=004969c0, reply_fd=176, wait_fd=178, cpu=x86 ) 0168: init_thread() = 0 { pid=0044, tid=0168, server_start=1d61e123e9d65ca (-3.6823560), info_size=0, version=602, all_cpus=00000003, suspend=1 } 0168: select( flags=2, cookie=096ee5a4, timeout=0, size=0, prev_apc=0000, result={}, data={}, context={cpu=x86,eip=7bcb2524,esp=096efff0,ebp=00000000,eflags=00000202,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=004969c0,ebx=0652c750,ecx=00000000,edx=00000000,esi=00000000,edi=00000000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,fp.ctrl=0000027f,fp.status=00000000,fp.tag=00000000,fp.err_off=00000000,fp.err_sel=00000000,fp.data_off=00000000,fp.data_sel=00000000,fp.cr0npx=00000000,fp.reg0=0,fp.reg1=0,fp.reg2=0,fp.reg3=0,fp.reg4=0,fp.reg5=0,fp.reg6=0,fp.reg7=0,extended={0000027f, ...,00000000}} ) 0168: select() = PENDING { call={APC_NONE}, apc_handle=0000, context={} } 0168: *wakeup* signaled=258 0168: select( flags=2, cookie=096ee5a4, timeout=0, size=0, prev_apc=0000, result={}, data={}, context={} ) 0168: *signal* signal=19 0168: select() = TIMEOUT { call={APC_NONE}, apc_handle=0000, context={cpu=x86,dr0=004490a2,dr1=004490a2,dr2=004490a2,dr3=004490a2,dr6=00000000,dr7=00000055} } ... 0168:Call KERNEL32.CreateNamedPipeA(063983c0 "\\.\pipe\com_paceap_eden_licensed_activationfrontend",40000003,00000000,000000ff,00002000,00002000,00000000,096efa8c) ret=004afa3e ... 0168:Call kernelbase.CreateNamedPipeW(096ef698 L"\\.\pipe\com_paceap_eden_licensed_activationfrontend",40000003,00000000,000000ff,00002000,00002000,00000000,096efa8c) ret=7b45c01e 0168:trace:sync:CreateNamedPipeW (L"\\.\pipe\com_paceap_eden_licensed_activationfrontend", 0x40000003, 00000000, 255, 8192, 8192, 0, 096EFA8C) ... 0168:Call ntdll.NtCreateNamedPipeFile(096ef5b4,c0100000,096ef5c4,096ef5dc,00000003,00000005,00000000,00000000,00000000,00000000,ffffffff,00002000,00002000,096ef5b8) ret=7b042db4 0168:trace:ntdll:NtCreateNamedPipeFile (0x96ef5b4 c0100000 L"\??\pipe\com_paceap_eden_licensed_activationfrontend" 0x96ef5dc 3 5 0 0 0 0 -1 8192 8192 0x96ef5b8) ... 0168: create_named_pipe( access=c0100000, options=00000000, sharing=00000003, maxinstances=ffffffff, outsize=00002000, insize=00002000, timeout=0, flags=00000000, objattr={rootdir=0000,attributes=00000040,sd={control=00000004,owner=<not present>,group=<not present>,sacl={},dacl={{AceType=ACCESS_DENIED_ACE_TYPE,Mask=10000000,AceFlags=0,Sid={S-1-5-7}},{AceType=ACCESS_ALLOWED_ACE_TYPE,Mask=10000000,AceFlags=0,Sid={S-1-5-11}}}},name=L"\??\pipe\com_paceap_eden_licensed_activationfrontend"} ) 0168: create_named_pipe() = 0 { handle=02f4 } 0168:Ret ntdll.NtCreateNamedPipeFile() retval=00000000 ret=7b042db4 ... 0168:Ret kernelbase.CreateNamedPipeW() retval=000002f4 ret=7b45c01e 0168:Ret KERNEL32.CreateNamedPipeA() retval=000002f4 ret=004afa3e ... 0168:Call KERNEL32.ConnectNamedPipe(000002f4,096efa78) ret=004afd26 0168:Call kernelbase.ConnectNamedPipe(000002f4,096efa78) ret=7bc9f474 0168:trace:sync:ConnectNamedPipe (000002F4,096EFA78) ... 0168: ioctl( code=FSCTL_PIPE_LISTEN, async={handle=02f4,event=02f8,iosb=096efa78,user=0652ca90,apc=00000000,apc_context=096efa78}, in_data={} ) 0168: ioctl() = PENDING { wait=0000, options=00000000, out_data={} } ... 0168:Ret ntdll.NtFsControlFile() retval=00000103 ret=7b042b94 0168:Call ntdll.RtlNtStatusToDosError(00000103) ret=7b042bc4 0168:Ret ntdll.RtlNtStatusToDosError() retval=000003e5 ret=7b042bc4 0168:Ret kernelbase.ConnectNamedPipe() retval=00000000 ret=7bc9f474 0168:Ret KERNEL32.ConnectNamedPipe() retval=00000000 ret=004afd26 0168:Call KERNEL32.GetLastError() ret=004afd32 0168:Call kernelbase.GetLastError() ret=7bc9f474 0168:Ret kernelbase.GetLastError() retval=000003e5 ret=7bc9f474 0168:Ret KERNEL32.GetLastError() retval=000003e5 ret=004afd32 0168:Call KERNEL32.WaitForSingleObject(000002f8,0000000a) ret=004afd4d 0168:Call kernelbase.WaitForSingleObject(000002f8,0000000a) ret=7bc9f474 0168:Call ntdll.NtWaitForMultipleObjects(00000001,096ef79c,00000001,00000000,096ef720) ret=7b040eda 0168: select( flags=2, cookie=096eedb4, timeout=+0.0099874, size=8, prev_apc=0000, result={}, data={WAIT,handles={02f8}}, context={} ) 0168: select() = PENDING { call={APC_NONE}, apc_handle=0000, context={} } ... 0168:Ret PE DLL (proc=0x7e769db0,module=0x7e720000 L"ucrtbase.dll",reason=THREAD_DETACH,res=(nil)) retval=1 0168: *killed* exit_code=0 --- snip ---
Service teardown phase, pipe servers get destroyed. To do that, app thread 0068 calls 'DisconnectNamedPipe' to trigger the pipe server thread teardown.
--- snip --- ... 0068:Call KERNEL32.DisconnectNamedPipe(000002f4) ret=004aee2b 0068:Call kernelbase.DisconnectNamedPipe(000002f4) ret=7bc9f474 0068:trace:sync:DisconnectNamedPipe (000002F4) 0068:Call ntdll.NtFsControlFile(000002f4,00000000,00000000,00000000,06bff3fc,00110004,00000000,00000000,00000000,00000000) ret=7b042fa7 0068:trace:ntdll:NtFsControlFile (0x2f4,(nil),(nil),(nil),0x6bff3fc,0x00110004,(nil),0x00000000,(nil),0x00000000) 0068: ioctl( code=FSCTL_PIPE_DISCONNECT, async={handle=02f4,event=0000,iosb=06bff3fc,user=0652cac8,apc=00000000,apc_context=00000000}, in_data={} ) 0068: ioctl() = PIPE_LISTENING { wait=0000, options=00000000, out_data={} } 0068:Ret ntdll.NtFsControlFile() retval=c00000b3 ret=7b042fa7 0068:Call ntdll.RtlNtStatusToDosError(c00000b3) ret=7b042fb4 0068:Ret ntdll.RtlNtStatusToDosError() retval=00000218 ret=7b042fb4 0068:Ret kernelbase.DisconnectNamedPipe() retval=00000000 ret=7bc9f474 0068:Ret KERNEL32.DisconnectNamedPipe() retval=00000000 ret=004aee2b 0068:Call KERNEL32.CloseHandle(000002f4) ret=004aec93 0068:Call kernelbase.CloseHandle(000002f4) ret=7bc9f474 0068:Call ntdll.NtClose(000002f4) ret=7b02f739 0068: close_handle( handle=02f4 ) 0060: *wakeup* signaled=256 0068: close_handle() = 0 0068:Ret ntdll.NtClose() retval=00000000 ret=7b02f739 0068:Ret kernelbase.CloseHandle() retval=00000001 ret=7bc9f474 0068:Ret KERNEL32.CloseHandle() retval=00000001 ret=004aec93 ... --- snip ---
This interestingly wakes up service client side RPC thread 0060 which wasn't responsible for any app created named pipes. Likely because it's one of the few threads left in alertable state to handle system APCs?
--- snip --- ... 0060: select( flags=2, cookie=069df3d4, timeout=infinite, size=8, prev_apc=0000, result={}, data={WAIT_ALL,handles={0098}}, context={} ) 0060: select() = KERNEL_APC { call={APC_ASYNC_IO,user=0652ca90,sb=096efa78,status=HANDLES_CLOSED}, apc_handle=0134, context={} } ... 0060:trace:seh:raise_exception code=c0000005 flags=0 addr=0x7bc65af9 ip=7bc65af9 tid=0060 0060:trace:seh:raise_exception info[0]=00000001 0060:trace:seh:raise_exception info[1]=096efa78 0060:trace:seh:raise_exception eax=00000000 ebx=0652ca90 ecx=8000000a edx=069df400 esi=7bd2261c edi=096efa78 0060:trace:seh:raise_exception ebp=069df2f8 esp=069df270 cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00010a02 0060:trace:seh:call_vectored_handlers calling handler at 0x448700 code=c0000005 flags=0 0060:trace:seh:call_vectored_handlers handler at 0x448700 returned 0 0060:trace:seh:call_stack_handlers calling handler at 0x7bcd7650 code=c0000005 flags=0 0060:Call kernelbase.UnhandledExceptionFilter(069dee48) ret=7bc65702 ... wine: Unhandled page fault on write access to 096EFA78 at address 7BC65AF9 (thread 0060), starting debugger... ... 0060:err:seh:start_debugger Couldn't start debugger L"winedbg --auto 68 360" (1115) ... --- snip ---
The overlapped structure 0x096efa78 was allocated on app pipe handler thread 0168 stack, see 'select' context after 'init_thread' (esp=096efff0) and 'ConnectNamedPipe' call.
The pipe handler thread 0168 has already terminated way before thread 0060 woke up - with its thread stack unmapped. This causes causes a page fault when accessing the iosb.
$ sha1sum LicenseSupportInstallerWin64.zip b22693fe4c29a60068c1f4c024232f9dc263b12b LicenseSupportInstallerWin64.zip
$ du -sh LicenseSupportInstallerWin64.zip 282M LicenseSupportInstallerWin64.zip
$ wine --version wine-5.7-97-g7ccc45f754
Regards