Fix to unblock Event Log failure in runtime:4.8-windowsservercore-lts…

…c2019 alt (#159)

Fix to unblock Event Log monitoring failure in ltcs2019 image

LogMonitor/src/LogMonitor/EventMonitor.cpp

@@ -597,20 +597,107 @@ EventMonitor::PrintEvent(
 void
 EventMonitor::EnableEventLogChannels()
 {
-    for (const auto& eventChannel : m_eventChannels)
-    {
-        EnableEventLogChannel(eventChannel.Name.c_str());
+    for (const auto& eventChannel : m_eventChannels) {
+        DWORD status = EnableEventLogChannel(eventChannel.Name.c_str());
+
+        if (status == RPC_S_SERVER_UNAVAILABLE) {
+            HANDLE timerEvent = CreateWaitableTimer(NULL, FALSE, NULL);
+
+            if (!timerEvent) {
+            status = GetLastError();
+            logWriter.TraceError(
+                Utility::FormatString(
+                    L"Failed to create timer object.", status).c_str());
+            break;
+            }
+
+            std::double_t waitInSeconds = 300;
+
+            int elapsedTime = 0;
+
+            const int eventsCount = 2;
+            HANDLE channelEnableEvents[eventsCount] = {m_stopEvent, timerEvent};
+
+            while (elapsedTime < waitInSeconds) {
+                int waitInterval = Utility::GetWaitInterval(waitInSeconds, elapsedTime);
+                LARGE_INTEGER timeToWait = Utility::ConvertWaitIntervalToLargeInt(waitInterval);
+                BOOL waitableTimer = SetWaitableTimer(timerEvent, &timeToWait, 0, NULL, NULL, 0);
+                if (!waitableTimer) {
+                    status = GetLastError();
+                    logWriter.TraceError(
+                        Utility::FormatString(
+                            L"Failed to set timer object to enable %s event channel. Error: %lu",
+                            eventChannel.Name.c_str(),
+                            status).c_str());
+                    break;
+                }
+
+                DWORD wait = WaitForMultipleObjects(eventsCount, channelEnableEvents, FALSE, INFINITE);
+                switch (wait) {
+                    case WAIT_OBJECT_0:
+                    {
+                        //
+                        // The process is exiting. Stop the timer and return.
+                        //
+                        CancelWaitableTimer(timerEvent);
+                        CloseHandle(timerEvent);
+                    }
+
+                    case WAIT_OBJECT_0 + 1:
+                    {
+                        //
+                        // Timer event. Retry enabling the failing channel.
+                        //
+                        break;
+                    }
+
+                    default:
+                    {
+                        //
+                        // Wait failed, return the failure.
+                        //
+                        status = GetLastError();
+
+                        logWriter.TraceError(
+                            Utility::FormatString(
+                                L"Failed to enable event channel. Channel: %ws Error: 0x%X",
+                                eventChannel.Name.c_str(), status).c_str());
+
+                        CancelWaitableTimer(timerEvent);
+                        CloseHandle(timerEvent);
+                    }
+                }
+
+                DWORD status = EnableEventLogChannel(eventChannel.Name.c_str());
+
+                if (status == RPC_S_SERVER_UNAVAILABLE) {
+                    elapsedTime += Utility::WAIT_INTERVAL;
+                } else {
+                    logWriter.TraceInfo(
+                        Utility::FormatString(
+                            L"Enabled %s event channel after %d seconds.",
+                            eventChannel.Name.c_str(),
+                            elapsedTime).c_str() );
+                    status = ERROR_SUCCESS;
+                    break;
+                }
+            }
+
+            CancelWaitableTimer(timerEvent);
+            CloseHandle(timerEvent);
+        }
     }
 }
 
 
+
 /// Enables or disables an Event Log channel.
 ///
 /// \param ChannelPath  Full path to the event log channel.
 ///
 /// \return None
 ///
-void
+DWORD
 EventMonitor::EnableEventLogChannel(
     _In_ LPCWSTR ChannelPath
     )
@@ -624,8 +711,7 @@ EventMonitor::EnableEventLogChannel(
     // Open the channel configuration.
     //
     channelConfig = EvtOpenChannelConfig(NULL, ChannelPath, 0);
-    if (NULL == channelConfig)
-    {
+    if (NULL == channelConfig) {
         status = GetLastError();
         goto Exit;
     }
@@ -635,26 +721,20 @@ EventMonitor::EnableEventLogChannel(
         0,
         sizeof(EVT_VARIANT),
         &propValue,
-        &dwPropValSize))
-    {
+        &dwPropValSize)) {
         //
         // Return if event channel is already enabled.
         //
-        if (propValue.BooleanVal)
-        {
+        if (propValue.BooleanVal) {
             goto Exit;
         }
-    }
-    else
-    {
+    } else {
         status = GetLastError();
         logWriter.TraceError(
             Utility::FormatString(
                 L"Failed to query event channel configuration. Channel: %ws Error: 0x%X",
                 ChannelPath,
-                status
-            ).c_str()
-        );
+                status).c_str());
     }
 
     //
@@ -668,28 +748,22 @@ EventMonitor::EnableEventLogChannel(
         channelConfig,
         EvtChannelConfigEnabled,
         0,
-        &propValue
-    ))
-    {
+        &propValue)) {
         status = GetLastError();
         goto Exit;
     }
 
     //
     // Save changes.
     //
