by hbelusca | November 19, 2016

Hello everyone, I am Hermès Bélusca-Maïto. This is my first week report, as part of the part-time scholarship that I started two weeks ago, that consists in making ReactOS being able to support Word 2010.

Preliminaries

Before starting anything with Word 2010 I needed to prepare a testing environment. Because I am a native Windows user, I use a ReactOS trunk build made with the MSVC compiler. This ReactOS build was then properly installed and adequately configured on a VirtualBox (VBox) virtual machine (VM). I also use the WinDbg debugger to be able to easily debug ReactOS and perform step-by-step and source-code level debugging, and use VirtualKD as the debugger proxy to accelerate serial output especially when tracing is needed. As it can be instructive to compare execution traces of Word 2010 from ReactOS and from a real Windows Server 2003 (Win2k3), I have also installed a Win2k3 VBox VM similarly configured. To make many test reinstallations easier I created an ISO image out of my personal Office 2010 Professional DVD.

I quickly tested Word 2010 installation on Win2k3, where it is supposed to work. The installation did fail at first, because it required the presence of MSXML 6 SP1. The latter can easily be downloaded from Microsoft's website; I performed its installation, and then Word 2010 installation went correctly without any problem. Therefore I redid again a clean Win2k3 VM installation with MSXML 6 SP1 included, and then took VM snapshots (of the ReactOS and Win2k3 VMs) for easier purpose of being able to quickly restore the VMs to a clean state after installation tests.

I then inspected several monitoring tools on ReactOS to see which one(s) could be used for performing different tracing, such as file monitoring, registry monitoring, API calls monitoring etc... As it appeared ReactOS is not completely ready for some of them: SysInternals' Process Monitor (ProcMon) does not work due to the need for a functional filter manager driver (which is half-stubbed in ReactOS); SysInternals' Registry Monitor (RegMon) helper driver crashes due to a problem involving registry callbacks; and well-known Rohitab's APIMonitor is extremely slow to run for some obscure reasons (CORE-10741), and therefore I do not want to use tools that would need ROS fixing to make them work before really starting working on Word 2010.

The only tool that really works flawlessly so far is SysInternals' File monitor (FileMon).

First test of Word 2010 installation under ReactOS

First things first, I attempted to install Word 2010 on ReactOS. The installation package goes through the MSI ("Microsoft Windows Installer") framework. It went well until ≈ 60-70% where it then failed, just saying that "An error happened during the installation".

First installation attempt of Word 2010 in ReactOS

Installation failure at 70%

To attempt to diagnose this problem I first disabled MSI rollback and enabled MSI logging, both via the standard MS method and by using WINE-style debugging (I thank Mark Jansen for pointing out the two first previous MS links to me). I then re-attempted an installation and checked the debug logs, and here is what I have found when the installation fails:

< Snip... > (sdk\lib\rtl\path.c:682) In RtlGetFullPathName_Ustr: RtlQueryEnvironmentVariable_U(=C:) returned 0xc0000100 err:(dll\win32\msi\action.c:501) Execution halted, action L"CAInitSPPTokenStore.x86" returned 1603 < From there on, installation performs cleanup rollback ... >

While the first line is innocuous (it actually says that a call failed and it will take a default code path, this is expected in this context), the second line shows that a MSI action of the Word 2010 installation, named "CAInitSPPTokenStore.x86" , failed with the rather generic error code:

1603: ERROR_INSTALL_FAILURE: Fatal error during installation.

To debug this failure I added much more WINE-style debug tracing, for msi, rpc and ole (the last two modules produce very noisy traces), and instantly noticed that the Word 2010 installation attempted to install, then try to start/stop the so-called "OSPPSVC" (Office Software Protection Platform) service. From there I decided to investigate much more the OSPPSVC service.

OSPPSVC service investigation, 1/2

Performing the installation with rollback disabled allowed me to keep the installed files even after the installation failed, and in particular the services installed by the Word 2010 installation: the "Office Source Engine" service (OSE, does not cause problems during the installation so far), and the "Office Software Protection Platform" service (OSPPSVC), the one that seems to cause the installation to fail.

Services installed by Office installer

