chocolatey / home

The place to start for issues with areas of Chocolatey that are infrastructure related, or really any issues could be started here. There is also choco for the CLI client, Chocolatey GUI for the GUI.
Apache License 2.0
29 stars 10 forks source link

Virtual packages unable to resolve dependency (specifically .install dependencies) #308

Closed AjkayAlan closed 8 months ago

AjkayAlan commented 8 months ago

Checklist

What You Are Seeing?

When attempting to install virtual packages, I am having issues with some resolving correctly, and can't explain why, as they worked last week (potentially related to #306?).

Three examples I have seen this behavior is:

In all cases, if I use the virtual package, it fails with an Unable to resolve dependency error. However, if I directly reference the .install package via a choco install, it works without issue.

What is Expected?

Virtual packages should correctly pull their dependencies.

How Did You Get This To Happen?

  1. Install chocolatey v1 (in my case, Choco 1.4) by setting $env:chocolateyVersion = 1.4.0 then running the installer: Set-ExecutionPolicy Bypass -Scope Process -Force; [System.Net.ServicePointManager]::SecurityProtocol = [System.Net.ServicePointManager]::SecurityProtocol -bor 3072; iex ((New-Object System.Net.WebClient).DownloadString("https://community.chocolatey.org/install.ps1"))
  2. Verify that the specific package isn't already installed via choco list --local-only
  3. Attempt to install a failing package. E.g. choco install winscp --version 6.3.2 --verbose --debug or choco install git --version 2.44.0 --verbose --debug

System Details

Installed Packages

7zip.install 23.1.0
awscli 2.15.24
beyondcompare 4.4.7.20240301
chocolatey 1.4.0
chocolatey-compatibility.extension 1.0.0
chocolatey-core.extension 1.4.0
chocolatey-windowsupdate.extension 1.0.5
corretto11jdk 11.0.22.71
corretto17jdk 17.0.10.71
corretto8jdk 8.402.8.1
curl 8.6.0
dbeaver 23.2.4
github-desktop 3.3.9
intellijidea-ultimate 2023.3.4
KB2919355 1.0.20160915
KB2919442 1.0.20160915
KB2999226 1.0.20181019
KB3033929 1.0.5
KB3035131 1.0.3
maven 3.9.6
microsoft-windows-terminal 1.19.10573
notepadplusplus 8.6.4
notepadplusplus.install 8.6.4
nvm.install 1.1.10
podman-cli 4.9.3
podman-desktop 1.7.1
postman 10.17.3
putty 0.80.0
putty.install 0.79.0
putty.portable 0.80.0
python 3.12.2
python3 3.12.2
python312 3.12.2
ruby 3.2.3.1
ruby.install 3.2.3.1
terraform 1.7.3
tortoisegit 2.15.0
vcredist140 14.36.32532
vcredist2015 14.0.24215.20170201
vscode 1.87.0
vscode.install 1.87.0

### Output Log

