microsoft / winget-cli

WinGet is the Windows Package Manager. This project includes a CLI (Command Line Interface), PowerShell modules, and a COM (Component Object Model) API (Application Programming Interface).
https://learn.microsoft.com/windows/package-manager/
MIT License
23.13k stars 1.44k forks source link

Random assertion failure on `winget upgrade` #3771

Open sba923 opened 1 year ago

sba923 commented 1 year ago

Brief description of your issue

I randomly (and, alas, non-reproducibly) get the following error after winget upgrade has (apparently) correctly applied an update:

[6/6] Upgrading 'VLC media player' (Id='VideoLAN.VLC') from version '3.0.18' to version '3.0.19' via 'winget upgrade --id VideoLAN.VLC --version 3.0.19'
Found VLC media player [VideoLAN.VLC] Version 3.0.19
This application is licensed to you by its owner.
Microsoft is not responsible for, nor does it grant any licenses to, third-party packages.
Downloading https://download.videolan.org/videolan/vlc/3.0.19/win64/vlc-3.0.19-win64.msi
  ██████████████████████████████  56.2 MB / 56.2 MB
Successfully verified installer hash
Starting package install...
An unexpected error occurred while executing the command:
0x8007029c : An assertion failure has occurred.
winget exit code: 0x8007029c

Steps to reproduce

This occurs upon execution of winget upgrade but there's no actual repro scenario.

Expected behavior

winget upgrade should not display an assertion message, and exit with exit code 0.

Actual behavior

An unexpected error occurred while executing the command:
0x8007029c : An assertion failure has occurred.

Environment

Windows Package Manager v1.6.2771
Copyright (c) Microsoft Corporation. All rights reserved.

Windows: Windows.Desktop v10.0.19045.3570
System Architecture: X64
Package: Microsoft.DesktopAppInstaller v1.21.2771.0

Winget Directories
-------------------------------------------------------------------------------------------------------------------------------
Logs                               %LOCALAPPDATA%\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir
User Settings                      %LOCALAPPDATA%\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\settings.json
Portable Links Directory (User)    %LOCALAPPDATA%\Microsoft\WinGet\Links
Portable Links Directory (Machine) C:\Program Files\WinGet\Links
Portable Package Root (User)       %LOCALAPPDATA%\Microsoft\WinGet\Packages
Portable Package Root              C:\Program Files\WinGet\Packages
Portable Package Root (x86)        C:\Program Files (x86)\WinGet\Packages
Installer Downloads                %USERPROFILE%\Downloads

Links
---------------------------------------------------------------------------
Privacy Statement   https://aka.ms/winget-privacy
License Agreement   https://aka.ms/winget-license
Third Party Notices https://aka.ms/winget-3rdPartyNotice
Homepage            https://aka.ms/winget
Windows Store Terms https://www.microsoft.com/en-us/storedocs/terms-of-sale

Admin Setting                             State
--------------------------------------------------
LocalManifestFiles                        Disabled
BypassCertificatePinningForMicrosoftStore Disabled
InstallerHashOverride                     Disabled
LocalArchiveMalwareScanOverride           Disabled
denelon commented 1 year ago

Is there any chance you can share the log from this execution run?

You can either find the log directory with winget --info or you can run winget --logs to open the log directory.

sba923 commented 1 year ago

Sure, here you go: WinGet-VideoLAN.VLC.3.0.19-2023-10-16.zip

With this nice part:

2023-10-16 09:48:29.314 [CLI ] Installer args: /passive /norestart /log "C:\Users\<REDACTED>\AppData\Local\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir\WinGet-VideoLAN.VLC.3.0.19-2023-10-16-09-48-29.314.log"
2023-10-16 09:48:29.315 [CLI ] Starting: 'C:\Users\<REDACTED>\AppData\Local\Temp\WinGet\VideoLAN.VLC.3.0.19\vlc-3.0.19-win64.msi' with arguments '/passive /norestart /log "C:\Users\<REDACTED>\AppData\Local\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir\WinGet-VideoLAN.VLC.3.0.19-2023-10-16-09-48-29.314.log"'
2023-10-16 09:49:37.818 [FAIL] D:\a\_work\1\s\external\pkg\src\AppInstallerCLICore\Workflows\ShellExecuteInstallerHandler.cpp(39)\WindowsPackageManager.dll!00007FFFD0C46B1B: (caller: 00007FFFD0C47DC0) LogHr(1) tid(b20) 8007029C An assertion failure has occurred.

2023-10-16 09:49:37.818 [FAIL] D:\a\_work\1\s\external\pkg\src\AppInstallerCLICore\Workflows\ShellExecuteInstallerHandler.cpp(39)\WindowsPackageManager.dll!00007FFFD0C46B1B: (caller: 00007FFFD0C47DC0) Exception(1) tid(b20) 8007029C An assertion failure has occurred.

2023-10-16 09:49:37.913 [CLI ] Caught wil::ResultException: D:\a\_work\1\s\external\pkg\src\AppInstallerCLICore\Workflows\ShellExecuteInstallerHandler.cpp(39)\WindowsPackageManager.dll!00007FFFD0C46B1B: (caller: 00007FFFD0C47DC0) Exception(1) tid(b20) 8007029C An assertion failure has occurred.
JohnMcPMS commented 1 year ago