Attempting to start it manually failed with a "hard-error" message box saying that the imported function _wtof (needed by OSPPSVC) was not found in MSVCRT.DLL . A quick look inside its code showed that this function was stubbed, and a patch to implement it – inspired from already existing similar functions – was promptly proposed by Amine Khaldi in CORE-12335 and committed in revision 73206. No other imports being missing now, the service may be started.

Or can it be?

It happens that the service fails to successfully start and initialize itself. A look inside the ReactOS event log viewer clearly shows the problem: the service fails with the error:

0x80070002: HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND: The system cannot find the file specified.

This is in contrast with Win2k3 where nothing like that happens, and manually starting the service succeeds.

OSPPSVC failing to load in ReactOS

OSPPSVC successfully starts in Win2k3

But which file(s) the service cannot find in ReactOS and why? To attempt to answer this question, I have traced the file calls using FileMon, with its filter set to "osppsvc.exe". Here is what can be found in the log, taken within ReactOS:

... 56 01:00:04 OSPPSVC.EXE:1960 OPEN C:\WINDOWS\System32\%ALLUSERSPROFILE%\Microsoft\OfficeSoftwareProtectionPlatform\ SUCCESS Options: Open Access: All 57 01:00:04 OSPPSVC.EXE:1960 CLOSE C: SUCCESS 58 01:00:04 OSPPSVC.EXE:1960 READ C: SUCCESS Offset: 0 Length: 16384 59 01:00:04 OSPPSVC.EXE:1960 CLOSE C: SUCCESS 60 01:00:04 OSPPSVC.EXE:1960 READ C: SUCCESS Offset: 0 Length: 16384 61 01:00:04 OSPPSVC.EXE:1960 CLOSE C: SUCCESS 62 01:00:04 OSPPSVC.EXE:1960 QUERY INFORMATION C:\WINDOWS\System32\%ALLUSERSPROFILE%\Microsoft\OfficeSoftwareProtectionPlatform\ SUCCESS FileNetworkOpenInformation 63 01:00:04 OSPPSVC.EXE:1960 CLOSE C:\WINDOWS\System32\%ALLUSERSPROFILE%\Microsoft\OfficeSoftwareProtectionPlatform\ SUCCESS ...

Now, here is what happens in Win2k3:

146 00:58:53 OSPPSVC.EXE:2372 QUERY INFORMATION C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\ SUCCESS Attributes: D ... 280 00:58:54 OSPPSVC.EXE:2372 QUERY INFORMATION C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\Cache\ SUCCESS Attributes: D 281 00:58:54 OSPPSVC.EXE:2372 QUERY INFORMATION C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\Cache\cache.dat SUCCESS Attributes: A 282 00:58:54 OSPPSVC.EXE:2372 OPEN C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\Cache\cache.dat SUCCESS Options: Open Access: All 283 00:58:54 OSPPSVC.EXE:2372 QUERY INFORMATION C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\Cache\cache.dat SUCCESS Length: 189560 ... 291 00:58:54 OSPPSVC.EXE:2372 READ C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\Cache\cache.dat SUCCESS Offset: 131072 Length: 61440 292 00:58:54 OSPPSVC.EXE:2372 CLOSE C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\Cache\cache.dat SUCCESS ...

and in addition, the service opens the following files:

C:\Program Files\Fichiers communs\Microsoft Shared\OfficeSoftwareProtectionPlatform\osppobjs-spp-plugin-manifest-signed.xrm-ms C:\Program Files\Fichiers communs\Microsoft Shared\OfficeSoftwareProtectionPlatform\OSPPOBJS.DLL

We start to see what is happening. While in Win2k3 the service opens a data cache file in C:\Documents and Settings\All Users\Microsoft\OfficeSoftwareProtectionPlatform\ , on ReactOS it attempts to open instead C:\WINDOWS\System32\%ALLUSERSPROFILE%\Microsoft\OfficeSoftwareProtectionPlatform\ , which is not the directory it was intended to open, yet it succeeds (because a previous step of the installer actually created such a directory). What is happening there is that the service cannot expand the %ALLUSERSPROFILE% environment variable (which should be equal to C:\Documents and Settings\All Users\ ), and instead falls back to a malformed path, i.e. is trying to open %ALLUSERSPROFILE%\Microsoft\OfficeSoftwareProtectionPlatform\ from within its current directory C:\WINDOWS\System32\ . As it turns out this problem is due to the fact that currently the environment block, which should contain the %ALLUSERSPROFILE% environment variable, is not suitable as it is for the service. This problem is the subject of the JIRA report CORE-12414 that I intend to fix. Thanks to an apitest service I am currently developing, I can better see what is happening: in ReactOS the environment block of a started service is:

