@joebigelow / wix-1 / commits / b72f58ab

Use a dedicated pipe for redirecting logging from the elevated process.

Fixes 6869

Sean Hall committed Aug 19, 2022 at 14:08 UTC b72f58abdf6dd5d0020f174358027158cb52cb72
12 files changed +335 -99
src/burn/engine/core.cpp
+24
@@ -69,6 +69,9 @@ static HRESULT DetectPackagePayloadsCached(
69 static DWORD WINAPI CacheThreadProc(
70 __in LPVOID lpThreadParameter
71 );
72 +static DWORD WINAPI LoggingThreadProc(
73 + __in LPVOID lpThreadParameter
74 + );
75 static void LogPackages(
76 __in_opt const BURN_PACKAGE* pUpgradeBundlePackage,
77 __in_opt const BURN_PACKAGE* pForwardCompatibleBundlePackage,
@@ -615,6 +618,9 @@ extern "C" HRESULT CoreElevate(
618
619 hr = VariableSetNumeric(&pEngineState->variables, BURN_BUNDLE_ELEVATED, TRUE, TRUE);
620 ExitOnFailure(hr, "Failed to overwrite the %ls built-in variable.", BURN_BUNDLE_ELEVATED);
621 +
622 + pEngineState->hUnelevatedLoggingThread = ::CreateThread(NULL, 0, LoggingThreadProc, pEngineState, 0, NULL);
623 + ExitOnNullWithLastError(pEngineState->hUnelevatedLoggingThread, hr, "Failed to create unelevated logging thread.");
624 }
625
626 LExit:
@@ -2325,6 +2331,24 @@ LExit:
2331 return (DWORD)hr;
2332 }
2333
2334 +static DWORD WINAPI LoggingThreadProc(
2335 + __in LPVOID lpThreadParameter
2336 + )
2337 +{
2338 + HRESULT hr = S_OK;
2339 + BURN_ENGINE_STATE* pEngineState = reinterpret_cast<BURN_ENGINE_STATE*>(lpThreadParameter);
2340 + BURN_PIPE_RESULT result = { };
2341 +
2342 + hr = PipePumpMessages(pEngineState->companionConnection.hLoggingPipe, NULL, NULL, &result);
2343 + ExitOnFailure(hr, "Failed to pump logging messages for elevated process.");
2344 +
2345 + hr = (HRESULT)result.dwResult;
2346 +
2347 +LExit:
2348 +
2349 + return (DWORD)hr;
2350 +}
2351 +
2352 static void LogPackages(
2353 __in_opt const BURN_PACKAGE* pUpgradeBundlePackage,
2354 __in_opt const BURN_PACKAGE* pForwardCompatibleBundlePackage,
src/burn/engine/core.h
+1 -1
@@ -152,7 +152,7 @@ typedef struct _BURN_ENGINE_STATE
152
153 BURN_PLAN plan;
154
155 - DWORD dwElevatedLoggingTlsId;
155 + HANDLE hUnelevatedLoggingThread;
156
157 LPWSTR sczBundleEngineWorkingPath;
158 BURN_PIPE_CONNECTION companionConnection;
src/burn/engine/elevation.cpp
+2 -13
@@ -91,7 +91,6 @@ typedef struct _BURN_ELEVATION_LAUNCH_APPROVED_EXE_MESSAGE_CONTEXT
91
92 typedef struct _BURN_ELEVATION_CHILD_MESSAGE_CONTEXT
93 {
94 - DWORD dwLoggingTlsId;
94 HANDLE hPipe;
95 HANDLE* phLock;
96 BOOL* pfDisabledAutomaticUpdates;
@@ -397,10 +396,10 @@ extern "C" HRESULT ElevationElevate(
396 Assert(!pEngineState->companionConnection.dwProcessId);
397 Assert(INVALID_HANDLE_VALUE == pEngineState->companionConnection.hPipe);
398 Assert(INVALID_HANDLE_VALUE == pEngineState->companionConnection.hCachePipe);
399 + Assert(INVALID_HANDLE_VALUE == pEngineState->companionConnection.hLoggingPipe);
400
401 HRESULT hr = S_OK;
402 int nResult = IDOK;
403 - HANDLE hPipesCreatedEvent = INVALID_HANDLE_VALUE;
403
404 hr = UserExperienceOnElevateBegin(&pEngineState->userExperience);
405 ExitOnRootFailure(hr, "BA aborted elevation requirement.");
@@ -408,7 +407,7 @@ extern "C" HRESULT ElevationElevate(
407 hr = PipeCreateNameAndSecret(&pEngineState->companionConnection.sczName, &pEngineState->companionConnection.sczSecret);
408 ExitOnFailure(hr, "Failed to create pipe name and client token.");
409
411 - hr = PipeCreatePipes(&pEngineState->companionConnection, TRUE, &hPipesCreatedEvent);
410 + hr = PipeCreatePipes(&pEngineState->companionConnection, TRUE);
411 ExitOnFailure(hr, "Failed to create pipe and cache pipe.");
412
413 LogId(REPORT_STANDARD, MSG_LAUNCH_ELEVATED_ENGINE_STARTING);
@@ -442,8 +441,6 @@ extern "C" HRESULT ElevationElevate(
441 ExitOnFailure(hr, "Failed to elevate.");
442
443 LExit:
445 - ReleaseHandle(hPipesCreatedEvent);
446 -
444 if (FAILED(hr))
445 {
446 PipeConnectionUninitialize(&pEngineState->companionConnection);
@@ -1532,7 +1529,6 @@ LExit:
1529
1530 *******************************************************************/
1531 extern "C" HRESULT ElevationChildPumpMessages(
1535 - __in DWORD dwLoggingTlsId,
1532 __in HANDLE hPipe,
1533 __in HANDLE hCachePipe,
1534 __in BURN_APPROVED_EXES* pApprovedExes,
@@ -1556,7 +1552,6 @@ extern "C" HRESULT ElevationChildPumpMessages(
1552 BURN_PIPE_RESULT result = { };
1553 BOOL fDisabledAutomaticUpdates = FALSE;
1554
1559 - cacheContext.dwLoggingTlsId = dwLoggingTlsId;
1555 cacheContext.hPipe = hCachePipe;
1556 cacheContext.pCache = pCache;
1557 cacheContext.pContainers = pContainers;
@@ -1566,7 +1561,6 @@ extern "C" HRESULT ElevationChildPumpMessages(
1561 cacheContext.pRegistration = pRegistration;
1562 cacheContext.pUserExperience = pUserExperience;
1563
1569 - context.dwLoggingTlsId = dwLoggingTlsId;
1564 context.hPipe = hPipe;
1565 context.phLock = phLock;
1566 context.pfDisabledAutomaticUpdates = &fDisabledAutomaticUpdates;
@@ -1660,11 +1654,6 @@ static DWORD WINAPI ElevatedChildCacheThreadProc(
1654 BOOL fComInitialized = FALSE;
1655 BURN_PIPE_RESULT result = { };
1656
1663 - if (!::TlsSetValue(pContext->dwLoggingTlsId, pContext->hPipe))
1664 - {
1665 - ExitWithLastError(hr, "Failed to set elevated cache pipe into thread local storage for logging.");
1666 - }
1667 -
1657 // initialize COM
1658 hr = ::CoInitializeEx(NULL, COINIT_MULTITHREADED);
1659 ExitOnFailure(hr, "Failed to initialize COM.");
src/burn/engine/elevation.h
-1
@@ -166,7 +166,6 @@ HRESULT ElevationLaunchApprovedExe(
166
167 // Child (per-machine process) side functions.
168 HRESULT ElevationChildPumpMessages(
169 - __in DWORD dwLoggingTlsId,
169 __in HANDLE hPipe,
170 __in HANDLE hCachePipe,
171 __in BURN_APPROVED_EXES* pApprovedExes,
src/burn/engine/embedded.cpp
+1 -3
@@ -51,7 +51,6 @@ extern "C" HRESULT EmbeddedRunBundle(
51 {
52 HRESULT hr = S_OK;
53 DWORD dwCurrentProcessId = ::GetCurrentProcessId();
54 - HANDLE hCreatedPipesEvent = NULL;
54 LPWSTR sczCommand = NULL;
55 PROCESS_INFORMATION pi = { };
56 BURN_PIPE_RESULT result = { };
@@ -65,7 +64,7 @@ extern "C" HRESULT EmbeddedRunBundle(
64 hr = PipeCreateNameAndSecret(&pConnection->sczName, &pConnection->sczSecret);
65 ExitOnFailure(hr, "Failed to create embedded pipe name and client token.");
66
68 - hr = PipeCreatePipes(pConnection, FALSE, &hCreatedPipesEvent);
67 + hr = PipeCreatePipes(pConnection, FALSE);
68 ExitOnFailure(hr, "Failed to create embedded pipe.");
69
70 hr = StrAllocFormatted(&sczCommand, L"%ls -%ls %ls %ls %u", sczBaseCommand, BURN_COMMANDLINE_SWITCH_EMBEDDED, pConnection->sczName, pConnection->sczSecret, dwCurrentProcessId);
@@ -100,7 +99,6 @@ LExit:
99 ReleaseHandle(pi.hProcess);
100
101 StrSecureZeroFreeString(sczCommand);
103 - ReleaseHandle(hCreatedPipesEvent);
102 PipeConnectionUninitialize(pConnection);
103
104 return hr;
src/burn/engine/engine.cpp
+217 -47
@@ -3,6 +3,15 @@
3 #include "precomp.h"
4
5
6 +typedef struct _REDIRECTED_LOGGING_CONTEXT
7 +{
8 + CRITICAL_SECTION csBuffer;
9 + LPSTR sczBuffer;
10 + HANDLE hPipe;
11 + HANDLE hLogEvent;
12 + HANDLE hFinishedEvent;
13 +} REDIRECTED_LOGGING_CONTEXT;
14 +
15 // constants
16
17 const DWORD RESTART_RETRIES = 10;
@@ -49,6 +58,20 @@ static HRESULT DAPI RedirectLoggingOverPipe(
58 __in_z LPCSTR szString,
59 __in_opt LPVOID pvContext
60 );
61 +static HRESULT LogStringOverPipe(
62 + __in_z LPCSTR szString,
63 + __in HANDLE hPipe
64 + );
65 +static DWORD WINAPI ElevatedLoggingThreadProc(
66 + __in LPVOID lpThreadParameter
67 + );
68 +static HRESULT WaitForElevatedLoggingThread(
69 + __in REDIRECTED_LOGGING_CONTEXT* pContext,
70 + __in HANDLE hLoggingThread
71 + );
72 +static HRESULT WaitForUnelevatedLoggingThread(
73 + __in HANDLE hUnelevatedLoggingThread
74 + );
75 static HRESULT Restart();
76 static void CALLBACK BurnTraceError(
77 __in_z LPCSTR szFile,
@@ -361,7 +384,6 @@ static HRESULT InitializeEngineState(
384 HANDLE hSourceEngineFile = INVALID_HANDLE_VALUE;
385
386 pEngineState->internalCommand.automaticUpdates = BURN_AU_PAUSE_ACTION_IFELEVATED;
364 - pEngineState->dwElevatedLoggingTlsId = TLS_OUT_OF_INDEXES;
387 ::InitializeCriticalSection(&pEngineState->userExperience.csEngineActive);
388 PipeConnectionInitialize(&pEngineState->companionConnection);
389 PipeConnectionInitialize(&pEngineState->embeddedConnection);
@@ -434,11 +456,6 @@ static void UninitializeEngineState(
456 ReleaseStr(pEngineState->log.sczPath);
457 ReleaseStr(pEngineState->log.sczPathVariable);
458
437 - if (TLS_OUT_OF_INDEXES != pEngineState->dwElevatedLoggingTlsId)
438 - {
439 - ::TlsFree(pEngineState->dwElevatedLoggingTlsId);
440 - }
441 -
459 // clear struct
460 memset(pEngineState, 0, sizeof(BURN_ENGINE_STATE));
461 }
@@ -624,6 +641,8 @@ LExit:
641 if (INVALID_HANDLE_VALUE != pEngineState->companionConnection.hPipe)
642 {
643 PipeTerminateChildProcess(&pEngineState->companionConnection, pEngineState->userExperience.dwExitCode, FALSE);
644 +
645 + WaitForUnelevatedLoggingThread(pEngineState->hUnelevatedLoggingThread);
646 }
647
648 // If the splash screen is still around, close it.
@@ -646,6 +665,9 @@ static HRESULT RunElevated(
665 {
666 HRESULT hr = S_OK;
667 HANDLE hLock = NULL;
668 + HANDLE hLoggingThread = NULL;
669 + REDIRECTED_LOGGING_CONTEXT loggingContext = { };
670 + BOOL fDeleteLoggingCs = FALSE;
671
672 // Initialize logging.
673 hr = LoggingOpen(&pEngineState->log, &pEngineState->internalCommand, &pEngineState->command, &pEngineState->variables, pEngineState->registration.sczDisplayName);
@@ -655,20 +677,23 @@ static HRESULT RunElevated(
677 hr = PipeChildConnect(&pEngineState->companionConnection, TRUE);
678 ExitOnFailure(hr, "Failed to connect to unelevated process.");
679
658 - // Set up the thread local storage to store the correct pipe to communicate logging then
680 + // Set up the context for the logging thread then
681 // override logging to write over the pipe.
660 - pEngineState->dwElevatedLoggingTlsId = ::TlsAlloc();
661 - if (TLS_OUT_OF_INDEXES == pEngineState->dwElevatedLoggingTlsId)
662 - {
663 - ExitWithLastError(hr, "Failed to allocate thread local storage for logging.");
664 - }
682 + ::InitializeCriticalSection(&loggingContext.csBuffer);
683 + fDeleteLoggingCs = TRUE;
684
666 - if (!::TlsSetValue(pEngineState->dwElevatedLoggingTlsId, pEngineState->companionConnection.hPipe))
667 - {
668 - ExitWithLastError(hr, "Failed to set elevated pipe into thread local storage for logging.");
669 - }
685 + loggingContext.hLogEvent = ::CreateEventW(NULL, TRUE, FALSE, NULL);
686 + ExitOnNullWithLastError(loggingContext.hLogEvent, hr, "Failed to create log event for logging thread.");
687 +
688 + loggingContext.hFinishedEvent = ::CreateEventW(NULL, TRUE, FALSE, NULL);
689 + ExitOnNullWithLastError(loggingContext.hFinishedEvent, hr, "Failed to create finished event for logging thread.");
690 +
691 + loggingContext.hPipe = pEngineState->companionConnection.hLoggingPipe;
692 +
693 + hLoggingThread = ::CreateThread(NULL, 0, ElevatedLoggingThreadProc, &loggingContext, 0, NULL);
694 + ExitOnNullWithLastError(hLoggingThread, hr, "Failed to create elevated logging thread.");
695
671 - LogRedirect(RedirectLoggingOverPipe, pEngineState);
696 + LogRedirect(RedirectLoggingOverPipe, &loggingContext);
697
698 // Create a top-level window to prevent shutting down the elevated process.
699 hr = UiCreateMessageWindow(hInstance, pEngineState);
@@ -677,16 +702,35 @@ static HRESULT RunElevated(
702 SrpInitialize(TRUE);
703
704 // Pump messages from parent process.
680 - hr = ElevationChildPumpMessages(pEngineState->dwElevatedLoggingTlsId, pEngineState->companionConnection.hPipe, pEngineState->companionConnection.hCachePipe, &pEngineState->approvedExes, &pEngineState->cache, &pEngineState->containers, &pEngineState->packages, &pEngineState->payloads, &pEngineState->variables, &pEngineState->registration, &pEngineState->userExperience, &hLock, &pEngineState->userExperience.dwExitCode, &pEngineState->fRestart, &pEngineState->plan.fApplying);
681 - LogRedirect(NULL, NULL); // reset logging so the next failure gets written to "log buffer" for the failure log.
705 + hr = ElevationChildPumpMessages(pEngineState->companionConnection.hPipe, pEngineState->companionConnection.hCachePipe, &pEngineState->approvedExes, &pEngineState->cache, &pEngineState->containers, &pEngineState->packages, &pEngineState->payloads, &pEngineState->variables, &pEngineState->registration, &pEngineState->userExperience, &hLock, &pEngineState->userExperience.dwExitCode, &pEngineState->fRestart, &pEngineState->plan.fApplying);
706 ExitOnFailure(hr, "Failed to pump messages from parent process.");
707
708 + WaitForElevatedLoggingThread(&loggingContext, hLoggingThread);
709 +
710 LExit:
711 + ReleaseHandle(hLoggingThread);
712 +
713 LogRedirect(NULL, NULL); // we're done talking to the child so always reset logging now.
714
715 // If the message window is still around, close it.
716 UiCloseMessageWindow(pEngineState);
717
718 + if (fDeleteLoggingCs)
719 + {
720 + ::DeleteCriticalSection(&loggingContext.csBuffer);
721 + }
722 +
723 + ReleaseHandle(loggingContext.hLogEvent);
724 + ReleaseHandle(loggingContext.hFinishedEvent);
725 +
726 + // If there was a log message left, try to log it locally.
727 + if (loggingContext.sczBuffer)
728 + {
729 + LogStringWorkRaw(loggingContext.sczBuffer);
730 +
731 + ReleaseStr(loggingContext.sczBuffer);
732 + }
733 +
734 if (hLock)
735 {
736 ::ReleaseMutex(hLock);
@@ -883,54 +927,180 @@ static HRESULT DAPI RedirectLoggingOverPipe(
927 __in_opt LPVOID pvContext
928 )
929 {
886 - static BOOL s_fCurrentlyLoggingToPipe = FALSE;
930 + HRESULT hr = S_OK;
931 + REDIRECTED_LOGGING_CONTEXT* pContext = static_cast<REDIRECTED_LOGGING_CONTEXT*>(pvContext);
932 +
933 + ::EnterCriticalSection(&pContext->csBuffer);
934 +
935 + hr = StrAnsiAllocConcat(&pContext->sczBuffer, szString, 0);
936 +
937 + if (SUCCEEDED(hr) && !::SetEvent(pContext->hLogEvent))
938 + {
939 + HRESULT hrSet = HRESULT_FROM_WIN32(::GetLastError());
940 + if (FAILED(hrSet))
941 + {
942 + TraceError(hrSet, "Failed to set log event.");
943 + }
944 + }
945 +
946 + ::LeaveCriticalSection(&pContext->csBuffer);
947
948 + return hr;
949 +}
950 +
951 +static HRESULT LogStringOverPipe(
952 + __in_z LPCSTR szString,
953 + __in HANDLE hPipe
954 + )
955 +{
956 HRESULT hr = S_OK;
889 - BURN_ENGINE_STATE* pEngineState = static_cast<BURN_ENGINE_STATE*>(pvContext);
890 - BOOL fStartedLogging = FALSE;
891 - HANDLE hPipe = INVALID_HANDLE_VALUE;
957 BYTE* pbData = NULL;
958 SIZE_T cbData = 0;
959 DWORD dwResult = 0;
960
896 - // Prevent this function from being called recursively.
897 - if (s_fCurrentlyLoggingToPipe)
898 - {
899 - ExitFunction();
900 - }
961 + hr = BuffWriteStringAnsi(&pbData, &cbData, szString);
962 + ExitOnFailure(hr, "Failed to prepare logging pipe message.");
963 +
964 + hr = PipeSendMessage(hPipe, static_cast<DWORD>(BURN_PIPE_MESSAGE_TYPE_LOG), pbData, cbData, NULL, NULL, &dwResult);
965 + ExitOnFailure(hr, "Failed to send logging message over the pipe.");
966 +
967 + hr = (HRESULT)dwResult;
968 +
969 +LExit:
970 + ReleaseBuffer(pbData);
971
902 - s_fCurrentlyLoggingToPipe = TRUE;
903 - fStartedLogging = TRUE;
972 + return hr;
973 +}
974 +
975 +static DWORD WINAPI ElevatedLoggingThreadProc(
976 + __in LPVOID lpThreadParameter
977 + )
978 +{
979 + HRESULT hr = S_OK;
980 + DWORD dwLastError = ERROR_SUCCESS;
981 + REDIRECTED_LOGGING_CONTEXT* pContext = static_cast<REDIRECTED_LOGGING_CONTEXT*>(lpThreadParameter);
982 + DWORD dwSignaledIndex = 0;
983 + LPSTR sczBuffer = NULL;
984 + BURN_PIPE_RESULT result = { };
985 + HANDLE rghEvents[2] =
986 + {
987 + pContext->hLogEvent,
988 + pContext->hFinishedEvent,
989 + };
990
905 - // Make sure the current thread set the pipe in TLS.
906 - hPipe = ::TlsGetValue(pEngineState->dwElevatedLoggingTlsId);
907 - if (!hPipe || INVALID_HANDLE_VALUE == hPipe)
991 + for (;;)
992 {
909 - hr = HRESULT_FROM_WIN32(ERROR_PIPE_NOT_CONNECTED);
910 - ExitFunction();
993 + hr = AppWaitForMultipleObjects(countof(rghEvents), rghEvents, FALSE, INFINITE, &dwSignaledIndex);
994 + if (FAILED(hr))
995 + {
996 + LogRedirect(NULL, NULL); // reset logging so the next failure gets written locally.
997 + ExitOnFailure(hr, "Failed to wait for log thread events, signaled: %u.", dwSignaledIndex);
998 + }
999 +
1000 + if (1 == dwSignaledIndex)
1001 + {
1002 + LogRedirect(NULL, NULL); // No more messages will be logged over the pipe.
1003 + }
1004 +
1005 + dwLastError = ERROR_SUCCESS;
1006 +
1007 + ::EnterCriticalSection(&pContext->csBuffer);
1008 +
1009 + sczBuffer = pContext->sczBuffer;
1010 + pContext->sczBuffer = NULL;
1011 +
1012 + if (0 == dwSignaledIndex && !::ResetEvent(rghEvents[0]))
1013 + {
1014 + dwLastError = ::GetLastError();
1015 + }
1016 +
1017 + ::LeaveCriticalSection(&pContext->csBuffer);
1018 +
1019 + if (ERROR_SUCCESS != dwLastError)
1020 + {
1021 + LogRedirect(NULL, NULL); // reset logging so the next failure gets written locally.
1022 + ExitOnWin32Error(dwLastError, hr, "Failed to reset log event.");
1023 + }
1024 +
1025 + if (sczBuffer)
1026 + {
1027 + hr = LogStringOverPipe(sczBuffer, pContext->hPipe);
1028 + if (FAILED(hr))
1029 + {
1030 + LogRedirect(NULL, NULL); // reset logging so the next failure gets written locally.
1031 + ExitOnFailure(hr, "Failed to wait log message over pipe.");
1032 + }
1033 +
1034 + ReleaseStr(sczBuffer);
1035 + }
1036 +
1037 + if (1 == dwSignaledIndex)
1038 + {
1039 + break;
1040 + }
1041 }
1042
913 - // Do not log or use ExitOnFailure() macro here because they will be discarded
914 - // by the recursive block at the top of this function.
915 - hr = BuffWriteStringAnsi(&pbData, &cbData, szString);
916 - if (SUCCEEDED(hr))
1043 +LExit:
1044 + LogRedirect(NULL, NULL); // No more messages will be logged over the pipe.
1045 +
1046 {
918 - hr = PipeSendMessage(hPipe, static_cast<DWORD>(BURN_PIPE_MESSAGE_TYPE_LOG), pbData, cbData, NULL, NULL, &dwResult);
919 - if (SUCCEEDED(hr))
1047 + HRESULT hrTerminate = PipeTerminateLoggingPipe(pContext->hPipe, hr);
1048 + if (FAILED(hrTerminate))
1049 {
921 - hr = (HRESULT)dwResult;
1050 + TraceError(hrTerminate, "Failed to terminate logging pipe.");
1051 }
1052 }
1053
925 -LExit:
926 - ReleaseBuffer(pbData);
1054 + // Log the message locally if it failed to go over the pipe.
1055 + if (sczBuffer)
1056 + {
1057 + LogStringWorkRaw(sczBuffer);
1058 +
1059 + ReleaseStr(sczBuffer);
1060 + }
1061 +
1062 + // Log any remaining message locally.
1063 + if (pContext->sczBuffer)
1064 + {
1065 + AssertSz(FAILED(hr), "Exiting logging thread on success even though there was a leftover message");
1066 + LogStringWorkRaw(pContext->sczBuffer);
1067 +
1068 + ReleaseStr(pContext->sczBuffer);
1069 + }
1070 +
1071 + return (DWORD)hr;
1072 +}
1073 +
1074 +static HRESULT WaitForElevatedLoggingThread(
1075 + __in REDIRECTED_LOGGING_CONTEXT* pContext,
1076 + __in HANDLE hLoggingThread
1077 + )
1078 +{
1079 + HRESULT hr = S_OK;
1080
928 - // We started logging so remember to say we are no longer logging.
929 - if (fStartedLogging)
1081 + if (!::SetEvent(pContext->hFinishedEvent))
1082 {
931 - s_fCurrentlyLoggingToPipe = FALSE;
1083 + ExitWithLastError(hr, "Failed to set log finished event.");
1084 }
1085
1086 + hr = AppWaitForSingleObject(hLoggingThread, 5 * 60 * 1000); // TODO: is 5 minutes good?
1087 + ExitOnFailure(hr, "Failed to wait for elevated logging thread.");
1088 +
1089 +LExit:
1090 + return hr;
1091 +}
1092 +
1093 +static HRESULT WaitForUnelevatedLoggingThread(
1094 + __in HANDLE hUnelevatedLoggingThread
1095 + )
1096 +{
1097 + HRESULT hr = S_OK;
1098 +
1099 + // Give the thread 15 seconds to exit.
1100 + hr = AppWaitForSingleObject(hUnelevatedLoggingThread, 15 * 1000);
1101 + ExitOnFailure(hr, "Failed to wait for unelevated logging thread.");
1102 +
1103 +LExit:
1104 return hr;
1105 }
1106
src/burn/engine/pipe.cpp
+73 -18
@@ -8,6 +8,7 @@ static const DWORD PIPE_RETRY_FOR_CONNECTION = 1800; // for up to 3 minutes.
8
9 static const LPCWSTR PIPE_NAME_FORMAT_STRING = L"\\\\.\\pipe\\%ls";
10 static const LPCWSTR CACHE_PIPE_NAME_FORMAT_STRING = L"\\\\.\\pipe\\%ls.Cache";
11 +static const LPCWSTR LOGGING_PIPE_NAME_FORMAT_STRING = L"\\\\.\\pipe\\%ls.Log";
12
13 static HRESULT AllocatePipeMessage(
14 __in DWORD dwMessage,
@@ -48,6 +49,7 @@ void PipeConnectionInitialize(
49 memset(pConnection, 0, sizeof(BURN_PIPE_CONNECTION));
50 pConnection->hPipe = INVALID_HANDLE_VALUE;
51 pConnection->hCachePipe = INVALID_HANDLE_VALUE;
52 + pConnection->hLoggingPipe = INVALID_HANDLE_VALUE;
53 }
54
55 /*******************************************************************
@@ -58,15 +60,14 @@ void PipeConnectionUninitialize(
60 __in BURN_PIPE_CONNECTION* pConnection
61 )
62 {
63 + ReleaseFileHandle(pConnection->hLoggingPipe);
64 ReleaseFileHandle(pConnection->hCachePipe);
65 ReleaseFileHandle(pConnection->hPipe);
66 ReleaseHandle(pConnection->hProcess);
67 ReleaseStr(pConnection->sczSecret);
68 ReleaseStr(pConnection->sczName);
69
67 - memset(pConnection, 0, sizeof(BURN_PIPE_CONNECTION));
68 - pConnection->hPipe = INVALID_HANDLE_VALUE;
69 - pConnection->hCachePipe = INVALID_HANDLE_VALUE;
70 + PipeConnectionInitialize(pConnection);
71 }
72
73 /*******************************************************************
@@ -235,13 +236,13 @@ LExit:
236 *******************************************************************/
237 extern "C" HRESULT PipeCreatePipes(
238 __in BURN_PIPE_CONNECTION* pConnection,
238 - __in BOOL fCreateCachePipe,
239 - __out HANDLE* phEvent
239 + __in BOOL fCompanion
240 )
241 {
242 Assert(pConnection->sczName);
243 Assert(INVALID_HANDLE_VALUE == pConnection->hPipe);
244 Assert(INVALID_HANDLE_VALUE == pConnection->hCachePipe);
245 + Assert(INVALID_HANDLE_VALUE == pConnection->hLoggingPipe);
246
247 HRESULT hr = S_OK;
248 PSECURITY_DESCRIPTOR psd = NULL;
@@ -249,10 +250,10 @@ extern "C" HRESULT PipeCreatePipes(
250 LPWSTR sczFullPipeName = NULL;
251 HANDLE hPipe = INVALID_HANDLE_VALUE;
252 HANDLE hCachePipe = INVALID_HANDLE_VALUE;
253 + HANDLE hLoggingPipe = INVALID_HANDLE_VALUE;
254
253 - // Only the grant special rights when the pipe is being used for "embedded"
254 - // scenarios (aka: there is no cache pipe).
255 - if (!fCreateCachePipe)
255 + // Only grant special rights when the pipe is being used for "embedded" scenarios.
256 + if (!fCompanion)
257 {
258 // Create the security descriptor that grants read/write/sync access to Everyone.
259 // TODO: consider locking down "WD" to LogonIds (logon session)
@@ -278,7 +279,7 @@ extern "C" HRESULT PipeCreatePipes(
279 ExitWithLastError(hr, "Failed to create pipe: %ls", sczFullPipeName);
280 }
281
281 - if (fCreateCachePipe)
282 + if (fCompanion)
283 {
284 // Create the cache pipe.
285 hr = StrAllocFormatted(&sczFullPipeName, CACHE_PIPE_NAME_FORMAT_STRING, pConnection->sczName);
@@ -287,20 +288,31 @@ extern "C" HRESULT PipeCreatePipes(
288 hCachePipe = ::CreateNamedPipeW(sczFullPipeName, PIPE_ACCESS_DUPLEX | FILE_FLAG_FIRST_PIPE_INSTANCE, PIPE_TYPE_BYTE | PIPE_READMODE_BYTE | PIPE_WAIT, 1, PIPE_64KB, PIPE_64KB, 1, NULL);
289 if (INVALID_HANDLE_VALUE == hCachePipe)
290 {
290 - ExitWithLastError(hr, "Failed to create pipe: %ls", sczFullPipeName);
291 + ExitWithLastError(hr, "Failed to create cache pipe: %ls", sczFullPipeName);
292 + }
293 +
294 + // Create the logging pipe.
295 + hr = StrAllocFormatted(&sczFullPipeName, LOGGING_PIPE_NAME_FORMAT_STRING, pConnection->sczName);
296 + ExitOnFailure(hr, "Failed to allocate full name of logging pipe: %ls", pConnection->sczName);
297 +
298 + hLoggingPipe = ::CreateNamedPipeW(sczFullPipeName, PIPE_ACCESS_DUPLEX | FILE_FLAG_FIRST_PIPE_INSTANCE, PIPE_TYPE_BYTE | PIPE_READMODE_BYTE | PIPE_WAIT, 1, PIPE_64KB, PIPE_64KB, 1, NULL);
299 + if (INVALID_HANDLE_VALUE == hLoggingPipe)
300 + {
301 + ExitWithLastError(hr, "Failed to create logging pipe: %ls", sczFullPipeName);
302 }
303 }
304
305 + pConnection->hLoggingPipe = hLoggingPipe;
306 + hLoggingPipe = INVALID_HANDLE_VALUE;
307 +
308 pConnection->hCachePipe = hCachePipe;
309 hCachePipe = INVALID_HANDLE_VALUE;
310
311 pConnection->hPipe = hPipe;
312 hPipe = INVALID_HANDLE_VALUE;
313
300 - // TODO: remove the following
301 - *phEvent = NULL;
302 -
314 LExit:
315 + ReleaseFileHandle(hLoggingPipe);
316 ReleaseFileHandle(hCachePipe);
317 ReleaseFileHandle(hPipe);
318 ReleaseStr(sczFullPipeName);
@@ -322,7 +334,7 @@ extern "C" HRESULT PipeWaitForChildConnect(
334 )
335 {
336 HRESULT hr = S_OK;
325 - HANDLE hPipes[2] = { pConnection->hPipe, pConnection->hCachePipe};
337 + HANDLE hPipes[3] = { pConnection->hPipe, pConnection->hCachePipe, pConnection->hLoggingPipe};
338 LPCWSTR wzSecret = pConnection->sczSecret;
339 DWORD cbSecret = lstrlenW(wzSecret) * sizeof(WCHAR);
340 DWORD dwCurrentProcessId = ::GetCurrentProcessId();
@@ -409,6 +421,32 @@ LExit:
421 return hr;
422 }
423
424 +/*******************************************************************
425 + PipeTerminateLoggingPipe -
426 +
427 +*******************************************************************/
428 +extern "C" HRESULT PipeTerminateLoggingPipe(
429 + __in HANDLE hLoggingPipe,
430 + __in DWORD dwParentExitCode
431 + )
432 +{
433 + HRESULT hr = S_OK;
434 + BYTE* pbData = NULL;
435 + SIZE_T cbData = 0;
436 +
437 + // Prepare the exit message.
438 + hr = BuffWriteNumber(&pbData, &cbData, dwParentExitCode);
439 + ExitOnFailure(hr, "Failed to write exit code to message buffer.");
440 +
441 + hr = WritePipeMessage(hLoggingPipe, static_cast<DWORD>(BURN_PIPE_MESSAGE_TYPE_COMPLETE), pbData, cbData);
442 + ExitOnFailure(hr, "Failed to post complete message to logging pipe.");
443 +
444 +LExit:
445 + ReleaseBuffer(pbData);
446 +
447 + return hr;
448 +}
449 +
450 /*******************************************************************
451 PipeTerminateChildProcess -
452
@@ -468,6 +506,8 @@ extern "C" HRESULT PipeTerminateChildProcess(
506 #endif
507
508 LExit:
509 + ReleaseBuffer(pbData);
510 +
511 return hr;
512 }
513
@@ -478,7 +518,7 @@ LExit:
518 *******************************************************************/
519 extern "C" HRESULT PipeChildConnect(
520 __in BURN_PIPE_CONNECTION* pConnection,
481 - __in BOOL fConnectCachePipe
521 + __in BOOL fCompanion
522 )
523 {
524 Assert(pConnection->sczName);
@@ -486,6 +526,7 @@ extern "C" HRESULT PipeChildConnect(
526 Assert(!pConnection->hProcess);
527 Assert(INVALID_HANDLE_VALUE == pConnection->hPipe);
528 Assert(INVALID_HANDLE_VALUE == pConnection->hCachePipe);
529 + Assert(INVALID_HANDLE_VALUE == pConnection->hLoggingPipe);
530
531 HRESULT hr = S_OK;
532 LPWSTR sczPipeName = NULL;
@@ -519,7 +560,7 @@ extern "C" HRESULT PipeChildConnect(
560 hr = ChildPipeConnected(pConnection->hPipe, pConnection->sczSecret, &pConnection->dwProcessId);
561 ExitOnFailure(hr, "Failed to verify parent pipe: %ls", sczPipeName);
562
522 - if (fConnectCachePipe)
563 + if (fCompanion)
564 {
565 // Connect to the parent for the cache pipe.
566 hr = StrAllocFormatted(&sczPipeName, CACHE_PIPE_NAME_FORMAT_STRING, pConnection->sczName);
@@ -528,12 +569,26 @@ extern "C" HRESULT PipeChildConnect(
569 pConnection->hCachePipe = ::CreateFileW(sczPipeName, GENERIC_READ | GENERIC_WRITE, 0, NULL, OPEN_EXISTING, 0, NULL);
570 if (INVALID_HANDLE_VALUE == pConnection->hCachePipe)
571 {
531 - ExitWithLastError(hr, "Failed to open parent pipe: %ls", sczPipeName)
572 + ExitWithLastError(hr, "Failed to open parent cache pipe: %ls", sczPipeName)
573 }
574
575 // Verify the parent and notify it that the child connected.
576 hr = ChildPipeConnected(pConnection->hCachePipe, pConnection->sczSecret, &pConnection->dwProcessId);
536 - ExitOnFailure(hr, "Failed to verify parent pipe: %ls", sczPipeName);
577 + ExitOnFailure(hr, "Failed to verify parent cache pipe: %ls", sczPipeName);
578 +
579 + // Connect to the parent for the logging pipe.
580 + hr = StrAllocFormatted(&sczPipeName, LOGGING_PIPE_NAME_FORMAT_STRING, pConnection->sczName);
581 + ExitOnFailure(hr, "Failed to allocate name of parent logging pipe.");
582 +
583 + pConnection->hLoggingPipe = ::CreateFileW(sczPipeName, GENERIC_READ | GENERIC_WRITE, 0, NULL, OPEN_EXISTING, 0, NULL);
584 + if (INVALID_HANDLE_VALUE == pConnection->hLoggingPipe)
585 + {
586 + ExitWithLastError(hr, "Failed to open parent logging pipe: %ls", sczPipeName)
587 + }
588 +
589 + // Verify the parent and notify it that the child connected.
590 + hr = ChildPipeConnected(pConnection->hLoggingPipe, pConnection->sczSecret, &pConnection->dwProcessId);
591 + ExitOnFailure(hr, "Failed to verify parent logging pipe: %ls", sczPipeName);
592 }
593
594 pConnection->hProcess = ::OpenProcess(SYNCHRONIZE, FALSE, pConnection->dwProcessId);
src/burn/engine/pipe.h
+7 -3
@@ -15,6 +15,7 @@ typedef struct _BURN_PIPE_CONNECTION
15 HANDLE hProcess;
16 HANDLE hPipe;
17 HANDLE hCachePipe;
18 + HANDLE hLoggingPipe;
19 } BURN_PIPE_CONNECTION;
20
21 typedef enum _BURN_PIPE_MESSAGE_TYPE : DWORD
@@ -77,12 +78,15 @@ HRESULT PipeCreateNameAndSecret(
78 );
79 HRESULT PipeCreatePipes(
80 __in BURN_PIPE_CONNECTION* pConnection,
80 - __in BOOL fCreateCachePipe,
81 - __out HANDLE* phEvent
81 + __in BOOL fCompanion
82 );
83 HRESULT PipeWaitForChildConnect(
84 __in BURN_PIPE_CONNECTION* pConnection
85 );
86 +HRESULT PipeTerminateLoggingPipe(
87 + __in HANDLE hLoggingPipe,
88 + __in DWORD dwParentExitCode
89 + );
90 HRESULT PipeTerminateChildProcess(
91 __in BURN_PIPE_CONNECTION* pConnection,
92 __in DWORD dwParentExitCode,
@@ -92,7 +96,7 @@ HRESULT PipeTerminateChildProcess(
96 // Child functions.
97 HRESULT PipeChildConnect(
98 __in BURN_PIPE_CONNECTION* pConnection,
95 - __in BOOL fConnectCachePipe
99 + __in BOOL fCompanion
100 );
101
102 #ifdef __cplusplus
src/burn/engine/uithread.cpp
-12
@@ -107,18 +107,6 @@ static DWORD WINAPI ThreadProc(
107 BURN_ENGINE_STATE* pEngineState = pContext->pEngineState;
108 BOOL fElevatedEngine = BURN_MODE_ELEVATED == pContext->pEngineState->internalCommand.mode;
109
110 - // If elevated, set up the thread local storage to store the correct pipe to communicate logging.
111 - if (fElevatedEngine)
112 - {
113 - Assert(TLS_OUT_OF_INDEXES != pEngineState->dwElevatedLoggingTlsId);
114 -
115 - if (!::TlsSetValue(pEngineState->dwElevatedLoggingTlsId, pEngineState->companionConnection.hPipe))
116 - {
117 - // If the function failed we cannot write to the pipe so just terminate.
118 - ExitFunction1(hr = E_INVALIDSTATE);
119 - }
120 - }
121 -
110 wc.lpfnWndProc = WndProc;
111 wc.hInstance = pContext->hInstance;
112 wc.lpszClassName = BURN_UITHREAD_CLASS_WINDOW;
src/libs/dutil/WixToolset.DUtil/logutil.cpp
+4
@@ -222,8 +222,12 @@ void DAPI LogRedirect(
222 __in_opt LPVOID pvContext
223 )
224 {
225 + ::EnterCriticalSection(&LogUtil_csLog);
226 +
227 s_vpfLogStringWorkRaw = vpfLogStringWorkRaw;
228 s_vpvLogStringWorkRawContext = pvContext;
229 +
230 + ::LeaveCriticalSection(&LogUtil_csLog);
231 }
232
233
src/test/burn/WixToolsetTest.BurnE2E/FilesInUseTests.cs
+1 -1
@@ -34,7 +34,7 @@ namespace WixToolsetTest.BurnE2E
34 packageA.VerifyInstalled(false);
35 }
36
37 - [RuntimeFact]
37 + [LongRuntimeFact]
38 public void WixStdBAFailsWithLockedFile()
39 {
40 var packageA = this.CreatePackageInstaller("PackageA");
src/test/burn/WixToolsetTest.BurnE2E/LongPathTests.cs
+5
@@ -284,6 +284,11 @@ namespace WixToolsetTest.BurnE2E
284 {
285 WixAssert.Skip($"MAX_PATH is being enforced ({baseFolder})");
286 }
287 + else if (lastError == 3)
288 + {
289 + // TODO: figure out why Windows Sandbox returns this error instead of 206 like all other environments.
290 + WixAssert.Skip($"The system cannot find the path specified ({baseFolder})");
291 + }
292 throw new Win32Exception(lastError);
293 }
294 }