```bash
When attempting to install `WinSCP`:

PS C:\windows\system32> choco install winscp --version 6.3.2 --verbose --debug
Chocolatey v1.4.0
Chocolatey is running on Windows v 10.0.19045.0
Attempting to delete file "C:/ProgramData/chocolatey/choco.exe.old".
Attempting to delete file "C:\ProgramData\chocolatey\choco.exe.old".
Command line: "C:\ProgramData\chocolatey\choco.exe" install winscp --version 6.3.2 --verbose --debug
Received arguments: install winscp --version 6.3.2 --verbose --debug
RemovePendingPackagesTask is now ready and waiting for PreRunMessage.
Sending message 'PreRunMessage' out if there are subscribers...
[Pending] Removing all pending packages that should not be considered installed...
Performing validation checks.
Global Configuration Validation Checks:
 - Package Exit Code / Exit On Reboot = Checked
System State Validation Checks:
 Reboot Requirement Checks:
 - Pending Computer Rename = Checked
 - Pending Component Based Servicing = Checked
 - Pending Windows Auto Update = Checked
 - Pending File Rename Operations = Ignored
 - Pending Windows Package Installer = Checked
 - Pending Windows Package Installer SysWow64 = Checked
The source 'https://community.chocolatey.org/api/v2/' evaluated to a 'normal' source type

NOTE: Hiding sensitive configuration data! Please double and triple
 check to be sure no sensitive data is shown, especially if copying
 output to a gist for review.
Configuration: CommandName='install'|
CacheLocation='C:\Users\OBFUSCATED\AppData\Local\Temp\chocolatey'|
ContainsLegacyPackageInstalls='True'|
CommandExecutionTimeoutSeconds='2700'|WebRequestTimeoutSeconds='30'|
Sources='https://community.chocolatey.org/api/v2/'|SourceType='normal'|
Debug='True'|Verbose='True'|Trace='False'|Force='False'|Noop='False'|
HelpRequested='False'|UnsuccessfulParsing='False'|RegularOutput='True'|
QuietOutput='False'|PromptForConfirmation='True'|
DisableCompatibilityChecks='False'|AcceptLicense='False'|
AllowUnofficialBuild='False'|Input='winscp'|Version='6.3.2'|
AllVersions='False'|SkipPackageInstallProvider='False'|
SkipHookScripts='False'|PackageNames='winscp'|Prerelease='False'|
ForceX86='False'|OverrideArguments='False'|NotSilent='False'|
ApplyPackageParametersToDependencies='False'|
ApplyInstallArgumentsToDependencies='False'|IgnoreDependencies='False'|
AllowMultipleVersions='False'|AllowDowngrade='False'|
ForceDependencies='False'|PinPackage='False'|
Information.PlatformType='Windows'|
Information.PlatformVersion='10.0.19045.0'|
Information.PlatformName='Windows 10'|
Information.ChocolateyVersion='1.4.0.0'|
Information.ChocolateyProductVersion='1.4.0'|
Information.FullName='choco, Version=1.4.0.0, Culture=neutral, PublicKeyToken=79d02ea9cad655eb'|

Information.Is64BitOperatingSystem='True'|
Information.Is64BitProcess='True'|Information.IsInteractive='True'|
Information.UserName='OBFUSCATED'|
Information.UserDomainName='OBFUSCATED'|
Information.IsUserAdministrator='True'|
Information.IsUserSystemAccount='False'|
Information.IsUserRemoteDesktop='False'|
Information.IsUserRemote='True'|
Information.IsProcessElevated='True'|
Information.IsLicensedVersion='False'|Information.LicenseType='Foss'|
Information.CurrentDirectory='C:\windows\system32'|
Features.AutoUninstaller='True'|Features.ChecksumFiles='True'|
Features.AllowEmptyChecksums='False'|
Features.AllowEmptyChecksumsSecure='True'|
Features.FailOnAutoUninstaller='False'|
Features.FailOnStandardError='False'|Features.UsePowerShellHost='True'|
Features.LogEnvironmentValues='False'|Features.LogWithoutColor='False'|
Features.VirusCheck='False'|
Features.FailOnInvalidOrMissingLicense='False'|
Features.IgnoreInvalidOptionsSwitches='True'|
Features.UsePackageExitCodes='True'|
Features.UseEnhancedExitCodes='False'|
Features.UseFipsCompliantChecksums='False'|
Features.ShowNonElevatedWarnings='True'|
Features.ShowDownloadProgress='True'|
Features.StopOnFirstPackageFailure='False'|
Features.UseRememberedArgumentsForUpgrades='False'|
Features.IgnoreUnfoundPackagesOnUpgradeOutdated='False'|
Features.SkipPackageUpgradesWhenNotInstalled='False'|
Features.RemovePackageInformationOnUninstall='False'|
Features.ExitOnRebootDetected='False'|
Features.LogValidationResultsOnWarnings='True'|
Features.UsePackageRepositoryOptimizations='True'|
ListCommand.LocalOnly='False'|ListCommand.IdOnly='False'|
ListCommand.IncludeRegistryPrograms='False'|ListCommand.PageSize='25'|
ListCommand.Exact='False'|ListCommand.ByIdOnly='False'|
ListCommand.ByTagOnly='False'|ListCommand.IdStartsWith='False'|
ListCommand.OrderByPopularity='False'|ListCommand.ApprovedOnly='False'|
ListCommand.DownloadCacheAvailable='False'|
ListCommand.NotBroken='False'|
ListCommand.IncludeVersionOverrides='False'|
UpgradeCommand.FailOnUnfound='False'|
UpgradeCommand.FailOnNotInstalled='False'|
UpgradeCommand.NotifyOnlyAvailableUpgrades='False'|
UpgradeCommand.ExcludePrerelease='False'|
NewCommand.AutomaticPackage='False'|
NewCommand.UseOriginalTemplate='False'|SourceCommand.Command='unknown'|
SourceCommand.Priority='0'|SourceCommand.BypassProxy='False'|
SourceCommand.AllowSelfService='False'|
SourceCommand.VisibleToAdminsOnly='False'|
FeatureCommand.Command='unknown'|ConfigCommand.Command='unknown'|
ApiKeyCommand.Remove='False'|PinCommand.Command='unknown'|
OutdatedCommand.IgnorePinned='False'|
ExportCommand.IncludeVersionNumbers='False'|Proxy.BypassOnLocal='True'|
TemplateCommand.Command='unknown'|
_ Chocolatey:ChocolateyInstallCommand - Normal Run Mode _
Installing the following packages:
winscp
By installing, you accept licenses for the packages.
[NuGet] Attempting to resolve dependency 'winscp.install (= 6.3.2)'.
winscp not installed. An error occurred during installation:
 Unable to resolve dependency 'winscp.install (= 6.3.2)'.
winscp package files install failed with exit code 1. Performing other installation steps.
No package information as package is null.
No package information to save as package is null.
Sending message 'HandlePackageResultCompletedMessage' out if there are subscribers...
The install of winscp was NOT successful.
winscp not installed. An error occurred during installation:
 Unable to resolve dependency 'winscp.install (= 6.3.2)'.

Chocolatey installed 0/1 packages. 1 packages failed.
 See the log for details (C:\ProgramData\chocolatey\logs\chocolatey.log).

Failures
 - winscp (exited 1) - winscp not installed. An error occurred during installation:
 Unable to resolve dependency 'winscp.install (= 6.3.2)'.
Sending message 'PostRunMessage' out if there are subscribers...
Exiting with 1

Additional Context

This was not an issue last week. Our internal telemetry shows the last successful request on 2024-03-21 at 9AM CDT, and the first failing attempt on 2024-03-25 at 4:50AM CDT. I see 5 unique users today that have encountered this issue, and all failures encountered in our automation today were due to this issue.

┆Issue is synchronized with this Gitlab issue by Unito

gep13 commented 8 months ago

@AjkayAlan sorry to hear that you are having issues.

In order to best understand what is going on here, we are going to need to understand what requests/responses are being made between Chocolatey CLI and the Chocolatey Community Repository?

Are you familiar with a tool called Fiddler? Using this tool would help us capture the requests/responses, to then allow us to debug further into what is going on.

A while back, I created a short video on Fiddler, and how it can be used for this type of debugging.

https://youtu.be/z4CwJ-MF7ik?si=HmU8g781D70eeOPr

If you can, can you capture all the requests/responses for Chocolatey CLI, when running one of the commands that you are attempting?

AjkayAlan commented 8 months ago

No worries @gep13! I have gone ahead and gotten a capture with Fiddler for you. I did so using my personal computer (Windows 11 instead of Windows 10), and it has nothing installed via choco, so its more of a clean machine. Here is a gif so you can see what I am seeing - along with so you can take a peek if the Fiddler capture looks good.

ChocoInstallFail

If everything looks like I captured things correctly, i'd be happy to send you (or others on your team) the saved Fiddler session. I've added you to a private repo at https://github.com/AjkayAlan/choco-home-issue-308 which has a link to the file in OneDrive on the readme.

gep13 commented 8 months ago

@AjkayAlan thank you for the Fiddler export, this has been very useful!

We have been able to reproduce the problem, and will be working on a fix. I will ping you here once that is released, and I would ask if you could confirm it is working for you.

AjkayAlan commented 8 months ago

I see this is marked as completed by the sync bot - but wanted to note that I still am seeing the same issue.

I am going to assume the actual work is done, but there still needs to be an infrastructure rollout before the fix is actually active.

AdmiringWorm commented 8 months ago

@AjkayAlan the necessary code has been implemented, and it gets automatically closed at that point.

It hasn't yet been released to production. We'll leave a comment here once it has been released.

EDIT: So yes, your assumption is correct.

gep13 commented 8 months ago

@AjkayAlan we use the 5 - Released label to indicate that this has made its way out to Production.

gep13 commented 8 months ago

@AjkayAlan the modifications have now been deployed.

Can you please re-test, and let us know if you are still running into problems? Thanks

AjkayAlan commented 8 months ago

@gep13 Good news and bad news.

Good news first - the fix seems to have corrected some packages. Notably, git --version 2.44.0 and python --version 3.12.2 are now looking good and work as expected.

Bad news - some other packages still aren't working. I tested choco install winscp --version 6.3.2 on both my work device and personal device and am still getting Unable to resolve dependency 'winscp.install (=6.3.2)'. Another package that came up with issues with internal users (and I have also repeated on my end) is choco install notepadplusplus --version 8.6.4.

Here is a gif showing what git did (which worked), and what winscp did (which failed). The gif is slightly edited to reduce excess wait times.

ChocoInstallFail_WinSCP_20240326

I have also added a new fiddler capture in https://github.com/AjkayAlan/choco-home-issue-308 in the readme in case it helps, and also added AdmiringWorm as a collaborator to the repo.

gep13 commented 8 months ago

@AjkayAlan this is not unexpected 😄

We are now into the realm of caching causing problems with the responses that you are getting back.

If you can provide a complete list of packages that aren't working for you, we should be able to get those taken care of, or the cached results should eventually expire, to be replaced with the correct result from the API.

Apologies again for the inconvenience here!

gep13 commented 8 months ago

@AjkayAlan if you try the notepadplusplus and winscp packages again, they should hopefully work for you now.

If there are any others, post them here, and I will try to get to them when I can, otherwise, as I mentioned, the cache should expire naturally as well.

AjkayAlan commented 8 months ago

notepadplusplus and winscp are confirmed working now 🥳 - glad to know its just a caching thing at this point!

I have not been able to find any other packages that are still cached bad. Notably, I have tried a few other virtual packages with child .install packages which must have recached, including:

Everything is looking good and I can confirm the root cause is resolved. Thank you again for the help and continued work towards keeping Chocolatey awesome 🥇 !

gep13 commented 8 months ago

@AjkayAlan woo hoo!

Thank you for confirming, much appreciated! I am very glad to hear that things are working now! I will be able to sleep a little bit easier tonight! 😄