This looks to be an error in our handling of the call to ShellExecute and expecting a process handle back. Given the timing in the logs, it looks like SE didn't actually return until the MSI has finished installing. This makes it impossible to "cancel" (stop waiting), but is also likely why no process was returned (it ran in process inside the SE call). We currently rely on the process handle to track the completion and success/failure of the installer, but given this behavior, it would appear that there are some cases where we won't get that.

At this point, I would probably fix this by dropping SE completely (for MSI/EXE). We have code for directly calling MSI APIs, and we can replace SE with an explicit CreateProcess call for exes.

sba923 commented 1 year ago

Thanks for sharing.

My personal experience is that ShellExecute is a very fragile mechanism to rely on for programmatic, non-interactive stuff.

ydroneaud commented 9 months ago

I'm experiencing it too with winget install PuTTY.PuTTY.

> winget install --verbose --verbose-logs PuTTY.PuTTY
Trouvé PuTTY [PuTTY.PuTTY] Version 0.80.0.0
La licence d’utilisation de cette application vous est octroyée par son propriétaire.
Microsoft n’est pas responsable des paquets tiers et n’accorde pas de licences à ceux-ci.
Le code de hachage de l’installation a été vérifié avec succès
Démarrage du package d’installation... Merci de patienter.
Une erreur inattendue s'est produite lors de l'exécution de la commande :
0x8007029c : Un chec dassertion sest produit.

Logs contains:

...
2024-01-02 15:10:39.518 [CLI ] Installer args: /passive /norestart /log "C:\Users\XXXXX\AppData\Local\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir\WinGet-PuTTY.PuTTY.0.80.0.0-2024-01-02-15-10-39.518.log"
2024-01-02 15:10:39.519 [CLI ] Starting: 'C:\Users\XXXXX\AppData\Local\Temp\WinGet\PuTTY.PuTTY.0.80.0.0\putty-64bit-0.80-installer.msi' with arguments '/passive /norestart /log "C:\Users\XXXXX\AppData\Local\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir\WinGet-PuTTY.PuTTY.0.80.0.0-2024-01-02-15-10-39.518.log"'
2024-01-02 15:11:12.201 [FAIL] C:\__w\1\s\external\pkg\src\AppInstallerCLICore\Workflows\ShellExecuteInstallerHandler.cpp(39)\WindowsPackageManager.dll!00007FFB494C5D2B: (caller: 00007FFB494C6FC0) LogHr(1) tid(5620) 8007029C Un échec d’assertion s’est produit.

2024-01-02 15:11:12.201 [FAIL] C:\__w\1\s\external\pkg\src\AppInstallerCLICore\Workflows\ShellExecuteInstallerHandler.cpp(39)\WindowsPackageManager.dll!00007FFB494C5D2B: (caller: 00007FFB494C6FC0) Exception(18) tid(5620) 8007029C Un échec d’assertion s’est produit.

2024-01-02 15:11:12.234 [CLI ] Caught wil::ResultException: 

PuTTY MSI installer was successful, according to this other log:

...
MSI (s) (74:30) [15:11:10:191]: Product: PuTTY release 0.80 (64-bit) -- Installation completed successfully.

MSI (s) (74:30) [15:11:10:191]: Windows Installer a installé le produit. Nom du produit : PuTTY release 0.80 (64-bit). Version du produit : 0.80.0.0. Langue du produit : 1033. Fabricant : Simon Tatham. Réussite de l’installation ou état d’erreur : 0.

=== Logging stopped: 02/01/2024  15:11:10 ===

winget --info:

> winget --info
Gestionnaire de package Windows v1.6.3482
Copyright (c) Microsoft Corporation. Tous droits réservés.

Windows: Windows.Desktop v10.0.19045.3803
Architecture du système : X64
Package : Microsoft.DesktopAppInstaller v1.21.3482.0

Répertoires Winget
-----------------------------------------------------------------------------------------------------------------------------------------
Journaux                                     %LOCALAPPDATA%\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir
Paramètres utilisateurs                      %LOCALAPPDATA%\Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\settings.json
Répertoire des liens portables (utilisateur) %LOCALAPPDATA%\Microsoft\WinGet\Links
Répertoire des liens portables (ordinateur)  C:\Program Files\WinGet\Links
Racine de package portable (utilisateur)     %LOCALAPPDATA%\Microsoft\WinGet\Packages
Racine du package portable                   C:\Program Files\WinGet\Packages
Racine de package portable (x86)             C:\Program Files (x86)\WinGet\Packages
Téléchargements du programme d’installation  %USERPROFILE%\Downloads

Liens
---------------------------------------------------------------------------------------------
Déclaration de confidentialité        https://aka.ms/winget-privacy
Contrat de licence                    https://aka.ms/winget-license
Avis de tiers                         https://aka.ms/winget-3rdPartyNotice
Page d’accueil                        https://aka.ms/winget
Conditions générales du Windows Store https://www.microsoft.com/en-us/storedocs/terms-of-sale

Paramètre administrateur                  État
---------------------------------------------------
LocalManifestFiles                        Désactivé
BypassCertificatePinningForMicrosoftStore Désactivé
InstallerHashOverride                     Désactivé
LocalArchiveMalwareScanOverride           Désactivé

Pardon my french, litteraly, as my system is using French locale.

sba923 commented 4 months ago

FWIW, I'm still encountering this from time to time...

image

sba923 commented 1 month ago

This also affects winget install BTW

image