[Bug 49043] New: iLok License Manager daemon 'LDSvc.exe' crashes on startup (PACE copy protection spuriously fails to get/set thread context of newly created threads)
https://bugs.winehq.org/show_bug.cgi?id=49043 Bug ID: 49043 Summary: iLok License Manager daemon 'LDSvc.exe' crashes on startup (PACE copy protection spuriously fails to get/set thread context of newly created threads) Product: Wine Version: 5.7 Hardware: x86-64 OS: Linux Status: NEW Severity: normal Priority: P2 Component: wineserver Assignee: wine-bugs(a)winehq.org Reporter: focht(a)gmx.net Distribution: --- Hello folks, an interesting problem while looking at bug 49010 ("ilok license manager: doesn't connect to the activation server as in 4.0.2"). NOTE: It's not the only problem but I think it's worth mentioning separately and there is actually a patchset that aims to mitigate the issue. Also these patches do not refer to any bug id. The license manager is an auto-start service. Part of PACE copy-protection hence obviously using anti-debug/hacking trickery. --- snip --- $ pwd /home/focht/.wine/drive_c/Program Files (x86)/iLok License Manager $ WINEDEBUG=+seh,+relay,+loaddll,+process,+ntdll,+server,+virtual wine ./iLok\ License\ Manager.exe >>log.txt 2>&1 ... 003c:Call KERNEL32.CreateProcessW(00000000,008ab690 L"C:\\Program Files (x86)\\Common Files\\PACE\\Services\\LicenseServices\\LDSvc.exe -u https://activation.paceap.com/InitiateActivation",00000000,00000000,100000000,00000400,008aa020,00000000,0022f5a0,0022f570) ret=14000683a ... 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\kernelbase.dll" at 0x7b000000: PE builtin 0068:trace:loaddll:load_so_dll Loaded L"C:\\windows\\system32\\kernel32.dll" at 0x7b420000: builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\Program Files (x86)\\Common Files\\PACE\\Services\\LicenseServices\\LDSvc.exe" at 0x400000: native 0068:trace:loaddll:load_so_dll Loaded L"C:\\windows\\system32\\ucrtbase.dll" at 0x7e720000: builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\version.dll" at 0x330000: PE builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\sechost.dll" at 0x350000: PE builtin 0068:trace:loaddll:load_so_dll Loaded L"C:\\windows\\system32\\advapi32.dll" at 0x7e680000: builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\rpcrt4.dll" at 0x5430000: PE builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\setupapi.dll" at 0x5340000: PE builtin 0068:trace:loaddll:load_so_dll Loaded L"C:\\windows\\system32\\gdi32.dll" at 0x7e540000: builtin 0068:trace:loaddll:load_so_dll Loaded L"C:\\windows\\system32\\user32.dll" at 0x7e830000: builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\ole32.dll" at 0x5580000: PE builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\msacm32.dll" at 0x370000: PE builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\WINMM.dll" at 0x10000000: PE builtin 0068:trace:loaddll:load_native_dll Loaded L"C:\\windows\\system32\\MSVCP140.dll" at 0x58e0000: PE builtin ... 003c:trace:process:RtlCreateUserProcess L"\\??\\C:\\Program Files (x86)\\Common Files\\PACE\\Services\\LicenseServices\\LDSvc.exe" pid 0064 tid 0068 handles 0xe8/0xec ... 0068:Starting process L"C:\\Program Files (x86)\\Common Files\\PACE\\Services\\LicenseServices\\LDSvc.exe" (entryproc=0x449060) ... 0068:Call advapi32.StartServiceCtrlDispatcherA(0032fdac) ret=004482e8 ... 007c:Call advapi32.RegisterServiceCtrlHandlerA(029090e4 "PACELicenseDServices",004474d0) ret=00447605 ... 007c:Call KERNEL32.CreateRemoteThread(ffffffff,00000000,00000000,00447580,00000000,00000004,00000000) ret=004486d6 ... 007c:Ret KERNEL32.CreateRemoteThread() retval=000000a0 ret=004486d6 ... 0080:Call ucrtbase._beginthreadex(00000000,00000000,004969c0,06527148,00000004,06527168) ret=00496955 ... 0080:Ret ucrtbase._beginthreadex() retval=0000018c ret=00496955 0080:Call KERNEL32.ResumeThread(0000018c) ret=0049699a ... 0080:Ret KERNEL32.ResumeThread() retval=00000001 ret=0049699a ... 00b8: *fd* 24 <- 179 00b8: init_thread( unix_pid=26107, unix_tid=26127, debug_level=1, teb=7ffc4000, entry=004969c0, reply_fd=24, wait_fd=26, cpu=x86 ) 00b8: *fd* 26 <- 180 00b8: init_thread() = 0 { pid=0064, tid=00b8, server_start=1d61d46752028e8 (-2.0593510), info_size=0, version=602, all_cpus=00000003, suspend=1 } 00b8: select( flags=2, cookie=06e1e5a4, timeout=0, size=0, prev_apc=0000, result={}, data={}, context={cpu=x86,eip=7bcb24a4,esp=06e1fff0,ebp=00000000,eflags=00000202,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=004969c0,ebx=065231e0,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}} ) 00b8: select() = TIMEOUT { call={APC_NONE}, apc_handle=0000, context={} } 00b8:Call PE DLL (proc=0x7e769d80,module=0x7e720000 L"ucrtbase.dll",reason=THREAD_ATTACH,res=(nil)) ... L"WININET.dll",reason=THREAD_ATTACH,res=(nil)) retval=1 00b8:Call PE DLL (proc=0x160050e3,module=0x16000000 L"dnssd.dll",reason=THREAD_ATTACH,res=(nil)) ... 00b8:Call KERNEL32.WaitForMultipleObjects(00000002,06e1fd90,00000000,fffffffe) ret=00495e84 00b8:Call kernelbase.WaitForMultipleObjects(00000002,06e1fd90,00000000,fffffffe) ret=7bc9f8e4 00b8:Call ntdll.NtWaitForMultipleObjects(00000002,06e1fb7c,00000001,00000000,06e1fb00) ret=7b040eda 00b8: select( flags=2, cookie=06e1f194, timeout=+4294967.2939836, size=12, prev_apc=0000, result={}, data={WAIT,handles={0124,00dc}}, context={} ) 00b8: select() = PENDING { call={APC_NONE}, apc_handle=0000, context={} } 00b8: *wakeup* signaled=0 00b8:Ret ntdll.NtWaitForMultipleObjects() retval=00000000 ret=7b040eda 00b8:Ret kernelbase.WaitForMultipleObjects() retval=00000000 ret=7bc9f8e4 00b8:Ret KERNEL32.WaitForMultipleObjects() retval=00000000 ret=00495e84 00b8:Call KERNEL32.WaitForSingleObject(00000128,00000000) ret=00592a19 00b8:Call kernelbase.WaitForSingleObject(00000128,00000000) ret=7bc9f8e4 00b8:Call ntdll.NtWaitForMultipleObjects(00000001,06e1fc3c,00000001,00000000,06e1fbc0) ret=7b040eda 00b8: select( flags=2, cookie=06e1f254, timeout=0, size=8, prev_apc=0000, result={}, data={WAIT,handles={0128}}, context={} ) 00b8: select() = 0 { call={APC_NONE}, apc_handle=0000, context={} } 00b8:Ret ntdll.NtWaitForMultipleObjects() retval=00000000 ret=7b040eda 00b8:Ret kernelbase.WaitForSingleObject() retval=00000000 ret=7bc9f8e4 00b8:Ret KERNEL32.WaitForSingleObject() retval=00000000 ret=00592a19 00b8:trace:process:NtQueryInformationProcess (0xffffffff,0x00000022,0x7ffc7ac0,0x00000004,(nil)) 00b8:trace:seh:raise_exception code=c0000005 flags=0 addr=(nil) ip=00000000 tid=00b8 00b8:trace:seh:raise_exception info[0]=00000008 00b8:trace:seh:raise_exception info[1]=00000000 00b8:trace:seh:raise_exception eax=06e1fdec ebx=065231e0 ecx=00002592 edx=4a108e6a esi=00000000 edi=012933bb 00b8:trace:seh:raise_exception ebp=06e1fdec esp=06e1fbd0 cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00010246 00b8:trace:seh:call_vectored_handlers calling handler at 0x448700 code=c0000005 flags=0 00b8:trace:seh:call_vectored_handlers handler at 0x448700 returned 0 00b8:trace:seh:call_stack_handlers calling handler at (nil) code=c0000005 flags=0 00b8:trace:process:NtQueryInformationProcess (0xffffffff,0x00000022,0x7ffc7ac0,0x00000004,(nil)) 00b8:trace:seh:raise_exception code=c0000005 flags=0 addr=(nil) ip=00000000 tid=00b8 00b8:trace:seh:raise_exception info[0]=00000008 00b8:trace:seh:raise_exception info[1]=00000000 00b8:trace:seh:raise_exception eax=06e1f86c ebx=06e1fb78 ecx=00000000 edx=7bcb2550 esi=06e1f8ac edi=06e1fde0 00b8:trace:seh:raise_exception ebp=06e1f808 esp=06e1f7dc cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00010216 00b8:trace:seh:call_vectored_handlers calling handler at 0x448700 code=c0000005 flags=0 00b8:trace:seh:call_vectored_handlers handler at 0x448700 returned 0 00b8:trace:seh:call_stack_handlers calling handler at 0x7bcb2550 code=c0000005 flags=0 00b8:trace:seh:call_stack_handlers handler at 0x7bcb2550 returned 2 00b8:trace:seh:call_stack_handlers calling handler at (nil) code=c0000005 flags=10 ... 00b8:err:seh:setup_exception_record stack overflow 1600 bytes in thread 00b8 eip f7c3f5ed esp 06d20cf0 stack 0x6d20000-0x6d21000-0x6e20000 00b8: *killed* exit_code=0 --- snip --- The root cause can be seen much earlier. NOTE: I made the output linear / "atomic" for easier reading. In reality various consecutive calls were interleaved from many other threads started in parallel. --- snip --- ... 0080:Call ucrtbase._beginthreadex(00000000,00000000,004969c0,065231e0,00000004,06523200) ret=00496955 0080:Call KERNEL32.CreateRemoteThread(ffffffff,00000000,00000000,004969c0,065231e0,00000004,06523200) ret=004486d6 0080:Call kernelbase.CreateRemoteThread(ffffffff,00000000,00000000,004969c0,065231e0,00000004,06523200) ret=7bc9f8e4 0080:Call ntdll.RtlCreateUserThread(ffffffff,00000000,00000001,00000000,00000000,00000000,004969c0,065231e0,06bfec30,06bfec24) ret=7b0434a6 0080: *fd* 16 <- 177 0080: new_thread( process=ffffffff, access=001fffff, suspend=1, request_fd=16, objattr={} ) 0080: new_thread() = 0 { tid=00b8, handle=00e0 } 0080:trace:virtual:map_view got mem in reserved area 0x7ffc4000-0x7ffc8000 0080:trace:virtual:VIRTUAL_DumpView View: 0x7ffc4000 - 0x7ffc7fff (valloc) 0080:trace:virtual:VIRTUAL_DumpView 0x7ffc4000 - 0x7ffc7fff c-rw- 0080:trace:virtual:map_view got mem in reserved area 0x6d20000-0x6e24000 0080:trace:virtual:VIRTUAL_DumpView View: 0x6d20000 - 0x6e23fff (valloc) 0080:trace:virtual:VIRTUAL_DumpView 0x6d20000 - 0x6d20fff c---- 0080:trace:virtual:VIRTUAL_DumpView 0x6d21000 - 0x6d21fff cgrw- 0080:trace:virtual:VIRTUAL_DumpView 0x6d22000 - 0x6e23fff c-rw- 0080:Ret ntdll.RtlCreateUserThread() retval=00000000 ret=7b0434a6 0080:Ret kernelbase.CreateRemoteThread() retval=000000e0 ret=7bc9f8e4 0080:Ret KERNEL32.CreateRemoteThread() retval=000000e0 ret=004486d6 0080:Call KERNEL32.GetThreadContext(000000e0,06bfea38) ret=00448963 0080:Call kernelbase.GetThreadContext(000000e0,06bfea38) ret=7bc9f8e4 0080: get_thread_context( handle=00e0, flags=00000010 ) 0080: get_thread_context() = ACCESS_DENIED { self=0, handle=0000, context={} } ... 00b8: init_thread( unix_pid=26107, unix_tid=26127, debug_level=1, teb=7ffc4000, entry=004969c0, reply_fd=24, wait_fd=26, cpu=x86 ) 00b8: *fd* 26 <- 180 ... 0080:Call ntdll.RtlNtStatusToDosError(c0000022) ret=7b04371d 0080:Ret ntdll.RtlNtStatusToDosError() retval=00000005 ret=7b04371d 0080:Ret kernelbase.GetThreadContext() retval=00000000 ret=7bc9f8e4 0080:Ret KERNEL32.GetThreadContext() retval=00000000 ret=00448963 ... 00b8: init_thread() = 0 { pid=0064, tid=00b8, server_start=1d61d46752028e8 (-2.0593510), info_size=0, version=602, all_cpus=00000003, suspend=1 } ... 0080:Ret ucrtbase._beginthreadex() retval=000000e0 ret=00496955 0080:Call KERNEL32.ResumeThread(000000e0) ret=0049699a 0080:Call kernelbase.ResumeThread(000000e0) ret=7bc9f8e4 0080:Call ntdll.NtResumeThread(000000e0,06bfed74) ret=7b043b01 0080: resume_thread( handle=00e0 ) 0080: resume_thread() = 0 { count=1 } 0080:Ret ntdll.NtResumeThread() retval=00000000 ret=7b043b01 0080:Ret kernelbase.ResumeThread() retval=00000001 ret=7bc9f8e4 0080:Ret KERNEL32.ResumeThread() retval=00000001 ret=0049699a --- snip --- Every newly created (suspended) thread gets the hardware debug breakpoint registers "consumed" with predefined values (handler) as part of the protection scheme. If it fails to do so, the goes haywire at some later point. The "good" case: --- snip --- ... 0080:Call ucrtbase._beginthreadex(00000000,00000000,004969c0,06523b30,00000004,06523b50) ret=00496955 0080:Call KERNEL32.CreateRemoteThread(ffffffff,00000000,00000000,004969c0,06523b30,00000004,06523b50) ret=004486d6 0080:Call kernelbase.CreateRemoteThread(ffffffff,00000000,00000000,004969c0,06523b30,00000004,06523b50) ret=7bc9f8e4 0080:Call ntdll.RtlCreateUserThread(ffffffff,00000000,00000001,00000000,00000000,00000000,004969c0,06523b30,06bfec30,06bfec24) ret=7b0434a6 0080: *fd* 28 <- 184 0080: new_thread( process=ffffffff, access=001fffff, suspend=1, request_fd=28, objattr={} ) 0080: new_thread() = 0 { tid=00c0, handle=00f4 } 0080:trace:virtual:map_view got mem in reserved area 0x7ffbc000-0x7ffc0000 0080:trace:virtual:VIRTUAL_DumpView View: 0x7ffbc000 - 0x7ffbffff (valloc) 0080:trace:virtual:VIRTUAL_DumpView 0x7ffbc000 - 0x7ffbffff c-rw- 0080:trace:virtual:map_view got mem in reserved area 0x6f40000-0x7044000 0080:trace:virtual:VIRTUAL_DumpView View: 0x6f40000 - 0x7043fff (valloc) 0080:trace:virtual:VIRTUAL_DumpView 0x6f40000 - 0x6f40fff c---- 0080:trace:virtual:VIRTUAL_DumpView 0x6f41000 - 0x6f41fff cgrw- 0080:trace:virtual:VIRTUAL_DumpView 0x6f42000 - 0x7043fff c-rw- 0080:Ret ntdll.RtlCreateUserThread() retval=00000000 ret=7b0434a6 0080:Ret kernelbase.CreateRemoteThread() retval=000000f4 ret=7bc9f8e4 0080:Ret KERNEL32.CreateRemoteThread() retval=000000f4 ret=004486d6 0080:Call KERNEL32.GetThreadContext(000000f4,06bfea38) ret=00448963 0080:Call kernelbase.GetThreadContext(000000f4,06bfea38) ret=7bc9f8e4 ... 00c0: *fd* 32 <- 185 00c0: *fd* 34 <- 186 00c0: init_thread( unix_pid=26107, unix_tid=26129, debug_level=1, teb=7ffbc000, entry=004969c0, reply_fd=32, wait_fd=34, cpu=x86 ) 00c0: init_thread() = 0 { pid=0064, tid=00c0, server_start=1d61d46752028e8 (-2.0605960), info_size=0, version=602, all_cpus=00000003, suspend=1 } ... 0080: get_thread_context( handle=00f4, flags=00000010 ) ... 00c0: *sent signal* signal=10 00c0: *signal* signal=19 ... 0080: get_thread_context() = PENDING { self=0, handle=00f8, context={} } 0080: select( flags=2, cookie=06bfd9a4, timeout=+0.0999631, size=8, prev_apc=0000, result={}, data={WAIT_ALL,handles={00f8}}, context={} ) 0080: select() = 0 { call={APC_NONE}, apc_handle=0000, context={} } 0080: get_thread_context( handle=00f8, flags=00000010 ) 0080: get_thread_context() = 0 { self=0, handle=0000, context={cpu=x86,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000} } 0080:trace:seh:__regs_NtGetContextThread 0xf4: dr0=00000000 dr1=00000000 dr2=00000000 dr3=00000000 dr6=00000000 dr7=00000000 0080:Ret kernelbase.GetThreadContext() retval=00000001 ret=7bc9f8e4 0080:Ret KERNEL32.GetThreadContext() retval=00000001 ret=00448963 0080:Call KERNEL32.GetThreadId(000000f4) ret=00448980 0080:Call kernelbase.GetThreadId(000000f4) ret=7bc9f8e4 0080:Call ntdll.NtQueryInformationThread(000000f4,00000000,06bfe988,0000001c,00000000) ret=7b04380a 0080: get_thread_info( handle=00f4, tid_in=0000 ) 0080: get_thread_info() = 0 { pid=0064, tid=00c0, teb=7ffbc000, entry_point=004969c0, affinity=000000ff, exit_code=259, priority=0, last=0, suspend_count=1, desc_len=0, desc=L"" } 0080:Ret ntdll.NtQueryInformationThread() retval=00000000 ret=7b04380a 0080:Ret kernelbase.GetThreadId() retval=000000c0 ret=7bc9f8e4 0080:Ret KERNEL32.GetThreadId() retval=000000c0 ret=00448980 0080:Call KERNEL32.SetThreadContext(000000f4,06bfea38) ret=00448a2b 0080:Call kernelbase.SetThreadContext(000000f4,06bfea38) ret=7bc9f8e4 0080:Call ntdll.NtSetContextThread(000000f4,06bfea38) ret=7b043b40 0080: set_thread_context( handle=00f4, context={cpu=x86,dr0=004490a2,dr1=004490a2,dr2=004490a2,dr3=004490a2,dr6=00000000,dr7=00000055} ) 0080: set_thread_context() = 0 { self=0 } 0080:Ret ntdll.NtSetContextThread() retval=00000000 ret=7b043b40 0080:Ret kernelbase.SetThreadContext() retval=00000001 ret=7bc9f8e4 0080:Ret KERNEL32.SetThreadContext() retval=00000001 ret=00448a2b 0080:Ret ucrtbase._beginthreadex() retval=000000f4 ret=00496955 0080:Call KERNEL32.ResumeThread(000000f4) ret=0049699a 0080:Call kernelbase.ResumeThread(000000f4) ret=7bc9f8e4 0080:Call ntdll.NtResumeThread(000000f4,06bfed74) ret=7b043b01 0080: resume_thread( handle=00f4 ) 0080: resume_thread() = 0 { count=1 } 0080:Ret ntdll.NtResumeThread() retval=00000000 ret=7b043b01 0080:Ret kernelbase.ResumeThread() retval=00000001 ret=7bc9f8e4 0080:Ret KERNEL32.ResumeThread() retval=00000001 ret=0049699a --- snip --- * https://www.winehq.org/pipermail/wine-devel/2020-April/165465.html * https://www.winehq.org/pipermail/wine-devel/2020-April/165466.html $ sha1sum LicenseSupportInstallerWin64.zip b22693fe4c29a60068c1f4c024232f9dc263b12b LicenseSupportInstallerWin64.zip $ du -sh LicenseSupportInstallerWin64.zip 282M LicenseSupportInstallerWin64.zip $ wine-5.7-58-g28ec279518 Regards -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=49043 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Keywords| |download, obfuscation URL| |https://web.archive.org/web | |/20200428185733/http://inst | |allers.ilok.com/iloklicense | |manager/LicenseSupportInsta | |llerWin64.zip -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=49043 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Fixed by SHA1| |e5a9c256ce08868f65ed730c00c | |f016a97369ce3 Status|NEW |RESOLVED Resolution|--- |FIXED --- Comment #1 from Anastasius Focht <focht(a)gmx.net> --- Hello folks, this looks fixed by commit https://source.winehq.org/git/wine.git/commitdiff/e5a9c256ce08868f65ed730c00... ("server: Don't try to synchronize system registers on not initialized threads in get_thread_context request.") Thanks Jacek Since the service is auto-start service, 'wineboot' can be used. --- snip --- $ wineserver -k $ for i in {1..100} ; do echo "try $i" ; WINEDEBUG=+server wineboot 2>&1 | grep "get_thread_context() = ACCESS_DENIED" ; wineserver -w ; done --- snip --- No failures to fetch thread context after the commit. There is still crash in the service but that's a different issue. $ wine --version wine-5.7-97-g7ccc45f754 Regards -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=49043 Alexandre Julliard <julliard(a)winehq.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED --- Comment #2 from Alexandre Julliard <julliard(a)winehq.org> --- Closing bugs fixed in 5.8. -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
participants (1)
-
WineHQ Bugzilla