cancel
Showing results for 
Show  only  | Search instead for 
Did you mean: 
Rothmansua
Level 3

DLL Custom Action doesn't get called on German OS

Hi all,

I am experiencing very strange problem with an InstallShield Basic MSI installation.
The installation contains a DLL custom action that gets called in the UI sequence between CostInitialize and CostFinalize actions.

The custom action works well on 2 of my Windows XP PCs which have English OS versions and it simply doesn't get executed on 2 Windows XP and 1 Windows Vista machine which have German OS installed.

When the installation comes to the custom action call here is the exerpt from the "working" installation log:


MSI © (C8:64) [13:13:00:573]: Doing action: GetContributePath
Action 13:13:00: GetContributePath.
Action start 13:13:00: GetContributePath.
MSI © (C8:78) [13:13:00:588]: Invoking remote custom action. DLL: C:\DOCUME~1\SSSSSS~1\LOCALS~1\Temp\MSI3C1.tmp, Entrypoint: DLL3
MSI © (C8:28) [13:13:00:635]: PROPERTY CHANGE: Adding CONTRIBUTE_INSTALLED property. Its value is '1'.
MSI © (C8!28) [13:13:00:635]: PROPERTY CHANGE: Adding CONTRIBUTE_PATH property. Its value is 'C:\Program Files\Adobe\Adobe Contribute CS3'.
Action ended 13:13:00: GetContributePath. Return value 1.


And here is the same installation package on a German OS:


MSI © (D8:A0) [13:03:31:275]: Doing action: GetContributePath
Action 13:03:31: GetContributePath.
Action start 13:03:31: GetContributePath.
MSI © (D8:70) [13:03:31:297]: Invoking remote custom action. DLL: C:\Users\SSSSSS~1\AppData\Local\Temp\MSID301.tmp, Entrypoint: DLL3
Action ended 13:03:36: GetContributePath. Return value 1.


On the German PC right after
Action start 13:03:31: GetContributePath.
an InstallShield warning message box gets displayed:

Title: InstallShield DLL Custom Action
Text: Fie 'C:\Users\SSSSSS~1\AppData\Local\Temp\_is17CA.tmp can not be found. Make sure the file is on target system or installed already.

At this moment the mentioned file doesn't exist on the hard drive (also taking into account German folder translations).

I am pretty sure that the custom action doesn't get executed (you can also see in the log that the MSI properties do not get set, no output from DLL in my custom log file either).

I am building the installation package using English version of the InstallShield 2009 Professional.

I have found only a single link on internet with somehow similar problem:
http://community.flexerasoftware.com/archi...p?t-158588.html
Here, as I understand, the reason is a wrong version of the ISSetup.dll, which I assume is an InstallShield problem?

Has anybody seen such kind of error?
In which direction should I move now? I am pretty disappointed at the moment.

Thank you for any ideas.
Labels (1)
0 Kudos
(11) Replies
joshstechnij
Level 10 Flexeran
Level 10 Flexeran

This error is typically caused by missing dependencies required to successfully load a DLL with LoadLibrary. You can usually troubleshoot what dependencies might be missing with tools like Dependency Walker or Process Monitor. The following KB article contains some additional information regarding this error:
Q112128: INFO: Troubleshooting Failures Of DLL Custom Actions
0 Kudos
Rothmansua
Level 3

Even if the missing file is a _is*.tmp one?
My custom action DLL is stored in the Binary table and gets called in the UI sequence.
The DLL can be used in other installation packages on the same 5 test machines with no problems. It doesn't require any external dependencies except C runtime.
0 Kudos
joshstechnij
Level 10 Flexeran
Level 10 Flexeran

Since LoadLibrary doesn't report which file is missing when a DLL fails to load, we will wind up reporting the DLL we attempted to load with LoadLibrary as missing. The best way to tell for sure would be to use Process Monitor to watch file system access filetering against the msiexec.exe process. If the file we are reporting as not present is in fact the cause, you will see a FILE NOT FOUND status in Process Monitor when the system tries to open this file. If a missing dependency is the problem, you will see a number of FILE NOT FOUND failures against the missing dependency as LoadLibrary tries to find the dependency in the system DLL search path.

