[Bug 49049] New: iLok License Manager daemon 'LDSvc.exe' crashes on shutdown

[WineHQ Bugzilla]

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: [e-mail]
          Reporter: [e-mail]
      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

[Bug 49049] iLok License Manager daemon 'LDSvc.exe' crashes on shutdown

[WineHQ Bugzilla]

https://bugs.winehq.org/show_bug.cgi?id=49049

Anastasius Focht  changed:

What    |Removed                     |Added
----------------------------------------------------------------------------
           Keywords|                            |download
                URL|                            |https://web.archive.org/web
                   |                            |/20200428185733/http://inst
                   |                            |allers.ilok.com/iloklicense
                   |                            |manager/LicenseSupportInsta
                   |                            |llerWin64.zip