-    if (!EvtSaveChannelConfig(channelConfig, 0))
-    {
+    if (!EvtSaveChannelConfig(channelConfig, 0)) {
         status = GetLastError();
-        if (status == ERROR_EVT_INVALID_OPERATION_OVER_ENABLED_DIRECT_CHANNEL)
-        {
+        if (status == ERROR_EVT_INVALID_OPERATION_OVER_ENABLED_DIRECT_CHANNEL) {
             //
             // The channel is already enabled.
             //
             status = ERROR_SUCCESS;
-        }
-        else
-        {
+        } else {
             goto Exit;
         }
     }
@@ -698,15 +772,15 @@ EventMonitor::EnableEventLogChannel(
 
 Exit:
 
-    if (ERROR_SUCCESS != status)
-    {
-        logWriter.TraceError(
-            Utility::FormatString(L"Failed to enable event channel %ws: 0x%X", ChannelPath, status).c_str()
-        );
+    if (ERROR_SUCCESS != status) {
+        logWriter.TraceInfo(
+            Utility::FormatString(L"Waiting for %ws event channel to be enabled",
+            ChannelPath).c_str());
     }
 
-    if (channelConfig != NULL)
-    {
+    if (channelConfig != NULL) {
         EvtClose(channelConfig);
     }
+
+    return status;
 }

LogMonitor/src/LogMonitor/EventMonitor.h

@@ -8,6 +8,7 @@
 class EventMonitor final
 {
 public:
+
     EventMonitor() = delete;
 
     EventMonitor(
@@ -56,7 +57,9 @@ class EventMonitor final
         _In_ const HANDLE& EventHandle
         );
 
+
     void EnableEventLogChannels();
 
-    static void EnableEventLogChannel(_In_ LPCWSTR ChannelPath);
+    static DWORD EnableEventLogChannel(
+        _In_ LPCWSTR ChannelPath);
 };

LogMonitor/src/LogMonitor/FileMonitor/FileMonitorUtilities.cpp

@@ -7,7 +7,7 @@
 #include <regex>
 
 /**
- * Warapper around Create Event API
+ * Wrapper around Create Event API
  *
  * @param bManualReset
  * @param bInitialState
@@ -64,7 +64,7 @@ HANDLE FileMonitorUtilities::GetLogDirHandle(
         //
         // Log directory is not created yet. Keep retrying every
         // 15 seconds for upto five minutes. Also start reading the
-        // log files from the begining, instead of current end of
+        // log files from the beginning, instead of current end of
         // file.
         //
         HANDLE timerEvent = CreateWaitableTimer(NULL, FALSE, NULL);
@@ -128,8 +128,8 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
 
     while (FileMonitorUtilities::_IsFileErrorStatus(status) && elapsedTime < waitInSeconds)
     {
-        int waitInterval = FileMonitorUtilities::_GetWaitInterval(waitInSeconds, elapsedTime);
-        LARGE_INTEGER timeToWait = FileMonitorUtilities::_ConvertWaitIntervalToLargeInt(waitInterval);
+        int waitInterval = Utility::GetWaitInterval(waitInSeconds, elapsedTime);
+        LARGE_INTEGER timeToWait = Utility::ConvertWaitIntervalToLargeInt(waitInterval);
 
         BOOL waitableTimer = SetWaitableTimer(timerEvent, &timeToWait, 0, NULL, NULL, 0);
         if (!waitableTimer)
@@ -191,7 +191,7 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
         if (logDirHandle == INVALID_HANDLE_VALUE)
         {
             status = GetLastError();
-            elapsedTime += WAIT_INTERVAL;
+            elapsedTime += Utility::WAIT_INTERVAL;
         }
         else
         {
@@ -207,33 +207,6 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
     return logDirHandle;
 }
 
-// Converts the time to wait to a large integer
-LARGE_INTEGER FileMonitorUtilities::_ConvertWaitIntervalToLargeInt(int timeInterval)
-{
-    LARGE_INTEGER liDueTime{};
-
-    int millisecondsToWait = timeInterval * 1000;
-    liDueTime.QuadPart = -millisecondsToWait * 10000LL; // wait time in 100 nanoseconds
-    return liDueTime;
-}
-
-// Returns the time (in seconds) to wait based on the specified waitInSeconds
-int FileMonitorUtilities::_GetWaitInterval(std::double_t waitInSeconds, int elapsedTime)
-{
-    if (isinf(waitInSeconds))
-    {
-        return int(WAIT_INTERVAL);
-    }
-
-    if (waitInSeconds < WAIT_INTERVAL)
-    {
-        return int(waitInSeconds);
-    }
-
-    const auto remainingTime = int(waitInSeconds - elapsedTime);
-    return remainingTime <= WAIT_INTERVAL ? remainingTime : WAIT_INTERVAL;
-}
-
 bool FileMonitorUtilities::_IsFileErrorStatus(DWORD status)
 {
     return status == ERROR_FILE_NOT_FOUND || status == ERROR_PATH_NOT_FOUND;

LogMonitor/src/LogMonitor/FileMonitor/FileMonitorUtilities.h

@@ -8,7 +8,6 @@
 class FileMonitorUtilities final
 {
     public:
-        static const int WAIT_INTERVAL = 15;
 
         static HANDLE CreateFileMonitorEvent(
             _In_ BOOL bManualReset,
@@ -32,13 +31,6 @@ class FileMonitorUtilities final
             HANDLE stopEvent,
             HANDLE timerEvent);
 
-        static LARGE_INTEGER _ConvertWaitIntervalToLargeInt(
-            int timeInterval);
-
-        static int _GetWaitInterval(
-            std::double_t waitInSeconds,
-            int elapsedTime);
-
         static bool _IsFileErrorStatus(DWORD status);
 
         static std::wstring _GetWaitLogMessage(

LogMonitor/src/LogMonitor/LogFileMonitor.cpp

@@ -340,7 +340,7 @@ LogFileMonitor::StartLogFileMonitor()
     {
         m_readLogFilesFromStart = true;
     }
-
+ 
     m_logDirHandle = logDirHandle;
 
     //

LogMonitor/src/LogMonitor/Utility.cpp

@@ -312,3 +312,34 @@ bool Utility::ConfigAttributeExists(AttributesMap& Attributes, std::wstring attr
     auto it = Attributes.find(attributeName);
     return it != Attributes.end() && it->second != nullptr;
 }
+
+///
+// Converts the time to wait to a large integer
+///
+LARGE_INTEGER Utility::ConvertWaitIntervalToLargeInt(_In_ int timeInterval)
+{
+    LARGE_INTEGER liDueTime{};
+
+    int millisecondsToWait = timeInterval * 1000;
+    liDueTime.QuadPart = -millisecondsToWait * 10000LL;  // wait time in 100 nanoseconds
+    return liDueTime;
+}
+
+///
+/// Returns the time (in seconds) to wait based on the specified waitInSeconds
+///
+int Utility::GetWaitInterval(_In_ std::double_t waitInSeconds, _In_ int elapsedTime)
+{
+    if (isinf(waitInSeconds))
+    {
+        return static_cast<int>(WAIT_INTERVAL);
+    }
+
+    if (waitInSeconds < WAIT_INTERVAL)
+    {
+        return static_cast<int>(waitInSeconds);
+    }
+
+    const auto remainingTime = static_cast<int>(waitInSeconds - elapsedTime);
+    return remainingTime <= WAIT_INTERVAL ? remainingTime : WAIT_INTERVAL;
+}

LogMonitor/src/LogMonitor/Utility.h

@@ -21,6 +21,9 @@ typedef std::map<std::wstring, void*, CaseInsensitiveWideString> AttributesMap;
 class Utility final
 {
 public:
+
+    static const int WAIT_INTERVAL = 15;
+
     static std::wstring SystemTimeToString(
         SYSTEMTIME SystemTime
     );
@@ -58,9 +61,20 @@ class Utility final
         _In_ const std::wstring& To
     );
 
-    static bool isJsonNumber(_In_ std::wstring& str);
+    static bool isJsonNumber(
+        _In_ std::wstring& str);
+
+    static void SanitizeJson(
+        _Inout_ std::wstring &str);
+
+    static bool ConfigAttributeExists(
+        _In_ AttributesMap& Attributes,
+        _In_ std::wstring attributeName);
 
-    static void SanitizeJson(_Inout_ std::wstring &str);
+    static LARGE_INTEGER ConvertWaitIntervalToLargeInt(
+        _In_ int timeInterval);
 
-    static bool ConfigAttributeExists(_In_ AttributesMap &Attributes, _In_ std::wstring attributeName);
+    static int GetWaitInterval(
+        _In_ std::double_t waitInSeconds,
+        _In_ int elapsedTime);
 };