https://bugs.winehq.org/show_bug.cgi?id=34079
Anastasius Focht focht@gmx.net changed:
What |Removed |Added ---------------------------------------------------------------------------- Component|-unknown |rpc Summary|OneDrive for Business: |OneDrive for Business C2R |Error on installation |(click-to-run) client |start-up |reports server error | |('rpcrt4.RpcMgmtIsServerLis | |tening' must check if | |binding handle refers to | |remote server)
--- Comment #30 from Anastasius Focht focht@gmx.net --- Hello folks,
revisiting.
Prerequisite: 'Windows 7' setting as requested by bootstrapper installer
The boostrapper first installs a Click-to-Run (C2R) client. App log (user temp directory):
--- snip --- Timestamp Process TID Area Category EventID Level Message Correlation ... 10/26/2015 13:34:33.834 SETU~K2V (0x2d) 0x2e Click-To-Run aoh9n Medium TryGetClient::HandleStateAction: Installation path is: C:\Program Files\Microsoft Office 15 10/26/2015 13:34:33.834 SETU~K2V (0x2d) 0x2e Click-To-Run amaya Medium TryGetClient::HandleStateAction: Looking for existing client. 10/26/2015 13:34:33.834 SETU~K2V (0x2d) 0x2e Click-To-Run amayd Medium TryGetClient::HandleStateAction: Did not find an existing client. Downloading a new one. 10/26/2015 13:34:33.836 SETU~K2V (0x2d) 0x2e Click-To-Run aon8l Medium TryGetClient::HandleStateAction: Getting Cab: i321033.cab 10/26/2015 13:34:35.622 SETU~K2V (0x2d) 0x2e Click-To-Run Telemetry amawv Medium MonitoredScope::ExecuteUnderStopWatch: TryGetClient::HandleStateAction: Getting Cab. Approximate duration: 1786 milliseconds. 10/26/2015 13:34:35.622 SETU~K2V (0x2d) 0x2e Click-To-Run amaye Medium TryGetClient::HandleStateAction: Found C2R Client in extracted cab. 10/26/2015 13:34:35.624 SETU~K2V (0x2d) 0x2e Click-To-Run aoh9t Medium TryLaunchClient::HandleStateAction: Launching OfficeClickToRun.exe with parameters: scenario=unknown scenariosubtype=CDN cdnbaseurl="http://officecdn.microsoft.com/pr/39168D7E-077B-48E7-872C-B232C3E72675" productreleaseid="GrooveRetail" culture="en-us" lcid="1033" platform="x86" version="15.0.4763.1003" prereleasebuild="4419" firstrun="root\office15\firstrun.exe" tx="PR" baseurl="http://officecdn.microsoft.com/PR/39168D7E-077B-48E7-872C-B232C3E72675" pidkeys="3V9N8-W93CC-FQPB8-Y9WVF-TVGJ3" mediatype="CDN" updatesenabled="True" autoUpgrade="True" productstoadd="GrooveRetail_en-us_x-none" trackedduration=1786 ... --- snip ---
and then starts the C2R client to proceed with the actual installation.
Another app log (user temp directory):
--- snip --- Timestamp Process TID Area Category EventID Level Message Correlation 10/26/2015 13:34:35.817 OFFICECL (0x27) 0xd Click-To-Run Telemetry aqkhc Medium {"MachineID":"9534288c4158254a9e6db7719985a469","SessionID":"","GeoID":"-1","Ver":"0.0.0.0","ExeVer":"15.0.4763.1002","SecuritySessionId":"1","ModulePath":"C:\Program Files\Microsoft Office 15\ClientX86\officeclicktorun.exe","CommandLine":"scenario=unknown scenariosubtype=CDN cdnbaseurl="http://officecdn.microsoft.com/pr/39168D7E-077B-48E7-872C-B232C3E72675" productreleaseid="GrooveRetail" culture="en-us" lcid="1033" platform="x86" version="15.0.4763.1003" prereleasebuild="4419" firstrun="root\office15\firstrun.exe" tx="PR" baseurl="http://officecdn.microsoft.com/PR/39168D7E-077B-48E7-872C-B232C3E72675" pidkeys="3V9N8-W93CC-FQPB8-Y9WVF-TVGJ3" mediatype="CDN" updatesenabled="True" autoUpgrade="True" productstoadd="GrooveRetail_en-us_x-none" trackedduration=1786","Bitness":"32","IntegrityLevel":"0x3000"} 10/26/2015 13:34:35.826 OFFICECL (0x27) 0xd Click-To-Run Telemetry aqkhe Medium {"MachineID":"9534288c4158254a9e6db7719985a469","SessionID":"","GeoID":"-1","Ver":"0.0.0.0","OSVersion":"6.1","SP":"1","ProductType":"1","ProcessorArch":"0","Locale":"1033"} ... Medium TaskBranch::DoExecute - Found task {3B2063B8-1A55-431B-9934-D3C4A1AEBC61} that matches {Continue} condition. 10/26/2015 13:34:36.302 OFFICECL (0x27) 0x37 Click-To-Run annua Medium ProcessPool::QueueTaskItem - Task GROUP:{3B2063B8-1A55-431B-9934-D3C4A1AEBC61} is being scheduled to run in this process 10/26/2015 13:34:36.307 OFFICECL (0x27) 0x37 Click-To-Run annvj Medium Worker::TaskExecutionThreadProc - Task BRANCH:{5603D3AB-5291-4F2A-B099-4313629824EB} completed with TaskState TASKSTATE_EXECUTING. 10/26/2015 13:34:36.308 OFFICECL (0x27) 0x37 Click-To-Run aozsm Medium TaskBranch::DoHandleWorkerCompleteEvent - Task {5603D3AB-5291-4F2A-B099-4313629824EB} success event is handled by task {5603D3AB-5291-4F2A-B099-4313629824EB} 10/26/2015 13:34:36.335 OFFICECL (0x27) 0x38 Click-To-Run annub Medium ProcessPool::QueueTaskItem - Sending task CONFIGURE:{E25A6AFC-9880-4760-9008-4438EBF206B0} to the right process. 10/26/2015 13:34:36.335 OFFICECL (0x27) 0x38 Click-To-Run annuc Unexpected ProcessPool::QueueTaskItem - Server returns error. Error code: -2147418113 10/26/2015 13:34:36.336 OFFICECL (0x27) 0x38 Click-To-Run amcfq Medium ProcessPool::QueueTaskItem - Task CONFIGURE:{E25A6AFC-9880-4760-9008-4438EBF206B0} can't be queued. Attempt to skip the task. 10/26/2015 13:34:36.337 OFFICECL (0x27) 0x38 Click-To-Run amcfr Medium Task::DoSkip - Hibernating task (E25A6AFC-9880-4760-9008-4438EBF206B0). It is currently in TASKSTATE_NOTSTARTED state 10/26/2015 13:34:36.341 OFFICECL (0x27) 0x38 Click-To-Run amcfs Medium Task::DoSkip - Skipping task (E25A6AFC-9880-4760-9008-4438EBF206B0). It is currently in TASKSTATE_HIBERNATED state 10/26/2015 13:34:36.346 OFFICECL (0x27) 0x38 Click-To-Run Telemetry aqebp Medium ScenarioController::ShowErrorUI - url is: http://officeredir.microsoft.com/r/rlidOfficeWebHelp?p1=OCSAC2RINSTALL&v.... {"MachineID":"9534288c4158254a9e6db7719985a469","SessionID":"","GeoID":"-1","Ver":"15.0.4763.1003","stringId":"4136","errorSource":"4","errorCode":"2"} --- snip ---
Relevant part of trace log:
--- snip --- ... 002e:Call KERNEL32.CreateProcessW(00522c00 L"C:\Program Files\Microsoft Office 15\ClientX86\OfficeClickToRun.exe",00523bd8 L"OfficeClickToRun.exe scenario=unknown scenariosubtype=CDN cdnbaseurl="http://officecdn.microsoft.com/pr/39168D7E-077B-48E7-872C-B232C3E72675%5C" productreleaseid="GrooveRetail" culture="en-us" lcid="1033" platform="x86" version="15.0.4763.1003" prereleasebuild="4419" firstrun="root\offic"...,00000000,00000000,00000000,08000020,00000000,00000000,0033dfb8,0033dffc) ret=0049f5e6 ... 000d:Call KERNEL32.__wine_kernel_init() ret=7bc6c9a3 ... 002e:Ret KERNEL32.CreateProcessW() retval=00000001 ret=0049f5e6 002e:Call KERNEL32.CloseHandle(000000d0) ret=0049f667 002e:Ret KERNEL32.CloseHandle() retval=00000001 ret=0049f667 ... 002e:Call KERNEL32.WaitForSingleObjectEx(000000cc,ffffffff,00000000) ret=0047dded ... 000d:Call msvcr100.wcsncpy_s(0033bf26,00000801,0033dee8 L"ApiServer::Initialize - Initializing ApiServer for endpoint: C2RClientAPI_Server_Elevated",ffffffff) ret=004846a4 ... 000d:Call KERNEL32.LoadLibraryExW(005e7458 L"Rpcrt4.dll",00000000,00001000) ret=0047a859 000d:fixme:module:load_library unsupported flag(s) used (flags: 0x00001000) 000d:Ret KERNEL32.LoadLibraryExW() retval=7e850000 ret=0047a859 ... 000d:Call KERNEL32.GetProcAddress(7e850000,005e7458 "RpcServerRegisterIf3") ret=0047aa8a 000d:Ret KERNEL32.GetProcAddress() retval=00000000 ret=0047aa8a ... 000d:Call rpcrt4.RpcServerRegisterIf2(0042c230,00000000,00000000,00000008,000004d2,ffffffff,00520a5a) ret=00520746 ... 000d:Ret rpcrt4.RpcServerRegisterIf2() retval=00000000 ret=00520746 000d:Call rpcrt4.RpcServerUseProtseqEpW(0033efa8 L"ncalrpc",0000000a,005e7410 L"C2RClientAPI_Server_Elevated",00000000) ret=005207b3 ... 000d:Call KERNEL32.CreateNamedPipeA(0015af60 "\\.\pipe\lrpc\C2RClientAPI_Server_Elevated",00000003,00000006,000000ff,000016d0,000016d0,00001388,00000000) ret=7e89215c 000d:Ret KERNEL32.CreateNamedPipeA() retval=000000bc ret=7e89215c ... 000d:Ret rpcrt4.RpcServerUseProtseqEpW() retval=00000000 ret=005207b3 ... 000d:Call rpcrt4.RpcServerRegisterAuthInfoW(00401b4c L"",00000009,00000000,00000000) ret=00520826 ... 000d:Ret rpcrt4.RpcServerRegisterAuthInfoW() retval=00000000 ret=00520826 000d:Call rpcrt4.RpcServerListen(00000001,000004d2,00000001) ret=0052088d ... 000d:Ret rpcrt4.RpcServerListen() retval=00000000 ret=0052088d ... 001e:Ret PE DLL (proc=0x355f8f,module=0x350000 L"ApiClient.dll",reason=THREAD_ATTACH,res=(nil)) retval=1 ... 0044:Call KERNEL32.CreateThread(00000000,00000000,004cc2c9,005ece70,00000000,00bfe9e4) ret=004b5e74 ... 0044:Ret KERNEL32.CreateThread() retval=0000015c ret=004b5e74 ... 0038:Call rpcrt4.RpcStringBindingComposeW(00000000,00ffe01c L"ncalrpc",00ffe000 L"",005e9468 L"C2RClientAPI_Server_System",00ffdfe4 L"",00ffd154) ret=0051c2b5 ... 0038:Ret rpcrt4.RpcStringBindingComposeW() retval=00000000 ret=0051c2b5 0038:Call rpcrt4.RpcBindingFromStringBindingW(00170f70 L"ncalrpc:[C2RClientAPI_Server_System]",005e9190) ret=0051c2fe ... 0038:Ret rpcrt4.RpcBindingFromStringBindingW() retval=00000000 ret=0051c2fe ... 0038:Call rpcrt4.RpcBindingSetAuthInfoW(00175570,00000000,00000006,0000000a,00000000,00000000) ret=0051c379 ... 0038:Ret rpcrt4.RpcBindingSetAuthInfoW() retval=00000000 ret=0051c379 ... 0038:Call rpcrt4.RpcMgmtIsServerListening(00175570) ret=004b69a3 0038:Ret rpcrt4.RpcMgmtIsServerListening() retval=00000000 ret=004b69a3 ... 0038:Call msvcr100.wcsncat_s(00ffb034 L"10/26/2015 13:34:36.335\tOFFICECL (0x27)\t0x38\t\tClick-To-Run\tannub\tMedium\tProcessPool::QueueTaskItem - Sending task CONFIGURE:{E25A6AFC-9880-4760-9008-4438EBF206B0} to the right process.",00001001,0041ccd8 L"\t",ffffffff) ret=00484507 ... 0038:Call rpcrt4.RpcMgmtIsServerListening(00175570) ret=00354719 0038:Ret rpcrt4.RpcMgmtIsServerListening() retval=00000000 ret=00354719 ... 0038:Call KERNEL32.CreateFileA(00170fe8 "\\.\pipe\lrpc\C2RClientAPI_Server_System",c0000000,00000000,00000000,00000003,00000000,00000000) ret=7e8922dd 0038:Ret KERNEL32.CreateFileA() retval=ffffffff ret=7e8922dd 0038:Call KERNEL32.WaitNamedPipeA(00170fe8 "\\.\pipe\lrpc\C2RClientAPI_Server_System",ffffffff) ret=7e8923ad 0038:Ret KERNEL32.WaitNamedPipeA() retval=00000000 ret=7e8923ad ... 0038:Call KERNEL32.RaiseException(000006ba,00000000,00000000,00000000) ret=7e89b5ce 0038:trace:seh:raise_exception code=6ba flags=0 addr=0x7b845f21 ip=7b845f21 tid=0038 0038:trace:seh:raise_exception eax=7b832cbd ebx=00ffd8d0 ecx=00ffd800 edx=00000000 esi=00ffd850 edi=00ffd810 0038:trace:seh:raise_exception ebp=00ffd7e8 esp=00ffd784 cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00000246 0038:trace:seh:call_stack_handlers calling handler at 0x35e43b code=6ba flags=0 ... 0038:Call KERNEL32.RaiseException(e06d7363,00000001,00000003,00ffc9e0) ret=0035672c 0038:trace:seh:raise_exception code=e06d7363 flags=1 addr=0x7b845f21 ip=7b845f21 tid=0038 0038:trace:seh:raise_exception info[0]=19930520 0038:trace:seh:raise_exception info[1]=00ffcd90 0038:trace:seh:raise_exception info[2]=0035f594 0038:trace:seh:raise_exception eax=7b832cbd ebx=0035eb30 ecx=0000000c edx=00ffc924 esi=00ffc9cc edi=00ffc990 0038:trace:seh:raise_exception ebp=00ffc968 esp=00ffc904 cs=0023 ds=002b es=002b fs=0063 gs=006b flags=00000202 0038:trace:seh:call_stack_handlers calling handler at 0x3569b7 code=e06d7363 flags=1 ... 0038:Call msvcr100.wcsncat_s(00ffb034 L"10/26/2015 13:34:36.335\tOFFICECL (0x27)\t0x38\t\tClick-To-Run\tannuc\tUnexpected\tProcessPool::QueueTaskItem - Server returns error. Error code: -2147418113",00001001,0041ccd8 L"\t",ffffffff) ret=00484507 ... --- snip ---
The client is a server on its own (= registers LRPC endpoint 'C2RClientAPI_Server_Elevated'). It then tries to establish a connection to another LRPC endpoint 'C2RClientAPI_Server_System' which obviously doesn't exist because the remote server/service is not present. The problem is the rather simple-case implementation of 'RpcMgmtIsServerListening'.
As already mentioned, the client exposes an interface on its own (being server too) hence 'RpcMgmtIsServerListening' returns S_OK which is wrong since the binding handle refers to another remote server that doesn't exist yet. In this case returning value 'RPC_S_NOT_LISTENING' code 1715 (0x6b3) would be the proper answer which tells the client to install/start the desired remote service/server providing the interface.
Source: https://source.winehq.org/git/wine.git/blob/73a68b065bec473719d7bcbcdb738716...
--- snip --- 1673 RPC_STATUS WINAPI RpcMgmtIsServerListening(RPC_BINDING_HANDLE Binding) 1674 { 1675 RPC_STATUS status = RPC_S_NOT_LISTENING; 1676 1677 TRACE("(%p)\n", Binding); 1678 1679 EnterCriticalSection(&listen_cs); 1680 if (manual_listen_count > 0) status = RPC_S_OK; 1681 LeaveCriticalSection(&listen_cs); 1682 return status; 1683 } --- snip ---
$ sha1sum Setup.x86.en-us_GrooveRetail_3V9N8-W93CC-FQPB8-Y9WVF-TVGJ3_TX_PR_.exe ddf02801b54227849886ef9a2767a1155f87a9ef Setup.x86.en-us_GrooveRetail_3V9N8-W93CC-FQPB8-Y9WVF-TVGJ3_TX_PR_.exe
$ du -sh Setup.x86.en-us_GrooveRetail_3V9N8-W93CC-FQPB8-Y9WVF-TVGJ3_TX_PR_.exe 1.1M Setup.x86.en-us_GrooveRetail_3V9N8-W93CC-FQPB8-Y9WVF-TVGJ3_TX_PR_.exe
$ wine --version wine-1.7.53-156-gf8d78b0
Regards