Create a persistent install log file to help root cause package upgrade issues (#13500)

* Create a persistent install log file to help root cause package upgrade issues

* Update src/windows/common/wslutil.cpp

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

* Collect log file in diagnostic script

---------

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

diagnostics/collect-wsl-logs.ps1

@@ -56,6 +56,8 @@ if (Test-Path $wslconfig)
     Copy-Item $wslconfig $folder | Out-Null
 }
 
+Copy-Item "C:\Windows\temp\wsl-install-log.txt" $folder -ErrorAction ignore
+
 get-appxpackage MicrosoftCorporationII.WindowsSubsystemforLinux -ErrorAction Ignore > $folder/appxpackage.txt
 get-acl "C:\ProgramData\Microsoft\Windows\WindowsApps" -ErrorAction Ignore | Format-List > $folder/acl.txt
 Get-WindowsOptionalFeature -Online > $folder/optional-components.txt

msipackage/package.wix.in

@@ -397,6 +397,14 @@
             Execute="deferred"
          />
 
+        <CustomAction Id="FinalizeInstall"
+            Impersonate="no"
+            BinaryRef="wslinstall.dll"
+            DllEntry="WslFinalizeInstallation"
+            Return="check"
+            Execute="deferred"
+         />
+
         <CustomAction Id="DeprovisionMsix"
             Impersonate="no"
             BinaryRef="wslinstall.dll"
@@ -533,6 +541,8 @@
                 <Custom Action="CalculateWslSettingsProtocolIds" Before="WriteRegistryValues" Condition='(not REMOVE~="ALL")' />
             <?endif?>
 
+            <Custom Action="FinalizeInstall" After="PublishFeatures"/>
+
         </InstallExecuteSequence>
 
         <!-- Don't show a 'Modify' button in settings since there is nothing to modify -->

src/windows/common/wslutil.cpp

@@ -135,6 +135,7 @@ static const std::map<HRESULT, LPCWSTR> g_commonErrors{
     X_WIN32(ERROR_INVALID_SECURITY_DESCR),
     X(VM_E_INVALID_STATE),
     X_WIN32(STATUS_SHUTDOWN_IN_PROGRESS),
+    X_WIN32(ERROR_BAD_PATHNAME),
     X(WININET_E_TIMEOUT)};
 
 #undef X