(rostests\apitests\advapi32\service.c:51) ComSpec=C:\WINDOWS\system32\cmd.exe (rostests\apitests\advapi32\service.c:51) NUMBER_OF_PROCESSORS=1 (rostests\apitests\advapi32\service.c:51) OS=Windows_NT (rostests\apitests\advapi32\service.c:51) Path=C:\WINDOWS\bin;C:\WINDOWS\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\UnxUtils\bin;C:\UnxUtils\usr\local\wbin (rostests\apitests\advapi32\service.c:51) PATHEXT=.COM;.EXE;.BAT;.CMD (rostests\apitests\advapi32\service.c:51) PROCESSOR_ARCHITECTURE=x86 (rostests\apitests\advapi32\service.c:51) PROCESSOR_IDENTIFIER=x86 Family 6 Model 14 Stepping 5, G (rostests\apitests\advapi32\service.c:51) PROCESSOR_LEVEL=6 (rostests\apitests\advapi32\service.c:51) PROCESSOR_REVISION=0e05 (rostests\apitests\advapi32\service.c:51) SystemDrive=C: (rostests\apitests\advapi32\service.c:51) SystemRoot=C:\WINDOWS (rostests\apitests\advapi32\service.c:51) TEMP=C:\WINDOWS\TEMP (rostests\apitests\advapi32\service.c:51) TMP=C:\WINDOWS\TEMP (rostests\apitests\advapi32\service.c:51) windir=C:\WINDOWS

while in Win2k3, it is:

(rostests\apitests\advapi32\service.c:51) ALLUSERSPROFILE=C:\Documents and Settings\All Users (rostests\apitests\advapi32\service.c:51) ClusterLog=C:\WINDOWS\Cluster\cluster.log (rostests\apitests\advapi32\service.c:51) CommonProgramFiles=C:\Program Files\Fichiers communs (rostests\apitests\advapi32\service.c:51) COMPUTERNAME=PC-HERMES-2K3 (rostests\apitests\advapi32\service.c:51) ComSpec=C:\WINDOWS\system32\cmd.exe (rostests\apitests\advapi32\service.c:51) FP_NO_HOST_CHECK=NO (rostests\apitests\advapi32\service.c:51) NUMBER_OF_PROCESSORS=1 (rostests\apitests\advapi32\service.c:51) OS=Windows_NT (rostests\apitests\advapi32\service.c:51) Path=C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem (rostests\apitests\advapi32\service.c:51) PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH (rostests\apitests\advapi32\service.c:51) PROCESSOR_ARCHITECTURE=x86 (rostests\apitests\advapi32\service.c:51) PROCESSOR_IDENTIFIER=x86 Family 6 Model 30 Stepping 5, GenuineIntel (rostests\apitests\advapi32\service.c:51) PROCESSOR_LEVEL=6 (rostests\apitests\advapi32\service.c:51) PROCESSOR_REVISION=1e05 (rostests\apitests\advapi32\service.c:51) ProgramFiles=C:\Program Files (rostests\apitests\advapi32\service.c:51) SystemDrive=C: (rostests\apitests\advapi32\service.c:51) SystemRoot=C:\WINDOWS (rostests\apitests\advapi32\service.c:51) TEMP=C:\WINDOWS\TEMP (rostests\apitests\advapi32\service.c:51) TMP=C:\WINDOWS\TEMP (rostests\apitests\advapi32\service.c:51) USERPROFILE=C:\Documents and Settings\Default User (rostests\apitests\advapi32\service.c:51) windir=C:\WINDOWS

And we clearly see all the missing important environment variables: ALLUSERSPROFILE , USERPROFILE , CommonProgramFiles and ProgramFiles .

In my next report I will further investigate the Word 2010 installation after having resolved the problem of environment variables for the OSPPSVC service.

Stay tuned!