[Fix] Log stream delay when dir does not exist (#174)

Co-authored-by: TinaMor <mor.tina@outlook.com>
microsoft · May 23, 2024 · c524905 · c524905
1 parent aa6ea06
commit c524905
Show file tree

Hide file tree

Showing 5 changed files with 232 additions and 78 deletions.
diff --git a/LogMonitor/docs/README.md b/LogMonitor/docs/README.md
@@ -214,6 +214,33 @@ This will monitor any changes in log files matching a specified filter, given th
 
 - `type` (required): `"File"`
 - `directory` (required): set to the directory containing the files to be monitored.
+     > :grey_exclamation:**NOTE:** Only works with absolute paths.
+     > 
+     > To support *long file name* functionality, we prepend "\\?\" to the path. This approach extends the MAX_PATH limit from 260 characters to 32,767 wide characters. For more details, see [Maximum Path Length Limitation](https://learn.microsoft.com/en-us/windows/win32/fileio/naming-a-file#maximum-path-length-limitation).
+     > 
+     > Due to this modification, the path **must** be an [absolute path](https://learn.microsoft.com/en-us/dotnet/standard/io/file-path-formats#traditional-dos-paths), beginning with a disk designator with a backslash, for example "C:\" or "d:\".
+     > 
+     > [UNC paths](https://learn.microsoft.com/en-us/dotnet/standard/io/file-path-formats#unc-paths) and [DOS device paths](https://learn.microsoft.com/en-us/dotnet/standard/io/file-path-formats#dos-device-paths) are not supported.
+     > 
+     >  Ensure you [identify the type of path](https://learn.microsoft.com/en-us/dotnet/standard/io/file-path-formats#identify-the-path) and the path is correctly formatted to avoid issues.
+     >
+     > | Example                                                    | Path Type        | Allowed            |
+     > |-------------------------------------------------------     |------------------|--------------------|
+     > | "c:"                                                       | Absolute         | :white_check_mark: |
+     > | "c:\\"                                                     | Absolute         | :white_check_mark: |
+     > | "c:\temp"                                                  | Absolute         | :white_check_mark: |
+     > | "\tempdir"                                                 | Absolute         | :x:                |
+     > | "C:tempdir"                                                | Relative         | :x:                |
+     > | "\\\\.\Volume\{b75e2c83-0000-0000-0000-602f00000000}\Test" | Volume GUID path | :x:                |
+     > | "\\\\.\c:\temp"                                            | DOS Device Path  | :x:                |
+     > | "\\\\?\c:\temp"                                            | DOS Device Path  | :x:                |
+     > | "\\\\127.0.0.1\c$\temp"                                    | UNC              | :x:                |
+     > | "\\\\LOCALHOST\c$\temp"                                    | UNC              | :x:                |
+     > | "\\\\.\UNC\LOCALHOST\c$\temp"                              | UNC              | :x:                |
+     > | "."                                                        | Relative         | :x:                |
+     > | ".\"                                                       | Relative         | :x:                |
+     > | "..\temp"                                                  | Relative         | :x:                |
+
 - `filter` (optional): uses [MS-DOS wildcard match type](https://learn.microsoft.com/en-us/previous-versions/windows/desktop/indexsrv/ms-dos-and-windows-wildcard-characters) i.e.. `*, ?`. Can be set to empty, which will be default to `"*"`.
 - `includeSubdirectories` (optional) : `"true|false"`, specify if sub-directories also need to be monitored. Defaults to `false`.
 - `includeFileNames` (optional): `"true|false"`, specifies whether to include file names in the logline, eg. `sample.log: xxxxx`. Defaults to `false`.
@@ -231,10 +258,10 @@ This will monitor any changes in log files matching a specified filter, given th
 
     In this case, LogMonitor will wait forever for the folder to be created. 
 
-    **NOTE:**
-    - This field is case insensitive
-    - When "INFINITY" is passed, it must be passed as a string.
-    - The infinity symbol, ∞, is also allowed as a string or the symbol itself.
+    > :grey_exclamation:**NOTE**
+    > - This field is case insensitive
+    > - When "INFINITY" is passed, it must be passed as a string.
+    > - The infinity symbol, ∞, is also allowed as a string or the symbol itself.
 
   <br />
 
@@ -254,7 +281,10 @@ This will monitor any changes in log files matching a specified filter, given th
   WARNING: Failed to parse configuration file. Error retrieving source attributes. Invalid source
   ```
 
-### Examples
+### Sample FileMonitor *LogMonitorConfig.json*
+#### Example 1
+
+LogMonitor will monitor log files in the directory "c:\inetpub\logs" along with its subfolders. If the directory does not exist, it will wait for up to 10 seconds for the directory to be created.
 
 ```json
 {
@@ -273,7 +303,13 @@ This will monitor any changes in log files matching a specified filter, given th
 }
 ```
 
-**Note:** When the directory is the root directory (e.g. C:\\ ) we can only monitor a file that is in the root directory, not a subfolder. This is due to access issues (even when running LogMonitor as an Admin) for some of the folders in the root directory. Therefore, `includeSubdirectories` must be `false` for the root directory. See example below:
+#### Example 2
+
+LogMonitor will monitor log files in the root directory, "C:\".
+
+ > When the directory is the root directory (e.g. "C:\\" ) we can only monitor a file that is in the root directory, not a subfolder. This is due to access issues (even when running LogMonitor as an Admin) for some of the folders in the root directory. Therefore, `includeSubdirectories` must be `false` for the root directory. 
+
+See sample valid *LogMonitorConfig.json* below:
 
 ```json
 {
@@ -289,7 +325,28 @@ This will monitor any changes in log files matching a specified filter, given th
   }
 }
 ```
+
+#### Example 3
+
+This example shows an invalid file monitor configuration:
+
+```json
+{
+  "LogConfig": {
+      "sources": [
+          {
+              "type": "File",
+              "directory": "C:",
+              "filter": "*.log",
+              "includeSubdirectories": true
+          }
+      ]
+  }
+}
+```
+
 When the root directory is passed and `includeSubdirectories = true`, we get an error:
+
 ```
 ERROR: LoggerSettings: Invalid Source File atrribute 'directory' (C:) and 'includeSubdirectories' (true).'includeSubdirectories' attribute cannot be 'true' for the root directory
 WARNING: Failed to parse configuration file. Error retrieving source attributes. Invalid source

diff --git a/LogMonitor/src/LogMonitor/FileMonitor/FileMonitorUtilities.cpp b/LogMonitor/src/LogMonitor/FileMonitor/FileMonitorUtilities.cpp
@@ -74,7 +74,8 @@ HANDLE FileMonitorUtilities::GetLogDirHandle(
             logWriter.TraceError(
                 Utility::FormatString(
                     L"Failed to create timer object. Log directory %ws will not be monitored for log entries. Error=%d",
-                    logDirectory.c_str(), status).c_str());
+                    logDirectory.c_str(), status)
+                    .c_str());
             return INVALID_HANDLE_VALUE;
         }
 
@@ -90,6 +91,10 @@ HANDLE FileMonitorUtilities::GetLogDirHandle(
 
 void FileMonitorUtilities::ParseDirectoryValue(_Inout_ std::wstring &directory)
 {
+    // Replace all occurrences of forward slashes (/) with backslashes (\).
+    std::replace(directory.begin(), directory.end(), L'/', L'\\');
+
+    // Remove trailing backslashes
     while (!directory.empty() && directory[directory.size() - 1] == L'\\')
     {
         directory.resize(directory.size() - 1);
@@ -113,6 +118,33 @@ bool FileMonitorUtilities::CheckIsRootFolder(_In_ std::wstring dirPath)
     return std::regex_search(dirPath, matches, pattern);
 }
 
+std::wstring FileMonitorUtilities::_GetParentDir(std::wstring dirPath)
+{
+    if (CheckIsRootFolder(dirPath))
+    {
+        return dirPath;
+    }
+
+    size_t pos = dirPath.find_last_of(L"/\\");
+    std::wstring parentdir = L"";
+    if (pos != std::wstring::npos)
+    {
+        parentdir = dirPath.substr(0, pos);
+    }
+
+    // Check if it is an empty string
+    if (parentdir.empty())
+    {
+        std::wstring pathError = Utility::FormatString(
+            L"Directory cannot be a relative path or an empty string %s.",
+            dirPath.c_str());
+        std::string strPathError(pathError.begin(), pathError.end());
+        throw std::invalid_argument(strPathError);
+    }
+
+    return parentdir;
+}
+
 HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
     std::wstring logDirectory,
     std::double_t waitInSeconds,
@@ -123,11 +155,64 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
     DWORD status = ERROR_FILE_NOT_FOUND;
     int elapsedTime = 0;
 
-    const int eventsCount = 2;
-    HANDLE dirOpenEvents[eventsCount] = {stopEvent, timerEvent};
+    const int eventsCount = 3;
+
+    HANDLE dirOpenEvents[eventsCount]{};
+    dirOpenEvents[0] = stopEvent;
+    dirOpenEvents[1] = timerEvent;
+
+    // Start monitoring the parent directory for changes
+    // NOTE: For nested directories, the parent dir must exist. If it does not, this will raise an error
+    // ERROR_FILE_NOT_FOUND (STATUS: 2) - The system cannot find the file specified
+    std::wstring parentdir = _GetParentDir(logDirectory);
+    HANDLE dirChangesHandle = FindFirstChangeNotification(
+        parentdir.c_str(),            // directory to watch
+        TRUE,                         // watch the subtree
+        FILE_NOTIFY_CHANGE_DIR_NAME); // watch dir name changes
+    dirOpenEvents[2] = dirChangesHandle;
+
+    if (dirChangesHandle == INVALID_HANDLE_VALUE)
+    {
+        status = GetLastError();
+        if (status == ERROR_FILE_NOT_FOUND)
+        {
+            logWriter.TraceError(
+                Utility::FormatString(
+                    L"The parent directory '%s' does not exist for the specified path: '%s'. Error: %lu",
+                    parentdir.c_str(),
+                    logDirectory.c_str(),
+                    status)
+                    .c_str());
+            return INVALID_HANDLE_VALUE;
+        }
+        else
+        {
+            logWriter.TraceError(
+                Utility::FormatString(
+                    L"Failed to monitor changes in directory %s. Error: %lu",
+                    logDirectory.c_str(),
+                    status)
+                    .c_str());
+            return INVALID_HANDLE_VALUE;
+        }
+    }
+
+    if (dirChangesHandle == NULL)
+    {
+        logWriter.TraceError(
+            Utility::FormatString(
+                L"Failed to monitor changes in directory %s.",
+                logDirectory.c_str())
+                .c_str());
+        return INVALID_HANDLE_VALUE;
+    }
+
+    // Get the starting tick count
+    ULONGLONG startTick = GetTickCount64();
 
     while (FileMonitorUtilities::_IsFileErrorStatus(status) && elapsedTime < waitInSeconds)
     {
+        // Calculate the wait interval
         int waitInterval = Utility::GetWaitInterval(waitInSeconds, elapsedTime);
         LARGE_INTEGER timeToWait = Utility::ConvertWaitIntervalToLargeInt(waitInterval);
 
@@ -147,7 +232,7 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
         DWORD wait = WaitForMultipleObjects(eventsCount, dirOpenEvents, FALSE, INFINITE);
         switch (wait)
         {
-        case WAIT_OBJECT_0:
+        case WAIT_OBJECT_0: // stopEvent
         {
             //
             // The process is exiting. Stop the timer and return.
@@ -157,11 +242,29 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
             return INVALID_HANDLE_VALUE;
         }
 
-        case WAIT_OBJECT_0 + 1:
+        case WAIT_OBJECT_0 + 1: // timerEvent
         {
-            //
             // Timer event. Retry opening directory handle.
-            //
+            break;
+        }
+
+        case WAIT_OBJECT_0 + 2: // Directory change notification
+        {
+            if (FindNextChangeNotification(dirChangesHandle) == FALSE)
+            {
+                status = GetLastError();
+                logWriter.TraceError(
+                    Utility::FormatString(
+                        L"Failed to request change notification in directory %s. Error: %lu",
+                        parentdir.c_str(),
+                        status)
+                        .c_str());
+                CancelWaitableTimer(timerEvent);
+                CloseHandle(timerEvent);
+                return INVALID_HANDLE_VALUE;
+            }
+
+            elapsedTime = static_cast<int>((GetTickCount64() - startTick) / 1000);
             break;
         }
 
@@ -171,10 +274,14 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
             // Wait failed, return the failure.
             //
             status = GetLastError();
+            logWriter.TraceError(
+                Utility::FormatString(
+                    L"Unexpected error when waiting for directory: %lu. Error: %lu.",
+                    wait, status)
+                    .c_str());
 
             CancelWaitableTimer(timerEvent);
             CloseHandle(timerEvent);
-
             return INVALID_HANDLE_VALUE;
         }
         }
@@ -204,6 +311,12 @@ HANDLE FileMonitorUtilities::_RetryOpenDirectoryWithInterval(
         }
     }
 
+    // Close the change notification handle if it was successfully created
+    if (dirChangesHandle != INVALID_HANDLE_VALUE)
+    {
+        FindCloseChangeNotification(dirChangesHandle);
+    }
+
     return logDirHandle;
 }
 

diff --git a/LogMonitor/src/LogMonitor/FileMonitor/FileMonitorUtilities.h b/LogMonitor/src/LogMonitor/FileMonitor/FileMonitorUtilities.h
@@ -36,4 +36,7 @@ class FileMonitorUtilities final
         static std::wstring _GetWaitLogMessage(
             std::wstring logDirectory,
             std::double_t waitInSeconds);
+
+        static std::wstring _GetParentDir(
+            std::wstring dirPath);
 };
diff --git a/LogMonitor/src/LogMonitor/LogFileMonitor.cpp b/LogMonitor/src/LogMonitor/LogFileMonitor.cpp
@@ -62,7 +62,7 @@ LogFileMonitor::LogFileMonitor(_In_ const std::wstring& LogDirectory,
     // By default, the name is limited to MAX_PATH characters. To extend this limit to 32,767 wide characters,
     // we prepend "\?" to the path. Prepending the string "\?" does not allow access to the root directory
     // We, therefore, do not prepend for the root directory
-    bool isRootFolder = CheckIsRootFolder(m_logDirectory);
+    bool isRootFolder = FileMonitorUtilities::CheckIsRootFolder(m_logDirectory);
     m_logDirectory = isRootFolder ? m_logDirectory : PREFIX_EXTENDED_PATH + m_logDirectory;
 
     if (m_filter.empty())
@@ -215,7 +215,8 @@ LogFileMonitor::StartLogFileMonitorStatic(
         {
             logWriter.TraceError(
                 Utility::FormatString(
-                    L"Failed to start log file monitor. Log files in a directory %s will not be monitored. Error: %lu",
+                    L"Failed to start log file monitor. Log files in a directory "
+                    "'%s' will not be monitored. Error: %lu",
                     pThis->m_logDirectory.c_str(),
                     status
                 ).c_str()
@@ -227,7 +228,8 @@ LogFileMonitor::StartLogFileMonitorStatic(
     {
         logWriter.TraceError(
             Utility::FormatString(
-                L"Failed to start log file monitor. Log files in a directory %s will not be monitored. %S",
+                L"Failed to start log file monitor. Log files in a directory "
+                "'%s' will not be monitored. %S",
                 pThis->m_logDirectory.c_str(),
                 ex.what()
             ).c_str()
@@ -238,7 +240,7 @@ LogFileMonitor::StartLogFileMonitorStatic(
     {
         logWriter.TraceError(
             Utility::FormatString(
-                L"Failed to start log file monitor. Log files in a directory %s will not be monitored.",
+                L"Failed to start log file monitor. Log files in a directory '%s' will not be monitored.",
                 pThis->m_logDirectory.c_str()
             ).c_str()
         );
@@ -2043,12 +2045,3 @@ LogFileMonitor::GetFileId(
 
     return status;
 }
-
-bool
-LogFileMonitor::CheckIsRootFolder(_In_ std::wstring dirPath)
-{
-    std::wregex pattern(L"^\\w:?$");
-
-    std::wsmatch matches;
-    return std::regex_search(dirPath, matches, pattern);
-}