Chef Infra Client 16.7.61 Install Error in WS2019

Chef Infra (archive)
1

Hi - I am getting a weird error when installing Chef Infra Client version 16.7.61 in some of our new WS 2019 servers. Essentially there is an error in the customactionscript that forces the MSI Install to rollback

Starting 7zip extraction using arguments: x C:\opscode\chef.zip -aoa -o"C:\opscode\chef"
Exception thrown by custom action:
System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.ComponentModel.Win32Exception: The system cannot find the file specified
at System.Diagnostics.Process.StartWithCreateProcess(ProcessStartInfo startInfo)
at System.Diagnostics.Process.Start()
at CustomActionFastMsi.CustomActions.FastUnzip(Session session)
--- End of inner exception stack trace ---
at System.RuntimeMethodHandle.InvokeMethod(Object target, Object arguments, Signature sig, Boolean constructor)
at System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object parameters, Object arguments)
at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object parameters, CultureInfo culture)
at Microsoft.Deployment.WindowsInstaller.CustomActionProxy.InvokeCustomAction(Int32 sessionHandle, String entryPoint, IntPtr remotingDelegatePtr)
CustomAction FastUnzip returned actual error code 1603 (note this may not be 100% accurate if translation happened inside sandbox)
Action ended 14:38:05: InstallFinalize. Return value 3.

Any help will be greatly appreciated. TIA

PS: This is only happening on a handful of servers and not to the whole fleet of servers we manage with Chef.

2

That's odd. When it happens, is the zip file actually missing from the opscode directory on the affected servers?

3

I see it get extracted by the MSI but still fails and then rolls back some reason. Here's the part of the log where I think the chef.zip gets created:

MSI (s) (2C:94) [13:21:28:461]: Executing op: ActionStart(Name=InstallFiles,Description=Copying new files,Template=File: [1], Directory: [9], Size: [6])
Action 13:21:28: InstallFiles. Copying new files
MSI (s) (2C:94) [13:21:28:461]: Executing op: ProgressTotal(Total=306601448,Type=0,ByteEquivalent=1)
MSI (s) (2C:94) [13:21:28:461]: Executing op: SetTargetFolder(Folder=C:\Users\allanbdevprd\Desktop\opscode)
MSI (s) (2C:94) [13:21:28:461]: Executing op: SetSourceFolder(Folder=1\opscode)
MSI (s) (2C:94) [13:21:28:461]: Executing op: ChangeMedia(,MediaPrompt=Please insert the disk: ,MediaCabinet=ChefClient.cab,BytesPerTick=65536,CopierType=2,ModuleFileName=C:\Windows\Installer\32b7bcfb.msi,,,,,IsFirstPhysicalMedia=1)
MSI (s) (2C:94) [13:21:28:461]: Executing op: FileCopy(SourceName=chef.zip,SourceCabKey=filA11494F21FE6160B8815989A459B35D7,DestName=chef.zip,Attributes=512,FileSize=306601448,PerTick=65536,,VerifyMedia=1,,,,,CheckCRC=0,,,InstallMode=58982400,HashOptions=0,HashPart1=565381109,HashPart2=1665347351,HashPart3=598999709,HashPart4=416442892,,)
MSI (s) (2C:94) [13:21:28:461]: File: C:\Users\allanbdevprd\Desktop\opscode\chef.zip; To be installed; Won't patch; No existing file
MSI (s) (2C:94) [13:21:28:461]: Source for file 'filA11494F21FE6160B8815989A459B35D7' is compressed
InstallFiles: File: chef.zip, Directory: C:\Users\allanbdevprd\Desktop\opscode, Size: 306601448

4

Hmm. That error would occur if the custom install action could not find 7z.exe. However, the MSI bundles 7z.exe along with the custom install DLL and in the same directory. So it is very strange that it can't find the file. Is the error reproducible on the same machine or will it succeed on a second attempt?

If it is reproducible, it would be interesting to run Procmon.exe with a filter to include a Path that ends with 7z.exe. Then run the MSI. Given your error, I'd expect a bunch of entries to show up saying something like PATH NOT FOUND. But it would tell us where it is looking for it.

5

Thank you for the suggestion on next step. The installation of 16.7.61 never completes in the affected servers and I ran procmon and filtered the Path for 7z.exe and this is the only entry with the PATH NOT FOUND result:

image
image1878×34 7.52 KB

6

