From a734d862b677eaad5a58a6065fc127924bca157d Mon Sep 17 00:00:00 2001 From: Pieter Viljoen Date: Tue, 3 Nov 2026 08:14:21 -0800 Subject: [PATCH 1/5] Read winget's Own Log When an Install Fails So a Portable Package Names Its Holders A failed winget install or upgrade named the processes holding the tool's files only where the package's installer log or winget's exit code said files were in use. A portable or zip package has no installer, so it writes no such log, and winget reports its refusal to delete a running executable under a generic install-failed code. The upgrade then failed with no hint of what held the file. Get-InstallerFailureReason now also reads winget's own session log for the failed call, the latest one started at or after the attempt that names the package id, and keeps its error lines. An access denial or a sharing violation now counts as files in use in either log, matching the exit codes already read that way. Only processes running from the tool's own install are ever named, so a denial over permissions blames nothing unrelated. Co-Authored-By: Claude Opus 5.5 --- host-setup/windows/install-tools.ps1 | 66 +++++++++++------ tests/test_install_tools.py | 107 ++++++++++++++++++++++++++- 2 files changed, 149 insertions(+), 24 deletions(-) diff --git a/host-setup/windows/install-tools.ps1 b/host-setup/windows/install-tools.ps1 index b9dfcbeb7..5a8b77910 100644 --- a/host-setup/windows/install-tools.ps1 +++ b/host-setup/windows/install-tools.ps1 @@ -473,30 +473,49 @@ $WINGET_LOG_DIRECTORY = Join-Path $env:LOCALAPPDATA 'Packages\Microsoft.DesktopA # So a run of later error and abort lines cannot push the actual reason out of the report. function Get-InstallerFailureReason { param([Parameter(Mandatory)][string]$Id, [Parameter(Mandatory)][datetime]$Since, [string]$Directory = $script:WINGET_LOG_DIRECTORY) - $result = @{ Log = $null; Entries = @(); InUse = $false } + $result = @{ Log = $null; Entries = @(); WingetLog = $null; WingetEntries = @(); InUse = $false } if (-not (Test-Path -LiteralPath $Directory -PathType Container)) { return $result } $log = Get-ChildItem -LiteralPath $Directory -Filter "$Id.*.log" -File -ErrorAction SilentlyContinue | Where-Object { $_.LastWriteTime -ge $Since } | Sort-Object LastWriteTime | Select-Object -Last 1 - if (-not $log) { return $result } - $result.Log = $log.FullName - $entries = [System.Collections.Generic.List[string]]::new() - foreach ($line in (Get-Content -LiteralPath $log.FullName -ErrorAction SilentlyContinue)) { - if (($line -eq '' -or $line -match '^\s') -and $entries.Count -gt 0) { - $entries[$entries.Count - 1] = "$($entries[$entries.Count - 1]) $($line.Trim())".TrimEnd() - } else { - $entries.Add(($line -replace '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d+\s+', '').Trim()) + if ($log) { + $result.Log = $log.FullName + $entries = [System.Collections.Generic.List[string]]::new() + foreach ($line in (Get-Content -LiteralPath $log.FullName -ErrorAction SilentlyContinue)) { + if (($line -eq '' -or $line -match '^\s') -and $entries.Count -gt 0) { + $entries[$entries.Count - 1] = "$($entries[$entries.Count - 1]) $($line.Trim())".TrimEnd() + } else { + $entries.Add(($line -replace '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d+\s+', '').Trim()) + } } + $selected = Select-FailureEntry -Entries $entries -Pattern '(?i)suppressed message box|\berror\b|\bfail|\babort|denied|in use|return value 3' + $result.Entries = $selected.Entries + $result.InUse = $selected.InUse + } + $idPattern = "(?i)(? ' } | ForEach-Object { ($_ -replace '^\S+ \S+ \[[^\]]*\]\s*', '').Trim() }) + $selected = Select-FailureEntry -Entries $errors -Pattern '.' + $result.WingetEntries = $selected.Entries + $result.InUse = $result.InUse -or $selected.InUse } - $inUsePattern = '(?i)process\(es\) use|in use by|used by another process' - $matched = @($entries | Where-Object { $_ -match '(?i)suppressed message box|\berror\b|\bfail|\babort|denied|in use|return value 3' -or $_ -match $inUsePattern }) + return $result +} + +function Select-FailureEntry { + param([string[]]$Entries, [Parameter(Mandatory)][string]$Pattern) + $inUsePattern = '(?i)process\(es\) use|in use by|used by another process|access is denied|sharing violation' + $matched = @($Entries | Where-Object { $_ -and ($_ -match $Pattern -or $_ -match $inUsePattern) }) $inUse = @($matched | Where-Object { $_ -match $inUsePattern }) - $result.InUse = $inUse.Count -gt 0 $shown = @($matched | Select-Object -Last 4) - if ($result.InUse -and -not ($shown | Where-Object { $_ -match $inUsePattern })) { + if ($inUse.Count -gt 0 -and -not ($shown | Where-Object { $_ -match $inUsePattern })) { $shown = @($inUse[0]) + @($matched | Select-Object -Last 3) } - $result.Entries = $shown - return $result + return @{ Entries = $shown; InUse = $inUse.Count -gt 0 } } # The directory one installed file's package owns, read as the child of the container it was installed into. @@ -580,14 +599,19 @@ function Write-InstallFailure { param([Parameter(Mandatory)][string]$ToolName, [Parameter(Mandatory)][string]$Package, [Parameter(Mandatory)][int]$Code, [Parameter(Mandatory)][datetime]$Since, [Parameter(Mandatory)][string]$Probe, [string]$Executable) warn "$ToolName failed on $Package, winget exited $Code ($('0x{0:X8}' -f $Code))" $reason = Get-InstallerFailureReason -Id $Package -Since $Since - if ($reason.Entries.Count -gt 0) { - info 'The installer log says:' - foreach ($entry in $reason.Entries) { - $shown = if ($HOME) { $entry -ireplace [regex]::Escape($HOME), '%USERPROFILE%' } else { $entry } - info " $shown" + foreach ($source in @( + @{ Heading = 'The installer log says:'; Entries = @($reason.Entries); Log = $reason.Log; Label = 'Full installer log' } + @{ Heading = "winget's own log says:"; Entries = @($reason.WingetEntries); Log = $reason.WingetLog; Label = 'Full winget log' } + )) { + if ($source.Entries.Count -gt 0) { + info $source.Heading + foreach ($entry in $source.Entries) { + $shown = if ($HOME) { $entry -ireplace [regex]::Escape($HOME), '%USERPROFILE%' } else { $entry } + info " $shown" + } } + if ($source.Log) { info "$($source.Label): $(Hide-Home $source.Log)" } } - if ($reason.Log) { info "Full installer log: $(Hide-Home $reason.Log)" } $logInUse = [bool]$reason.InUse # 0x8A150101 and 0x8A150103 are winget's own INSTALL_PACKAGE_IN_USE and INSTALL_FILE_IN_USE, which it returns where a manifest maps the installer's exit code to either. # 0x80070020 and 0x80070005 are ERROR_SHARING_VIOLATION and ERROR_ACCESS_DENIED carried as an HRESULT. diff --git a/tests/test_install_tools.py b/tests/test_install_tools.py index 876fe9525..e07a17726 100755 --- a/tests/test_install_tools.py +++ b/tests/test_install_tools.py @@ -817,7 +817,7 @@ def test_the_note_follows_what_dotnet_lists(self) -> None: $tokens = $null $errors = $null $ast = [System.Management.Automation.Language.Parser]::ParseFile($Installer, [ref]$tokens, [ref]$errors) -$wanted = @('Get-InstallerFailureReason', 'Get-InstallRoot', 'Invoke-Utf8Run', 'Get-ToolHolder') +$wanted = @('Get-InstallerFailureReason', 'Select-FailureEntry', 'Get-InstallRoot', 'Invoke-Utf8Run', 'Get-ToolHolder') foreach ($definition in $ast.FindAll({ param($node) $node -is [System.Management.Automation.Language.FunctionDefinitionAst] -and $wanted -contains $node.Name }, $true)) { . ([scriptblock]::Create($definition.Extent.Text)) } @@ -825,7 +825,13 @@ def test_the_note_follows_what_dotnet_lists(self) -> None: $results = [ordered]@{} foreach ($probe in $case.reasons) { $reason = Get-InstallerFailureReason -Id $probe.id -Since ([datetime]$probe.since) -Directory $case.directory - $results["reason $($probe.id) $($probe.since)"] = [ordered]@{ log = [bool]$reason.Log; entries = @($reason.Entries); in_use = $reason.InUse } + $results["reason $($probe.id) $($probe.since)"] = [ordered]@{ + log = [bool]$reason.Log + entries = @($reason.Entries) + winget_log = [bool]$reason.WingetLog + winget_entries = @($reason.WingetEntries) + in_use = $reason.InUse + } } $env:ProgramFiles = 'C:\PF' ${env:ProgramFiles(x86)} = 'C:\PF86' @@ -892,9 +898,12 @@ def test_the_note_follows_what_dotnet_lists(self) -> None: $script:REASON = @{ Log = 'C:\log.log' Entries = @($case.Value.entries | ForEach-Object { $_ -replace '', $HOME.Replace('$', '$$') }) + WingetLog = 'C:\winget.log' + WingetEntries = @(if ($case.Value.PSObject.Properties['winget_entries']) { $case.Value.winget_entries | ForEach-Object { $_ -replace '', $HOME.Replace('$', '$$') } }) InUse = [bool]($case.Value.PSObject.Properties['in_use'] -and $case.Value.in_use) } if ($script:REASON.Entries.Count -eq 0) { $script:REASON.Log = $null } + if ($script:REASON.WingetEntries.Count -eq 0) { $script:REASON.WingetLog = $null } function Get-InstallerFailureReason { param([string]$Id, [datetime]$Since) return $script:REASON } $script:LINES = @() Write-InstallFailure -ToolName 'tool' -Package 'Example.Tool' -Code $case.Value.code -Since (Get-Date) -Probe 'tool' -Executable $case.Value.executable @@ -915,6 +924,22 @@ def test_the_note_follows_what_dotnet_lists(self) -> None: "2026-01-02 03:04:06.002 Deinitializing Setup.", ] +PORTABLE_WINGET_LOG = [ + "2026-01-02 03:04:05.100 [CLI ] WinGet invoked with arguments: 'upgrade' '--id' 'Portable.Tool'", + "2026-01-02 03:04:05.200 [CLI ] Deleting portable exe at: C:\\LAD\\Portable.Tool_x\\tool.exe", + ( + "2026-01-02 03:04:05.300 [CLI ] Caught std::exception: remove: Access is denied.:" + ' "C:\\LAD\\Portable.Tool_x\\tool.exe"' + ), + "2026-01-02 03:04:05.301 [CLI ] Portable installer failed: 2316632067", + "2026-01-02 03:04:05.302 [CLI ] Terminating context: 0x8a150052 at C:\\src\\InstallFlow.cpp:239", +] + +OTHER_WINGET_LOG = [ + "2026-01-02 03:04:05.100 [CLI ] WinGet invoked with arguments: 'upgrade' '--id' 'Portable.Tool.Extra'", + "2026-01-02 03:04:05.300 [CLI ] Caught std::exception: remove: Access is denied.", +] + BUSY_LOG = [ "2026-01-02 03:04:05.100 The file is being used by another process.", *( @@ -936,6 +961,13 @@ def run_cases(self) -> dict[str, Any]: log.write_text("\r\n".join([*INNO_LOG, ""]), encoding="utf-8", newline="") busy = Path(directory, "Busy.Tool.1.0-26-01-02-03-04-05.log") busy.write_text("\r\n".join([*BUSY_LOG, ""]), encoding="utf-8", newline="") + for name, lines in ( + ("WinGet-2026-01-02-03-04-05.000.log", PORTABLE_WINGET_LOG), + ("WinGet-2026-01-02-03-04-06.000.log", OTHER_WINGET_LOG), + ): + Path(directory, name).write_text( + "\r\n".join([*lines, ""]), encoding="utf-8", newline="" + ) elsewhere = Path(directory, "LAD", "Programs", "Tool", "tool.exe") elsewhere.parent.mkdir(parents=True) elsewhere.write_bytes(b"") @@ -946,6 +978,8 @@ def run_cases(self) -> dict[str, Any]: {"id": "Example.Tool", "since": "2100-01-01"}, {"id": "Other.Tool", "since": "2000-01-01"}, {"id": "Busy.Tool", "since": "2000-01-01"}, + {"id": "Portable.Tool", "since": "2000-01-01"}, + {"id": "Portable.Tool", "since": "2100-01-01"}, ], "roots": [ "C:\\PF\\Git\\cmd\\git.exe", @@ -976,6 +1010,8 @@ def test_the_log_entry_keeps_its_continuation_lines(self) -> None: ), "Failed to proceed to next wizard page; aborting.", ], + "winget_log": False, + "winget_entries": [], "in_use": True, }, ) @@ -991,15 +1027,47 @@ def test_an_in_use_entry_survives_the_cap_on_later_errors(self) -> None: "Error 3: rollback step failed.", "Error 4: rollback step failed.", ], + "winget_log": False, + "winget_entries": [], "in_use": True, }, ) def test_a_log_older_than_the_attempt_or_for_another_id_is_not_read(self) -> None: results = self.run_cases() - unread = {"log": False, "entries": [], "in_use": False} + unread = { + "log": False, + "entries": [], + "winget_log": False, + "winget_entries": [], + "in_use": False, + } self.assertEqual(results["reason Example.Tool 2100-01-01"], unread) self.assertEqual(results["reason Other.Tool 2000-01-01"], unread) + self.assertEqual(results["reason Portable.Tool 2100-01-01"], unread) + + def test_wingets_own_log_gives_a_portable_packages_reason(self) -> None: + """A package with no installer log has its reason read from winget's own session log. + + A session log naming a longer id that only starts with this one is not read as this one's. + """ + self.assertEqual( + self.run_cases()["reason Portable.Tool 2000-01-01"], + { + "log": False, + "entries": [], + "winget_log": True, + "winget_entries": [ + ( + "Caught std::exception: remove: Access is denied.:" + ' "C:\\LAD\\Portable.Tool_x\\tool.exe"' + ), + "Portable installer failed: 2316632067", + "Terminating context: 0x8a150052 at C:\\src\\InstallFlow.cpp:239", + ], + "in_use": True, + }, + ) @unittest.skipUnless(sys.platform == "win32", "reads this host's own process list") def test_a_same_named_process_outside_the_tree_is_not_a_holder(self) -> None: @@ -1038,6 +1106,7 @@ def test_the_utf8_run_switches_only_for_console_output_and_restores_it(self) -> INSTALLER_FAILED = -1978335226 SHARING_VIOLATION = -2147024864 WINGET_FILE_IN_USE = -1978334973 +WINGET_INSTALL_FAILED = -1978335150 @unittest.skipUnless( @@ -1063,6 +1132,15 @@ def run_cases(self) -> dict[str, list[str]]: }, "no reason": {"entries": [], "code": INSTALLER_FAILED, "executable": ""}, "winget file in use": {"entries": [], "code": WINGET_FILE_IN_USE, "executable": ""}, + "portable in use": { + "entries": [], + "winget_entries": [ + 'Caught std::exception: remove: Access is denied.: "\\Tool_x\\tool.exe"' + ], + "in_use": True, + "code": WINGET_INSTALL_FAILED, + "executable": "", + }, "sharing violation": { "entries": [], "code": SHARING_VIOLATION, @@ -1121,6 +1199,29 @@ def test_wingets_own_file_in_use_code_names_the_holders(self) -> None: ], ) + def test_wingets_own_log_saying_access_denied_names_the_holders(self) -> None: + self.assertEqual( + self.run_cases()["portable in use"], + [ + "WARN tool failed on Example.Tool, winget exited -1978335150 (0x8A150052)", + "INFO winget's own log says:", + ( + "INFO Caught std::exception: remove: Access is denied.:" + ' "%USERPROFILE%\\Tool_x\\tool.exe"' + ), + "INFO Full winget log: LOG", + "HOLDERS tool", + ( + "INFO Running from tool's install, and Windows cannot replace a file a" + " running process holds:" + ), + "INFO helper (process 1234)", + "INFO bash (process 99)", + "INFO Close them, or stop them with the command below, then run this again:", + "INFO Stop-Process -Id 1234, 99", + ], + ) + def test_a_sharing_violation_names_the_holders_from_the_executable_given(self) -> None: lines = self.run_cases()["sharing violation"] self.assertEqual( From c700bdc8a0964a20ff1af7d2fe79aa81a49c1694 Mon Sep 17 00:00:00 2001 From: Pieter Viljoen Date: Tue, 3 Nov 2026 08:20:00 -0800 Subject: [PATCH 2/5] Count a Denial as Files in Use Only in winget's Own Log, and Correct the Two Headers An installer log saying "Access is denied" can be a permission failure, which no running process causes, so only winget's own log now reads a denial or a sharing violation as files in use. The headers of Get-InstallerFailureReason and Write-InstallFailure said only the installer log gives a reason, which this change made false. Co-Authored-By: Claude Opus 5.5 --- host-setup/windows/install-tools.ps1 | 23 ++++++++++++++--------- tests/test_install_tools.py | 20 ++++++++++++++++++++ 2 files changed, 34 insertions(+), 9 deletions(-) diff --git a/host-setup/windows/install-tools.ps1 b/host-setup/windows/install-tools.ps1 index 5a8b77910..a355c69b0 100644 --- a/host-setup/windows/install-tools.ps1 +++ b/host-setup/windows/install-tools.ps1 @@ -460,8 +460,9 @@ function Invoke-WingetRemove { # Where App Installer keeps every installer log winget asks a package for, named .-.log. $WINGET_LOG_DIRECTORY = Join-Path $env:LOCALAPPDATA 'Packages\Microsoft.DesktopAppInstaller_8wekyb3d8bbwe\LocalState\DiagOutputDir' -# The entries of the installer log one failed winget call wrote that say why it failed, or none where no such log or entry exists. -# All winget reports is that the installer exited non-zero, with a code the installer chose. +# The entries of the installer log one failed winget call wrote, and of winget's own log for that call, that say why it failed. +# Each is none where no such log or entry exists. +# For a package with an installer, all winget reports is that the installer exited non-zero, with a code the installer chose. # So the reason lives in that log and nowhere a person reads by default. # A silent Inno Setup installer, Git for Windows among them, answers its own blocking dialog and logs the dialog's text. # That text is the whole reason. @@ -471,6 +472,10 @@ $WINGET_LOG_DIRECTORY = Join-Path $env:LOCALAPPDATA 'Packages\Microsoft.DesktopA # Whether files were in use is read from every entry before that cap. # An in-use entry is always among those shown, the first one put back where none survived the cap. # So a run of later error and abort lines cannot push the actual reason out of the report. +# A portable or zip package has no installer, so winget's own WinGet-.log for the call holds its reason instead. +# That log is the latest one started since the attempt that names the package id, and only its error lines are kept. +# Only there does an access denial or a sharing violation count as files in use, being winget's own refusal to replace a file. +# In an installer log the same words can be a permission failure, which no running process causes. function Get-InstallerFailureReason { param([Parameter(Mandatory)][string]$Id, [Parameter(Mandatory)][datetime]$Since, [string]$Directory = $script:WINGET_LOG_DIRECTORY) $result = @{ Log = $null; Entries = @(); WingetLog = $null; WingetEntries = @(); InUse = $false } @@ -499,7 +504,7 @@ function Get-InstallerFailureReason { $result.WingetLog = $session.FullName $errors = @(Get-Content -LiteralPath $session.FullName -ErrorAction SilentlyContinue | Where-Object { $_ -match '^\S+ \S+ ' } | ForEach-Object { ($_ -replace '^\S+ \S+ \[[^\]]*\]\s*', '').Trim() }) - $selected = Select-FailureEntry -Entries $errors -Pattern '.' + $selected = Select-FailureEntry -Entries $errors -Pattern '.' -InUsePattern '(?i)in use by|used by another process|access is denied|sharing violation' $result.WingetEntries = $selected.Entries $result.InUse = $result.InUse -or $selected.InUse } @@ -507,12 +512,11 @@ function Get-InstallerFailureReason { } function Select-FailureEntry { - param([string[]]$Entries, [Parameter(Mandatory)][string]$Pattern) - $inUsePattern = '(?i)process\(es\) use|in use by|used by another process|access is denied|sharing violation' - $matched = @($Entries | Where-Object { $_ -and ($_ -match $Pattern -or $_ -match $inUsePattern) }) - $inUse = @($matched | Where-Object { $_ -match $inUsePattern }) + param([string[]]$Entries, [Parameter(Mandatory)][string]$Pattern, [string]$InUsePattern = '(?i)process\(es\) use|in use by|used by another process') + $matched = @($Entries | Where-Object { $_ -and ($_ -match $Pattern -or $_ -match $InUsePattern) }) + $inUse = @($matched | Where-Object { $_ -match $InUsePattern }) $shown = @($matched | Select-Object -Last 4) - if ($inUse.Count -gt 0 -and -not ($shown | Where-Object { $_ -match $inUsePattern })) { + if ($inUse.Count -gt 0 -and -not ($shown | Where-Object { $_ -match $InUsePattern })) { $shown = @($inUse[0]) + @($matched | Select-Object -Last 3) } return @{ Entries = $shown; InUse = $inUse.Count -gt 0 } @@ -583,7 +587,7 @@ function Get-ToolHolder { # What a failed winget call owes its reader: # - winget's code -# - the reason the installer's own log gives +# - the reason the installer's own log gives, and the one winget's own log gives # - the processes that may hold the tool's files # The hex form of the code is the one winget documents its codes under, where the signed decimal matches nothing a search finds. # The log entries pass through the same home folder masking as the log's path, since an installer's reason commonly names a file under the profile. @@ -591,6 +595,7 @@ function Get-ToolHolder { # So the processes running from the tool's install are named only where something says files were in use. # Something says so in one of these ways: # - an installer log entry in Inno Setup's or Windows' own in-use wording +# - an error in winget's own log for the call saying a file was in use or denied # - winget's code being one of its own package-in-use or file-in-use codes, a sharing violation, or an access denial # Anything else names nobody, for this reason. # A Git upgrade that failed on a download leaves no log and still finds every open Git Bash running from Git's own tree. diff --git a/tests/test_install_tools.py b/tests/test_install_tools.py index e07a17726..76a054637 100755 --- a/tests/test_install_tools.py +++ b/tests/test_install_tools.py @@ -940,6 +940,10 @@ def test_the_note_follows_what_dotnet_lists(self) -> None: "2026-01-02 03:04:05.300 [CLI ] Caught std::exception: remove: Access is denied.", ] +DENIED_LOG = [ + "2026-01-02 03:04:05.100 Error 0x80070005: Access is denied.", +] + BUSY_LOG = [ "2026-01-02 03:04:05.100 The file is being used by another process.", *( @@ -961,6 +965,8 @@ def run_cases(self) -> dict[str, Any]: log.write_text("\r\n".join([*INNO_LOG, ""]), encoding="utf-8", newline="") busy = Path(directory, "Busy.Tool.1.0-26-01-02-03-04-05.log") busy.write_text("\r\n".join([*BUSY_LOG, ""]), encoding="utf-8", newline="") + denied = Path(directory, "Denied.Tool.1.0-26-01-02-03-04-05.log") + denied.write_text("\r\n".join([*DENIED_LOG, ""]), encoding="utf-8", newline="") for name, lines in ( ("WinGet-2026-01-02-03-04-05.000.log", PORTABLE_WINGET_LOG), ("WinGet-2026-01-02-03-04-06.000.log", OTHER_WINGET_LOG), @@ -978,6 +984,7 @@ def run_cases(self) -> dict[str, Any]: {"id": "Example.Tool", "since": "2100-01-01"}, {"id": "Other.Tool", "since": "2000-01-01"}, {"id": "Busy.Tool", "since": "2000-01-01"}, + {"id": "Denied.Tool", "since": "2000-01-01"}, {"id": "Portable.Tool", "since": "2000-01-01"}, {"id": "Portable.Tool", "since": "2100-01-01"}, ], @@ -1033,6 +1040,19 @@ def test_an_in_use_entry_survives_the_cap_on_later_errors(self) -> None: }, ) + def test_an_installer_logs_access_denial_alone_is_not_files_in_use(self) -> None: + """An installer's denial can be a permission failure, which no running process causes.""" + self.assertEqual( + self.run_cases()["reason Denied.Tool 2000-01-01"], + { + "log": True, + "entries": ["Error 0x80070005: Access is denied."], + "winget_log": False, + "winget_entries": [], + "in_use": False, + }, + ) + def test_a_log_older_than_the_attempt_or_for_another_id_is_not_read(self) -> None: results = self.run_cases() unread = { From 51d2f6ea43d79c3183faa20a8c61e723e6921047 Mon Sep 17 00:00:00 2001 From: Pieter Viljoen Date: Tue, 3 Nov 2026 08:24:12 -0800 Subject: [PATCH 3/5] Say Only a Denial Is Limited to winget's Log, and Drop the Redundant Write-Time Filter The header said a sharing violation counts as files in use only in winget's own log, but the installer-log wording already reads Windows' "used by another process" that way. Only a denial is limited to winget's log. A log created at or after the attempt was also written after it, so the write-time clause filtered nothing. Co-Authored-By: Claude Opus 5.5 --- host-setup/windows/install-tools.ps1 | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/host-setup/windows/install-tools.ps1 b/host-setup/windows/install-tools.ps1 index a355c69b0..7bd7870bf 100644 --- a/host-setup/windows/install-tools.ps1 +++ b/host-setup/windows/install-tools.ps1 @@ -474,8 +474,8 @@ $WINGET_LOG_DIRECTORY = Join-Path $env:LOCALAPPDATA 'Packages\Microsoft.DesktopA # So a run of later error and abort lines cannot push the actual reason out of the report. # A portable or zip package has no installer, so winget's own WinGet-.log for the call holds its reason instead. # That log is the latest one started since the attempt that names the package id, and only its error lines are kept. -# Only there does an access denial or a sharing violation count as files in use, being winget's own refusal to replace a file. -# In an installer log the same words can be a permission failure, which no running process causes. +# Only there does an access denial count as files in use, being winget's own refusal to replace a file. +# In an installer log a denial can be a permission failure, which no running process causes. function Get-InstallerFailureReason { param([Parameter(Mandatory)][string]$Id, [Parameter(Mandatory)][datetime]$Since, [string]$Directory = $script:WINGET_LOG_DIRECTORY) $result = @{ Log = $null; Entries = @(); WingetLog = $null; WingetEntries = @(); InUse = $false } @@ -498,7 +498,7 @@ function Get-InstallerFailureReason { } $idPattern = "(?i)(? Date: Tue, 3 Nov 2026 08:30:10 -0800 Subject: [PATCH 4/5] Count Only a winget Denial Naming a File as In Use, and Correct the Git Example winget's own log counted any "Access is denied" error line as files in use, while the header justifies that only for winget failing to replace a file. Only a denial naming a file now counts. A sharing violation still does, through the "used by another process" wording. The Write-InstallFailure header also said a failed Git download leaves no log, which winget's own session log made false. Co-Authored-By: Claude Opus 5.5 --- host-setup/windows/install-tools.ps1 | 6 +++--- tests/test_install_tools.py | 20 ++++++++++++++++++++ 2 files changed, 23 insertions(+), 3 deletions(-) diff --git a/host-setup/windows/install-tools.ps1 b/host-setup/windows/install-tools.ps1 index 7bd7870bf..22cca8d3a 100644 --- a/host-setup/windows/install-tools.ps1 +++ b/host-setup/windows/install-tools.ps1 @@ -474,7 +474,7 @@ $WINGET_LOG_DIRECTORY = Join-Path $env:LOCALAPPDATA 'Packages\Microsoft.DesktopA # So a run of later error and abort lines cannot push the actual reason out of the report. # A portable or zip package has no installer, so winget's own WinGet-.log for the call holds its reason instead. # That log is the latest one started since the attempt that names the package id, and only its error lines are kept. -# Only there does an access denial count as files in use, being winget's own refusal to replace a file. +# Only there does an access denial count as files in use, and only one naming a file, as winget reports failing to replace one. # In an installer log a denial can be a permission failure, which no running process causes. function Get-InstallerFailureReason { param([Parameter(Mandatory)][string]$Id, [Parameter(Mandatory)][datetime]$Since, [string]$Directory = $script:WINGET_LOG_DIRECTORY) @@ -504,7 +504,7 @@ function Get-InstallerFailureReason { $result.WingetLog = $session.FullName $errors = @(Get-Content -LiteralPath $session.FullName -ErrorAction SilentlyContinue | Where-Object { $_ -match '^\S+ \S+ ' } | ForEach-Object { ($_ -replace '^\S+ \S+ \[[^\]]*\]\s*', '').Trim() }) - $selected = Select-FailureEntry -Entries $errors -Pattern '.' -InUsePattern '(?i)in use by|used by another process|access is denied|sharing violation' + $selected = Select-FailureEntry -Entries $errors -Pattern '.' -InUsePattern '(?i)in use by|used by another process|access is denied\.?:\s*"' $result.WingetEntries = $selected.Entries $result.InUse = $result.InUse -or $selected.InUse } @@ -598,7 +598,7 @@ function Get-ToolHolder { # - an error in winget's own log for the call saying a file was in use or denied # - winget's code being one of its own package-in-use or file-in-use codes, a sharing violation, or an access denial # Anything else names nobody, for this reason. -# A Git upgrade that failed on a download leaves no log and still finds every open Git Bash running from Git's own tree. +# A Git upgrade that failed on a download logs no such entry and still finds every open Git Bash running from Git's own tree. # Blaming those would send the reader after the wrong thing. function Write-InstallFailure { param([Parameter(Mandatory)][string]$ToolName, [Parameter(Mandatory)][string]$Package, [Parameter(Mandatory)][int]$Code, [Parameter(Mandatory)][datetime]$Since, [Parameter(Mandatory)][string]$Probe, [string]$Executable) diff --git a/tests/test_install_tools.py b/tests/test_install_tools.py index 76a054637..9437d8308 100755 --- a/tests/test_install_tools.py +++ b/tests/test_install_tools.py @@ -940,6 +940,11 @@ def test_the_note_follows_what_dotnet_lists(self) -> None: "2026-01-02 03:04:05.300 [CLI ] Caught std::exception: remove: Access is denied.", ] +UNRELATED_DENIAL_WINGET_LOG = [ + "2026-01-02 03:04:05.100 [CLI ] WinGet invoked with arguments: 'install' '--id' 'Settings.Tool'", + "2026-01-02 03:04:05.300 [CORE] Failed to open the settings store: Access is denied.", +] + DENIED_LOG = [ "2026-01-02 03:04:05.100 Error 0x80070005: Access is denied.", ] @@ -970,6 +975,7 @@ def run_cases(self) -> dict[str, Any]: for name, lines in ( ("WinGet-2026-01-02-03-04-05.000.log", PORTABLE_WINGET_LOG), ("WinGet-2026-01-02-03-04-06.000.log", OTHER_WINGET_LOG), + ("WinGet-2026-01-02-03-04-07.000.log", UNRELATED_DENIAL_WINGET_LOG), ): Path(directory, name).write_text( "\r\n".join([*lines, ""]), encoding="utf-8", newline="" @@ -985,6 +991,7 @@ def run_cases(self) -> dict[str, Any]: {"id": "Other.Tool", "since": "2000-01-01"}, {"id": "Busy.Tool", "since": "2000-01-01"}, {"id": "Denied.Tool", "since": "2000-01-01"}, + {"id": "Settings.Tool", "since": "2000-01-01"}, {"id": "Portable.Tool", "since": "2000-01-01"}, {"id": "Portable.Tool", "since": "2100-01-01"}, ], @@ -1053,6 +1060,19 @@ def test_an_installer_logs_access_denial_alone_is_not_files_in_use(self) -> None }, ) + def test_a_winget_denial_naming_no_file_is_not_files_in_use(self) -> None: + """Only a denial naming a file is winget failing to replace one.""" + self.assertEqual( + self.run_cases()["reason Settings.Tool 2000-01-01"], + { + "log": False, + "entries": [], + "winget_log": True, + "winget_entries": ["Failed to open the settings store: Access is denied."], + "in_use": False, + }, + ) + def test_a_log_older_than_the_attempt_or_for_another_id_is_not_read(self) -> None: results = self.run_cases() unread = { From 10a272ba9c06ab6450a6f3982ad0289c58da2a8b Mon Sep 17 00:00:00 2001 From: Pieter Viljoen Date: Tue, 3 Nov 2026 08:34:02 -0800 Subject: [PATCH 5/5] Drop the Empty-Entry Guard in Select-FailureEntry Neither pattern either caller passes can match an empty string or a null, so the match already drops every entry the guard did. Co-Authored-By: Claude Opus 5.5 --- host-setup/windows/install-tools.ps1 | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/host-setup/windows/install-tools.ps1 b/host-setup/windows/install-tools.ps1 index 22cca8d3a..2ba310256 100644 --- a/host-setup/windows/install-tools.ps1 +++ b/host-setup/windows/install-tools.ps1 @@ -513,7 +513,7 @@ function Get-InstallerFailureReason { function Select-FailureEntry { param([string[]]$Entries, [Parameter(Mandatory)][string]$Pattern, [string]$InUsePattern = '(?i)process\(es\) use|in use by|used by another process') - $matched = @($Entries | Where-Object { $_ -and ($_ -match $Pattern -or $_ -match $InUsePattern) }) + $matched = @($Entries | Where-Object { $_ -match $Pattern -or $_ -match $InUsePattern }) $inUse = @($matched | Where-Object { $_ -match $InUsePattern }) $shown = @($matched | Select-Object -Last 4) if ($inUse.Count -gt 0 -and -not ($shown | Where-Object { $_ -match $InUsePattern })) {