@@ -1344,10 +1345,17 @@ int WINAPI InstallRecordHandler(void* context, UINT messageType, LPCWSTR message
     try
     {
         WSL_LOG("MSIMessage", TraceLoggingValue(messageType, "type"), TraceLoggingValue(message, "message"));
+        auto type = (INSTALLMESSAGE)(0xFF000000 & (UINT)messageType);
+
+        if (type == INSTALLMESSAGE_ERROR || type == INSTALLMESSAGE_FATALEXIT || type == INSTALLMESSAGE_WARNING)
+        {
+            WriteInstallLog(std::format("MSI message: {}", message));
+        }
+
         auto* callback = reinterpret_cast<const std::function<void(UINT, LPCWSTR)>*>(context);
         if (callback != nullptr)
         {
-            (*callback)((INSTALLMESSAGE)(0xFF000000 & (UINT)messageType), message);
+            (*callback)(type, message);
         }
     }
     CATCH_LOG();
@@ -1401,6 +1409,8 @@ int wsl::windows::common::wslutil::UpdatePackage(bool PreRelease, bool Repair)
 UINT wsl::windows::common::wslutil::UpgradeViaMsi(
     _In_ LPCWSTR PackageLocation, _In_opt_ LPCWSTR ExtraArgs, _In_opt_ LPCWSTR LogFile, _In_ const std::function<void(INSTALLMESSAGE, LPCWSTR)>& Callback)
 {
+    WriteInstallLog(std::format("Upgrading via MSI package: {}. Args: {}", PackageLocation, ExtraArgs != nullptr ? ExtraArgs : L""));
+
     ConfigureMsiLogging(LogFile, Callback);
 
     auto result = MsiInstallProduct(PackageLocation, ExtraArgs);
@@ -1409,6 +1419,8 @@ UINT wsl::windows::common::wslutil::UpgradeViaMsi(
         TraceLoggingValue(result, "result"),
         TraceLoggingValue(ExtraArgs != nullptr ? ExtraArgs : L"", "ExtraArgs"));
 
+    WriteInstallLog(std::format("MSI upgrade result: {}", result));
+
     return result;
 }
 
@@ -1417,10 +1429,15 @@ UINT wsl::windows::common::wslutil::UninstallViaMsi(_In_opt_ LPCWSTR LogFile, _I
     const auto key = OpenLxssMachineKey(KEY_READ);
     const auto productCode = ReadString(key.get(), L"Msi", L"ProductCode", nullptr);
 
+    WriteInstallLog(std::format("Uninstalling MSI package: {}", productCode));
+
     ConfigureMsiLogging(LogFile, Callback);
 
     auto result = MsiConfigureProduct(productCode.c_str(), 0, INSTALLSTATE_ABSENT);
     WSL_LOG("MsiUninstallResult", TraceLoggingValue(result, "result"));
+
+    WriteInstallLog(std::format("MSI package uninstall result: {}", result));
+
     return result;
 }
 
@@ -1451,6 +1468,43 @@ wil::unique_hfile wsl::windows::common::wslutil::ValidateFileSignature(LPCWSTR P
     return fileHandle;
 }
 
+void wsl::windows::common::wslutil::WriteInstallLog(const std::string& Content)
+try
+{
+    static std::wstring path = wil::GetWindowsDirectoryW<std::wstring>() + L"\\temp\\wsl-install-log.txt";
+
+    // Wait up to 10 seconds for the log file mutex
+    wil::unique_handle mutex{CreateMutex(nullptr, true, L"Global\\WslInstallLog")};
+    THROW_LAST_ERROR_IF(!mutex);
+
+    THROW_LAST_ERROR_IF(WaitForSingleObject(mutex.get(), 10 * 1000) != WAIT_OBJECT_0);
+
+    wil::unique_handle file{CreateFile(
+        path.c_str(), GENERIC_ALL, FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE, nullptr, OPEN_ALWAYS, 0, nullptr)};
+
+    THROW_LAST_ERROR_IF(!file);
+
+    LARGE_INTEGER size{};
+    THROW_IF_WIN32_BOOL_FALSE(GetFileSizeEx(file.get(), &size));
+
+    // Append to the file if its size is below 10MB, otherwise truncate.
+    if (size.QuadPart < 10 * _1MB)
+    {
+        THROW_LAST_ERROR_IF(SetFilePointer(file.get(), 0, nullptr, FILE_END) == INVALID_SET_FILE_POINTER);
+    }
+    else
+    {
+        THROW_IF_WIN32_BOOL_FALSE(SetEndOfFile(file.get()));
+    }
+
+    static auto processName = wil::GetModuleFileNameW<std::wstring>();
+    auto logLine = std::format("{:%FT%TZ} {}[{}]: {}\n", std::chrono::system_clock::now(), processName, WSL_PACKAGE_VERSION, Content);
+
+    DWORD bytesWritten{};
+    THROW_IF_WIN32_BOOL_FALSE(WriteFile(file.get(), logLine.c_str(), static_cast<DWORD>(logLine.size()), &bytesWritten, nullptr));
+}
+CATCH_LOG();
+
 winrt::Windows::Management::Deployment::PackageVolume wsl::windows::common::wslutil::GetSystemVolume()
 try
 {

src/windows/common/wslutil.h

@@ -181,6 +181,8 @@ UINT UpgradeViaMsi(_In_ LPCWSTR PackageLocation, _In_opt_ LPCWSTR ExtraArgs, _In
 
 UINT UninstallViaMsi(_In_opt_ LPCWSTR LogFile, _In_ const std::function<void(INSTALLMESSAGE, LPCWSTR)>& callback);
 
+void WriteInstallLog(const std::string& Content);
+
 winrt::Windows::Management::Deployment::PackageVolume GetSystemVolume();
 
 } // namespace wsl::windows::common::wslutil

src/windows/wslinstall/DllMain.cpp

@@ -23,6 +23,7 @@ Abstract:
 using unique_msi_handle = wil::unique_any<MSIHANDLE, decltype(MsiCloseHandle), &MsiCloseHandle>;
 
 using namespace wsl::windows::common::registry;
+using namespace wsl::windows::common::wslutil;
 
 static constexpr auto c_progIdPrefix{L"App."};
 static constexpr auto c_protocolProgIdSuffix{L".Protocol"};
@@ -519,6 +520,7 @@ extern "C" UINT __stdcall DeprovisionMsix(MSIHANDLE install)
 try
 {
     WSL_LOG("DeprovisionMsix");
+    WriteInstallLog("MSI install: DeprovisionMsix");
 
     const winrt::Windows::Management::Deployment::PackageManager packageManager;
     const auto result = packageManager.DeprovisionPackageForAllUsersAsync(wsl::windows::common::wslutil::c_msixPackageFamilyName).get();
@@ -542,6 +544,7 @@ extern "C" UINT __stdcall RemoveMsixAsSystem(MSIHANDLE install)
 try
 {
     WSL_LOG("RemoveMsixAsSystem");
+    WriteInstallLog("MSI install: RemoveMsixAsSystem");
 
     const winrt::Windows::Management::Deployment::PackageManager packageManager;
 
@@ -571,6 +574,7 @@ extern "C" UINT __stdcall RemoveMsixAsUser(MSIHANDLE install)
 try
 {
     WSL_LOG("RemoveMsixAsUser");
+    WriteInstallLog("MSI install: RemoveMsixAsUser");
 
     const winrt::Windows::Management::Deployment::PackageManager packageManager;
 
@@ -640,6 +644,7 @@ extern "C" UINT __stdcall InstallMsixAsUser(MSIHANDLE install)
 try
 {
     WSL_LOG("InstallMsixAsUser");
+    WriteInstallLog("MSI install: InstallMsixAsUser");
 
     // RegisterPackageByFamilyNameAsync() cannot be run as SYSTEM.
     //  If this thread runs as SYSTEM, simply skip this step.
@@ -683,6 +688,7 @@ try
     msixFile.Handle.reset();
 
     WSL_LOG("InstallMsix", TraceLoggingValue(msixFile.Path.c_str(), "Path"));
+    WriteInstallLog("MSI install: InstallMsix");
 
     winrt::Windows::Management::Deployment::PackageManager packageManager;
 
@@ -780,11 +786,25 @@ catch (...)
     return ERROR_INSTALL_FAILURE;
 }
 
+extern "C" UINT __stdcall WslFinalizeInstallation(MSIHANDLE install)
+{
+    try
+    {
+        WSL_LOG("WslFinalizeInstallation");
+        WriteInstallLog(std::format("MSI install: WslFinalizeInstallation"));
+    }
+    CATCH_LOG();
+
+    return NOERROR;
+}
+
 extern "C" UINT __stdcall WslValidateInstallation(MSIHANDLE install)
 try
 {
     WSL_LOG("WslValidateInstallation");
 
+    WriteInstallLog(std::format("MSI install: WslValidateInstallation"));
+
     // TODO: Use a more precise version check so we don't install if the Windows build doesn't support lifted.
 
     if (wsl::windows::common::helpers::GetWindowsVersion().BuildNumber < wsl::windows::common::helpers::Vibranium)

src/windows/wslinstall/wslinstall.def

@@ -5,6 +5,7 @@ EXPORTS
     CleanMsixState
     DeprovisionMsix
     WslValidateInstallation
+    WslFinalizeInstallation
     InstallMsix
     InstallMsixAsUser
     RegisterLspCategories

src/windows/wslinstaller/exe/WslInstaller.cpp

@@ -102,7 +102,7 @@ DWORD WINAPI InstallMsiPackage(LPVOID Context)
     return 0;
 }
 
-bool IsUpdateNeeded()
+std::pair<bool, std::wstring> IsUpdateNeeded()
 {
     try
     {
@@ -115,13 +115,15 @@ bool IsUpdateNeeded()
             TraceLoggingLevel(WINEVENT_LEVEL_INFO),
             TraceLoggingValue(installedVersion.c_str(), "InstalledVersion"));
 
-        return installedVersion.empty() || wsl::windows::common::wslutil::ParseWslPackageVersion(installedVersion) < wsl::shared::PackageVersion;
+        return std::make_pair(
+            installedVersion.empty() || wsl::windows::common::wslutil::ParseWslPackageVersion(installedVersion) < wsl::shared::PackageVersion,
+            installedVersion);
     }
     catch (...)
     {
         LOG_CAUGHT_EXCEPTION();
 
-        return false;
+        return std::make_pair(false, L"");
     }
 }
 
@@ -132,11 +134,14 @@ std::shared_ptr<InstallContext> LaunchInstall()
 
     auto lock = mutex.lock_exclusive();
 
-    if (!IsUpdateNeeded())
+    auto [updateNeeded, existingVersion] = IsUpdateNeeded();
+    if (!updateNeeded)
     {
         return {};
     }
 
+    wsl::windows::common::wslutil::WriteInstallLog(std::format("Starting upgrade via WslInstaller. Previous version: {}", existingVersion));
+
     // Return an existing install if any
     if (auto ptr = weak_context.lock(); ptr != nullptr)
     {