Depending on what the results are of trying to use Process Monitor to troubleshoot this behavior, the next step would be to determine why the file is missing and attempt to reproduce this behavior in a sample project, and if possible, provide us with the sample project, or, resolve the missing dependency issue.
0 Kudos
Rothmansua
Level 3

I have reproduced the issue on the English Vista PC. So it doesn't really look like language problem any more.

Here is an extract from the Process Monitor with filter on MsiExec.exe only:

12:11:25,5637394 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Generic Read, Disposition: Create, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: 0, OpenResult: Created
12:11:25,5655059 MsiExec.exe 2172 QueryStandardInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS AllocationSize: 0, EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory: False
12:11:25,5655373 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5662283 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: 0, OpenResult: Overwritten
12:11:25,5667860 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 0, Length: 10.240, Priority: Normal
12:11:25,5672273 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FAST IO DISALLOWED Offset: 10.240, Length: 10.240
12:11:25,5672459 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 10.240, Length: 10.240, Priority: Normal
12:11:25,5675490 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 20.480, Length: 10.240
12:11:25,5677722 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FAST IO DISALLOWED Offset: 30.720, Length: 10.240
12:11:25,5677878 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 30.720, Length: 10.240, Priority: Normal
12:11:25,5680636 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 40.960, Length: 10.240
12:11:25,5682865 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 51.200, Length: 2.048
12:11:25,5687004 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5790923 MsiExec.exe 2172 RegOpenKey HKLM\Software\InstallShield\10\DebugDLLCustomAction NAME NOT FOUND Desired Access: Read
12:11:25,5793212 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\is7BC4.tmp SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: R, ShareMode: Read, AllocationSize: n/a, OpenResult: Opened
12:11:25,5794274 MsiExec.exe 2172 ReadFile C:\Users\sssssssssssss\AppData\Local\Temp\is7BC4.tmp END OF FILE Offset: 0, Length: 1.024, Priority: Normal
12:11:25,5794545 MsiExec.exe 2172 QueryStandardInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\is7BC4.tmp SUCCESS AllocationSize: 0, EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory: False
12:11:25,5794721 MsiExec.exe 2172 ReadFile C:\Users\sssssssssssss\AppData\Local\Temp\is7BC4.tmp SUCCESS Offset: 0, Length: 0, Priority: Normal
12:11:25,5794913 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\is7BC4.tmp SUCCESS
12:11:25,5797143 MsiExec.exe 2172 QueryOpen C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FAST IO DISALLOWED
12:11:25,5798292 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:11:25,5798902 MsiExec.exe 2172 QueryBasicInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS CreationTime: 05.02.2010 12:11:25, LastAccessTime: 05.02.2010 12:11:25, LastWriteTime: 05.02.2010 12:11:25, ChangeTime: 05.02.2010 12:11:25, FileAttributes: ANCI
12:11:25,5799037 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5801929 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened
12:11:25,5803157 MsiExec.exe 2172 WriteFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Offset: 0, Length: 53.248, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal
12:11:25,5809456 MsiExec.exe 2172 SetEndOfFileInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS EndOfFile: 53.248
12:11:25,5809938 MsiExec.exe 2172 CreateFileMapping C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS SyncType: SyncTypeOther
12:11:25,5810383 MsiExec.exe 2172 CreateFileMapping C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FILE LOCKED WITH ONLY READERS SyncType: SyncTypeCreateSection, PageProtection: PAGE_READONLY
12:11:25,5810488 MsiExec.exe 2172 QueryStandardInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS AllocationSize: 53.248, EndOfFile: 53.248, NumberOfLinks: 1, DeletePending: False, Directory: False
12:11:25,5811224 MsiExec.exe 2172 CreateFileMapping C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS SyncType: SyncTypeOther
12:11:25,5922385 MsiExec.exe 2172 Load Image C:\Users\SSSSSS~1\AppData\Local\Temp\_is8655.tmp SUCCESS Image Base: 0x800000, Image Size: 0xd000
12:11:25,5922835 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5924616 MsiExec.exe 2172 QueryOpen C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FAST IO DISALLOWED
12:11:25,5925770 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
12:11:25,5926384 MsiExec.exe 2172 QueryBasicInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS CreationTime: 05.02.2010 12:11:25, LastAccessTime: 05.02.2010 12:11:25, LastWriteTime: 05.02.2010 12:11:25, ChangeTime: 05.02.2010 12:11:25, FileAttributes: ANCI
12:11:25,5926521 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5928385 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Read Data/List Directory, Execute/Traverse, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened
12:11:25,5929250 MsiExec.exe 2172 CreateFileMapping C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS SyncType: SyncTypeOther
12:11:25,5929935 MsiExec.exe 2172 CreateFileMapping C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FILE LOCKED WITH ONLY READERS SyncType: SyncTypeCreateSection, PageProtection: PAGE_EXECUTE
12:11:25,5930429 MsiExec.exe 2172 CreateFileMapping C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS SyncType: SyncTypeOther
12:11:25,5930683 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5942719 MsiExec.exe 2172 Load Image C:\Users\SSSSSS~1\AppData\Local\Temp\_is8655.tmp SUCCESS Image Base: 0x800000, Image Size: 0xd000
12:11:25,5945042 MsiExec.exe 2172 RegOpenKey HKLM\Software\Microsoft\Windows\CurrentVersion\SideBySide SUCCESS Desired Access: Read
12:11:25,5945487 MsiExec.exe 2172 RegQueryValue HKLM\COMPONENTS\PreferExternalManifest NAME NOT FOUND Length: 20
12:11:25,5945633 MsiExec.exe 2172 RegCloseKey HKLM\COMPONENTS SUCCESS
12:11:25,5947254 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened
12:11:25,5948140 MsiExec.exe 2172 QueryBasicInformationFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS CreationTime: 05.02.2010 12:11:25, LastAccessTime: 05.02.2010 12:11:25, LastWriteTime: 05.02.2010 12:11:25, ChangeTime: 05.02.2010 12:11:25, FileAttributes: ANCI
12:11:25,5986885 MsiExec.exe 2172 CloseFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SUCCESS
12:11:25,5991260 MsiExec.exe 2172 CreateFile C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp SHARING VIOLATION Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a
12:11:25,5996095 MsiExec.exe 2172 RegOpenKey HKLM\Software\Microsoft\Windows\Windows Error Reporting\Escalation NAME NOT FOUND Desired Access: Read
12:11:25,5997617 MsiExec.exe 2172 RegOpenKey HKLM\Software\Microsoft\SQMClient\Windows\DisabledSessions SUCCESS Desired Access: Read
12:11:25,5997925 MsiExec.exe 2172 RegQueryValue HKLM\SOFTWARE\Microsoft\SQMClient\Windows\DisabledSessions\GlobalSession NAME NOT FOUND Length: 20


