7z.exe error causes Chocolatey CLI to throw wrong message

[steviecoaster]

What You Are Seeing?

When exracting a large 7z file on a system fails, 7zip throws an error code that is interpreted by Chocolatey as a timeout, however there is no configurable timeout for this action in either Chocolatey's config, or on the 7z.exe binary itself, so a more generic message should be thrown.

What is Expected?

A more descriptive message that 7zip encountered an issue, and that it is not a timeout issue

How Did You Get This To Happen? (Steps to Reproduce)

1. Use a slow-performing machine
2. Attempt to install a large (>1GB 7z file) using `Install-ChocolateyZipPackage)
3. Observe error

Output Log

Chocolatey timed out waiting for the command to finish. The timeout
 specified (or the default value) was '300' seconds.
2022-04-19 18:12:44,911 6992 [DEBUG] - Command ['"C:\ProgramData\chocolatey\tools\7z.exe" x -aoa -bd -bb1 -o"C:\JS-Software\Software" -y "C:\Users\lherzog\AppData\Local\Temp\chocolatey\avid-media-composer\2021.12.1\MediaComposer_2021.12.7z"'] exited with '258'
2022-04-19 18:12:44,913 6992 [DEBUG] - Command ['C:\ProgramData\chocolatey\tools\7z.exe' x -aoa -bd -bb1 -o"C:\JS-Software\Software" -y "C:\Users\lherzog\AppData\Local\Temp\chocolatey\avid-media-composer\2021.12.1\MediaComposer_2021.12.7z"] exited with '258'.

<snip>

2022-04-19 18:12:53,066 6992 [ERROR] - ERROR: 7-Zip signalled an unknown error (code 258). This is most likely an issue
 with the 'avid-media-composer' package and not with Chocolatey itself. Please follow
 up with the package maintainer(s) directly.
2022-04-19 18:12:55,447 6992 [DEBUG] - Built-in PowerShell host called with ['[System.Threading.Thread]::CurrentThread.CurrentCulture = '';[System.Threading.Thread]::CurrentThread.CurrentUICulture = ''; & import-module -name 'C:\ProgramData\chocolatey\helpers\chocolateyInstaller.psm1'; & 'C:\ProgramData\chocolatey\helpers\chocolateyScriptRunner.ps1' -packageScript 'C:\ProgramData\chocolatey\lib\avid-media-composer\tools\chocolateyinstall.ps1' -installArguments '' -packageParameters '''] exited with '258'.

┆Issue is synchronized with this Gitlab issue by Unito ┆Milestone: 4.2.0

[corbob]

Without diving into the code: I believe Chocolatey timed out waiting for the command to finish. The timeout specified (or the default value) was '300' seconds. comes from the Command Executor (Licensed Extension has a similar message when command executor runs something that goes beyond the given time limit). I would guess that this is either hard coded somewhere with a magic number, or perhaps with a constant.

If this isn't configurable, I imagine it should be. If it is configurable I'm not too sure what can be done... Although at the very least we could document that 258 is a timeout: https://docs.microsoft.com/en-us/windows/win32/debug/system-error-codes--0-499- 🤷

[herzogmedia]

That were my initial thoughts too, when raising this issue. We tried overriding the value with --timeout but it showed no effect.

[corbob]

So I'm not able to reproduce getting a 258 exit code from Chocolatey CLI. When I follow the code through, there is no wait period, so it will wait for 7z.exe to complete regardless of how long it takes (there may be a timeout on the PowerShell runner, but that's harder to debug). If I kill the process before it finishes, then I get -1 as the exit code (I'm not entirely sure what the difference is in what I'm doing in PowerShell versus what CommandExecutor does, since they seem to be doing very similar 🤷 ).

That being said, the Get-ChocolateyUnzip (which is the cmdlet called by Install-ChocolateyZipPackage) in the licensed extension is a completely different code path, and definitely does have a hard coded timeout of 5 minutes.

[herzogmedia]

That being said, the Get-ChocolateyUnzip (which is the cmdlet called by Install-ChocolateyZipPackage) in the licensed extension is a completely different code path, and definitely does have a hard coded timeout of 5 minutes.

We only tried it with licensed edition anyways. If you wish, I can try if the problem is still present in community edition next week

[corbob]

We only tried it with licensed edition anyways. If you wish, I can try if the problem is still present in community edition next week

If you wouldn't mind giving that a try, it'd help us identify specifically where the issue lies so we can get it resolved.

[herzogmedia]

@corbob I can now confirm that the issue only occures in the licensed edition. In foss-edition the package just takes as long as it takes to unzip.

[nascentt]

I see this has been closed but don't see a linked commit. Do this timeout no longer occur for chocolatey licensed or was something else done to fix it?

[corbob]

@nascentt yes, the work to fix this bug has been completed, but has not been released. It's slated for the 4.2.0 release of Chocolatey Extension.