It may be helpful to see the other 7z.exe entries in the log. Can you think of anything unique to the servers where it is failing? Perhaps any antivirus that might be blocking the installer from extracting 7z?

7

Hi @Matt_Wrock - We did try disabling our Antivirus while doing the install but still failing. Quick question though, we are not getting this error in this server when we install version 15.8.23. Does that mean that 7z.exe was not the tool for the unzip for that version?

8

correct. adding 7zip to the installation is fairly new. were there any/many other 7z.exe entries in the procmon log?

9

Hi @Matt_Wrock - Yeah here's all the non-SUCCESS results for Paths that contain 7z.exe:
"9:23:35.1481031 AM","rundll32.exe","4128","CreateFile","C:\Windows\assembly\GAC_MSIL\Microsoft.Deployment.WindowsInstaller\3.0.0.0__ce35f76fcda82bad\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2014530 AM","rundll32.exe","4128","CreateFile","C:\Windows\SysWOW64\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2018040 AM","rundll32.exe","4128","CreateFile","C:\Windows\assembly\GAC_MSIL\Microsoft.Deployment.WindowsInstaller\3.0.0.0__ce35f76fcda82bad\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2021111 AM","rundll32.exe","4128","CreateFile","C:\Windows\SysWOW64\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2030607 AM","rundll32.exe","4128","CreateFile","C:\Windows\System\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2236703 AM","rundll32.exe","4128","CreateFile","C:\Windows\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2239755 AM","rundll32.exe","4128","CreateFile","C:\Windows\SysWOW64\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2242643 AM","rundll32.exe","4128","CreateFile","C:\Windows\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2245567 AM","rundll32.exe","4128","CreateFile","C:\Windows\SysWOW64\wbem\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2257795 AM","rundll32.exe","4128","CreateFile","C:\Windows\SysWOW64\WindowsPowerShell\v1.0\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2259564 AM","rundll32.exe","4128","CreateFile","C:\Windows\SysWOW64\OpenSSH\7z.exe","PATH NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2262866 AM","rundll32.exe","4128","CreateFile","C:\Program Files\Microsoft SQL Server\110\Tools\Binn\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2266640 AM","rundll32.exe","4128","CreateFile","C:\Program Files\Amazon\AWSCLI\7z.exe","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"9:23:35.2268216 AM","rundll32.exe","4128","CreateFile","C:\Users\allanbdevprd\Desktop\opscode\chef\bin\7z.exe","PATH NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"

10

interesting. Those entries are likely just windows searching for it in the PATH. One thing you should see in your install log just before it mentions that it is extracting the file with 7zip is something like:

SFXCA: Extracting custom action to temporary directory: C:\WINDOWS\Installer\MSI4E36.tmp-\

Unfortunately after the install, that directory gets deleted but that is where the 7z.exe would exist along with the custom action dll. Do you see anything in the procmon log succesfully (or otherwise) creating a 7z.exe in a temp folder uncer c:\windows\installer\ ?

11

Hi @Matt_Wrock - I do see both the extraction step in the MSI logs and I do see in procmon that the 7z.exe get created but somehow Windows is not searching for 7z.exe there. We have engaged with MS Support on this issue but they are unable to replicate nor help pinpoint the rootcause.

I did not try something given how we kind of pinpointed that 7z.exe needs to run the extraction as part of the custom action script:

  • Installed 7z
  • Added Install directory of 7z to PATH Environment variable
  • Retried installation which completed successfully.

Though it worked it is still a mystery why these servers are blind to the Installer directory that the MSI creates.

12

Hi, I am having the same issue upgrading to 16.10.8. I experienced the issue on about 50/1300 hosts. I'm yet to try the workaround.

13

Good luck and let me know if the workaround worked for you. This is the 7z version that I downloaded and installed in my affected nodes: https://www.7-zip.org/a/7z1900-x64.exe

14

I just opened Unable to locate 7z.exe · Issue #12 · chef/fastmsi-custom-action · GitHub to use an absolute path when calling 7z.exe. That may or may not be the fix but it is not it tells us something is either preventing 7z from being extracted from the MSI or there is perhaps some timing issue where the custom action calls it before it is fully extracted.

1 Like
15

@Matt_Wrock Thanks for your help on this. (p.s. I tried the previously mentioned workaround on a few hosts and it worked as expected)

1 Like
16

@Matt_Wrock I tried Chef Infra Client 16.10.17 on a server with the issue today and it has resolved the issue. Thank you.

2 Likes