During installation the IS reports about missing file _is8655.tmp
As I can see it gets created normally, "loaded" and closed twice. The only problem here is "sharing violation".

Also I find strange that the installation built with IS 2009 tries to access registry under IS 10 keys.

I have recheked once more now. The installation project I am having problems with was converted from IS 10 to IS 12 and then to IS 2009 format.

Before the convertion the custom action worked well in the installation made with IS 12.
0 Kudos
joshstechnij
Level 10 Flexeran
Level 10 Flexeran

The registry read from Software\InstallShield\10\DebugDLLCustomAction occurs just before we call LoadLibrary against the DLL provided in the project (note that although this still looks at a version 10 key, this should have no impact as this registry entry is only used to force attaching a debugger before calling your DLL). The LoadLibrary call begins in the Process Monitor log with the following line:
12:11:25,5797143 MsiExec.exe 2172 QueryOpen C:\Users\sssssssssssss\AppData\Local\Temp\_is8655.tmp FAST IO DISALLOWED


The remaining log information here is all generated from code inside LoadLibrary. What seems strange is there are WriteFile and SetEndOfFileInformation events occurring within the context of LoadLibrary (by the time we call LoadLibrary, we have closed our handle to the file so we can't modify it without reopening the file). If I test this on a Windows Server 2008 machine (essentially equivalent to Vista), I do not see these events. Without knowing anything about this DLL, this could be caused by code running in DllMain (called by LoadLibrary) that I don't have in my test DLL.

If this DLL does contain code in DllMain, this code should be suspected first as the possible cause of a failure to load the DLL (see http://www.microsoft.com/whdc/driver/kernel/DLL_bestprac.mspx and http://blogs.msdn.com/mgrier/ for possible problems caused by non-trivial code contained in DllMain).

Another possible cause of this behavior could be an application compatibility shim altering the LoadLibrary behavior and somehow causing an issue when trying to load this DLL.

The sharing violation is most likely why the LoadLibrary call fails, but the cause of the sharing violation is unfortunately unknown. It may be possible to gain some additional information turning on loader snaps for msiexec.exe (with Image File Execution Options) to see if any debug output produced by the LDR component indicates the cause of this behavior.
0 Kudos
Rothmansua
Level 3

Thank you Josh,

It appears that my DLL (inherited and not written by me) uses extensively MFC in a shared library.
I tried to recompile everything linking MFC statically in. That didn't help (same behavior).
The DLL doesn't contain DllMain at all (it gets linked in from the MFC library).
I am trying to figure out now whether the MFC dependency is causing an issue.
0 Kudos
joshstechnij
Level 10 Flexeran
Level 10 Flexeran

Another thing that you may want to try if you haven't already is disabling any anti-virus software on the machine(s) encountering this behavior. We have seen a number of anti-virus products in the past cause a failure to load our own runtime DLLs.
0 Kudos
Rothmansua
Level 3

Issue persists also with disabled antivirus.
I have created an empty custom action DLL with the same exported functions as initial one but without any MFC dependencies and all functinos are epmty:


BOOL APIENTRY DllMain( HMODULE hModule,
DWORD ul_reason_for_call,
LPVOID lpReserved
)
{
return TRUE;
}

UINT __stdcall GetContributePath(MSIHANDLE hInstall)
{
return ERROR_SUCCESS;
}

I link it with Msi.lib only.
I have replaced the DLL in the IS project with the new empty one (had to modify .ism file manually to replace the DLL in the Binary table, since my changes could not be saved correctly from the IS UI).

Result: the issue persists. The same missing .tmp file error.

My custom action is a "Standard Library DLL stored in the Binary table" action (code 131136). As I can see in the Binary table it gets called via DLLWRAP.DLL. There is corresponding entry for that DLL in the binary table. The file is also correctly referenced from the Binary table and is available in the IS distribution.

Can the reason be in the wrong DLLWRAP.dll version?

It looks at the moment as if the problem is a corrupt IS project file. It seems like I need to recreate the project from scratch. Though it is pretty much of work, this is the next thing I am going to try.
0 Kudos
joshstechnij
Level 10 Flexeran
Level 10 Flexeran

Can you try using an MSI DLL custom action (stored in Binary table) with this empty DLL you are using? This should be able to help isolate the behavior further to determine if DllWrap.dll is an issue.
0 Kudos
Rothmansua
Level 3

I have tried the MSI Dll custom action.
The popup about missing .tmp file does not appear any more neither for initial MFC CA DLL nor for the test empty DLL.
Unfortunately, even after switch to MSI DLL custom action type neither MFC version nor simple empty version doesn't get called on some PCs (same log as above).
0 Kudos
Rothmansua
Level 3

At last I could start my custom action!

The reason was obviously in the /MD "Runtime Library = Multi-Threaded DLL" switch of the DLL VS project.

After switch to the /MT "Runtime Library = Multi-Threaded" I could start all my custom actions including MFC DLL one.

So Josh was right from the very beginning. The missing dependency (C Runtime in this case I assume) was the problem.

Thanks for the help!
0 Kudos