InstallScript Custom Action invoke call fails

[DLee65]

I have a customer trying to install Street Atlas USA 2009 on their Windows XP Pro SP2 machine. They have administrative privileges and IsSetupFilesExtract completes successfully.

However, when my first InstallScript custom action executes the invoke fails immediately even before a line of code is processed - or so it seems.
Custom Action Name: Set_COMMON_DOCUMENTS_Dir
Return Processing: Synchronous (Check Exit Code)
Execution: Immediate Execution
Scheduling: Always Execute
Install UI Sequence: After LaunchConditions
Install UI Conditions: 1

The purpose of the function is to set a property for COMMON_DOCUMENTS. The function code is listed below:

function SetCommonDocumentsDir (hMSI)
	NUMBER	nResult;
	STRING	strCommonDocumentsDir;
begin
	nResult = SHFolder.SHGetFolderPathA(NULL, CSIDL_COMMON_DOCUMENTS, NULL, 0, strCommonDocumentsDir);
    if nResult =0
    then
		MsiSetProperty(hMSI, "COMMONDOCUMENTS", strCommonDocumentsDir);
	else
		SprintfMsiLog("Failed to set path for COMMONDOCUMENTS. Return Value: %d", nResult);
	endif;
end;

For most customers this function works like a charm without any problems. I am in the process of trying to debug this working on the assumption that it might be something like a missing dependency but trying to debug this is going to be difficult.

Does anyone here know of some things I can look at that can cause InstallScript custom actions to fail on the invoke process? I will attach the MSI log file from the customer with user information blanked out.

[DLee65]

* listens to crickets * ... anyone have any ideas? I guess I will post this information to Accresso support directly.

[DLee65]

I was able to debug on my development machine. When I debug I get the following information. Note that I cannot get this to fail on my machine.

[code]MSI (c) (DC:7C) [06:53:34:201]: Doing action: Set_COMMON_DOCUMENTS_Dir
Action 6:53:34: Set_COMMON_DOCUMENTS_Dir.
Action start 6:53:34: Set_COMMON_DOCUMENTS_Dir.
MSI (c) (DC:DC) [06:53:34:544]: Invoking remote custom action. DLL: C:\DOCUME~1\danl\LOCALS~1\Temp\MSI781.tmp, Entrypoint: f2
InstallShield 6:53:34: Running InstallScript function f2
InstallShield 6:53:34: Using temp folder C:\DOCUME~1\danl\LOCALS~1\Temp\{449F62FE-1C74-47FB-9523-26CB33C4D792}
InstallShield 6:53:34: Installing engine...
InstallShield 6:53:34: Using product language 1033
InstallShield 6:53:34: Extracting support file setup.inx to C:\DOCUME~1\danl\LOCALS~1\Temp\{449F62FE-1C74-47FB-9523-26CB33C4D792}\setup.inx
InstallShield 6:53:34: Opening stream of file C:\DOCUME~1\danl\LOCALS~1\Temp\MSI781.tmp
InstallShield 6:53:34: Extracting support file ISRT.dll to C:\DOCUME~1\danl\LOCALS~1\Temp\{449F62FE-1C74-47FB-9523-26CB33C4D792}\ISRT.dll
InstallShield 6:53:34: Extracting support file IsConfig.ini to C:\DOCUME~1\danl\LOCALS~1\Temp\{449F62FE-1C74-47FB-9523-26CB33C4D792}\IsConfig.ini
InstallShield 6:53:34: Extracting support file _isres1033.dll to C:\DOCUME~1\danl\LOCALS~1\Temp\{449F62FE-1C74-47FB-9523-26CB33C4D792}\_isres.dll
InstallShield 6:53:34: Extracting support file String1033.txt to C:\DOCUME~1\danl\LOCALS~1\Temp\{449F62FE-1C74-47FB-9523-26CB33C4D792}\String1033.txt
InstallShield 6:53:34: Skipping optional support file _isuser1033.dll
InstallShield 6:53:34: Setting script cmdline...
InstallShield 6:53:34: Using ISSCRIPTDEBUG: 1
InstallShield 6:53:34: ProductCode is {AEB95804-A937-49E6-940A-37A606C16D5D}
InstallShield 6:53:34: Initializing Engine
InstallShield 6:53:35: Done Initializing...
InstallShield 6:53:35: Registering Msi Server...
[/code]
Note that in this log file I see files extracting. However in the customer's log none of the files ever extract. Any ideas? Thanks.

[Christopher_Pai]

Have you opened a support ticket? I looked at the logfile and nothing stood out.

[DLee65]

Yes, I have a support ticket open. I just heard from InstallShield support - and I must admit that their response time is lightyears faster than under Macrovision. Here is their initial response:

Looking at the log file it seems that there is an exception being thrown immediately after the custom action is being called. One way to obtain more information about this problem (which is likely to be machine specific) is to use DebugView from Microsoft:

DebugView for Windows v4.74
http://technet.microsoft.com/en-us/sysinternals/bb896647.aspx

If you launch this utility and then run the install you will see the usual logging information plus more details in DebugView. You will need to set the following registry key for this to work:

HKEY_LOCAL_MACHINE\SOFTWARE\Policies\Microsoft\Windows\Installer
DWORD: Debug with Data 7

Debug
http://msdn.microsoft.com/en-us/library/aa368263(VS.85).aspx

This may indicate the cause of the problem such as an access violation or a corrupted runtime library. You can also send across the text that is captured and I will look through it to see if I can see the problem.

[DLee65]

Here is an update to this issue. Running the Microsoft Debugger did not reveal any exception errors. We now know of at least three customers with this same failure. Two of the customers are running Windows XP SP2 Media Center Edition.

I applaud Acresso and InstallShield for their fast response and turn around on email exchange.

If anyone else has any ideas on what to look for that would certainly be appreciated. Right now we are stumped. The very first call to an InstallScript custom action fails in the invoke process.

[joshstechnij]

This seems to be some rather strange behavior. Is this occurring on more than one machine?

The custom action is dying at a very early point (if it is even reaching the f2 entry point in ISSetup.dll). We do the following as the very first lines of code in the ISSetup.dll entry points for InstallScript custom actions:
1. Save the install handle.
2. Log the message "Running InstallScript function fX" through MsiProcessMessage.

The original log posted doesn't even contain the above log info. There's not much in the above items that could throw an exception. There's two possibilities that I can see at this point:
- ISSetup.dll is failing to load.
- Our code is never called, and MSI is failing to call the action for some reason.
- Our code is called, but there is some issue with MSI on the machine that is causing the MsiProcessMessage call to die.

The most likely cause would seem to be ISSetup.dll failing to load, since the ISSetupFilesExtract action (which depends on msi.dll and sends information to the log) is running. The next step might be to use the SysInternals ProcessMonitor utility to see if any LoadImage failures are occurring with any files in the temp directory named MSI.tmp.

[DLee65]

Yes, we now have reports from three customers who are having this problem.

It is good to know what is going on in terms of processes. My coworker and I did not have a good idea of what process should be happening next other than extracting the MSI.tmp and we did not have a good method for testing for this on a customer's machine.

The customer might be willing to use sysinternals as you suggested though. One of the customers is very knowledgeable and so working with him is a bit easier. Thanks for the suggestion.

[DLee65]

For one of the customers, disabling the Sophos AntiVirus software Service and startup apps fixed the problem. It looked as if Sophos was making some type of hook into the DLL preventing access to the DLL when InstallShield was trying to access the extracted msi*.tmp file.