FileTarget - New current file should write start header, when archive…

… operation is performed on previous file
NLog · Sep 2, 2020 · 6db449b · 6db449b
1 parent 844a4cf
commit 6db449b
Show file tree

Hide file tree

Showing 2 changed files with 29 additions and 30 deletions.
diff --git a/src/NLog/Targets/FileTarget.cs b/src/NLog/Targets/FileTarget.cs
@@ -1227,7 +1227,7 @@ private void ProcessLogEvent(LogEventInfo logEvent, string fileName, ArraySegmen
 
             bool archiveOccurred = TryArchiveFile(fileName, logEvent, bytesToWrite.Count, previousLogEventTimestamp, initializedNewFile);
             if (archiveOccurred)
-                initializedNewFile = InitializeFile(fileName, logEvent) == DateTime.MinValue;
+                initializedNewFile = InitializeFile(fileName, logEvent) == DateTime.MinValue || initializedNewFile;
 
             if (ReplaceFileContentsOnEachWrite)
             {
@@ -1834,8 +1834,8 @@ private bool TryArchiveFile(string fileName, LogEventInfo ev, int upcomingWriteS
                     // See: https://msdn.microsoft.com/en-us/library/system.threading.abandonedmutexexception.aspx
                 }
 #endif
-
-                return TryArchiveFileAfterCloseFileAppender(fileName, archiveFile, ev, upcomingWriteSize, previousLogEventTimestamp, initializedNewFile);
+                ArchiveFileAfterCloseFileAppender(archiveFile, ev, upcomingWriteSize, previousLogEventTimestamp);
+                return true;
             }
             finally
             {
@@ -1870,33 +1870,34 @@ private BaseFileAppender TryCloseFileAppenderBeforeArchive(string fileName, stri
             return archivedAppender;
         }
 
-        private bool TryArchiveFileAfterCloseFileAppender(string fileName, string archiveFile, LogEventInfo ev, int upcomingWriteSize, DateTime previousLogEventTimestamp, bool initializedNewFile)
+        private void ArchiveFileAfterCloseFileAppender(string archiveFile, LogEventInfo ev, int upcomingWriteSize, DateTime previousLogEventTimestamp)
         {
             try
             {
                 // Check again if archive is needed. We could have been raced by another process
-                var validatedArchiveFile = GetArchiveFileName(fileName, ev, upcomingWriteSize, previousLogEventTimestamp, initializedNewFile);
+                var validatedArchiveFile = GetArchiveFileName(archiveFile, ev, upcomingWriteSize, previousLogEventTimestamp, false);
                 if (string.IsNullOrEmpty(validatedArchiveFile))
                 {
                     InternalLogger.Debug("FileTarget(Name={0}): Skip archiving '{1}' because no longer necessary", Name, archiveFile);
-                    if (archiveFile != fileName)
-                        _initializedFiles.Remove(fileName);
                     _initializedFiles.Remove(archiveFile);
                 }
                 else
                 {
-                    archiveFile = validatedArchiveFile;
-                    DoAutoArchive(archiveFile, ev, previousLogEventTimestamp, initializedNewFile);
+                    if (archiveFile != validatedArchiveFile)
+                    {
+                        _initializedFiles.Remove(archiveFile);
+                        archiveFile = validatedArchiveFile;
+                    }
                     _initializedFiles.Remove(archiveFile);
+
+                    DoAutoArchive(archiveFile, ev, previousLogEventTimestamp, false);
                 }
 
                 if (_previousLogFileName == archiveFile)
                 {
                     _previousLogFileName = null;
                     _previousLogEventTimestamp = null;
                 }
-
-                return true;    // Archive operation has been executed, by this application (or a concurrent one)
             }
             catch (Exception exception)
             {
@@ -1905,8 +1906,6 @@ private bool TryArchiveFileAfterCloseFileAppender(string fileName, string archiv
                 {
                     throw;
                 }
-
-                return false;
             }
         }
 
@@ -1934,21 +1933,14 @@ private string GetArchiveFileName(string fileName, LogEventInfo ev, int upcoming
         /// <summary>
         /// Returns the correct filename to archive
         /// </summary>
-        /// <returns></returns>
         private string GetPotentialFileForArchiving(string fileName)
         {
-            if (string.Equals(fileName, _previousLogFileName, StringComparison.OrdinalIgnoreCase))
-            {
-                //both the same, so don't care
-                return fileName;
-            }
-
-            if (string.IsNullOrEmpty(_previousLogFileName))
+            if (!string.IsNullOrEmpty(fileName))
             {
                 return fileName;
             }
 
-            if (string.IsNullOrEmpty(fileName))
+            if (!string.IsNullOrEmpty(_previousLogFileName))
             {
                 return _previousLogFileName;
             }
@@ -1980,7 +1972,7 @@ private string GetArchiveFileNameBasedOnFileSize(string fileName, int upcomingWr
             var fileLength = _fileAppenderCache.GetFileLength(archiveFileName);
             if (!fileLength.HasValue)
             {
-                archiveFileName = TryFallbackToPreviousLogFileName(fileName, archiveFileName, initializedNewFile);
+                archiveFileName = TryFallbackToPreviousLogFileName(archiveFileName, initializedNewFile);
                 if (!string.IsNullOrEmpty(archiveFileName))
                 {
                     upcomingWriteSize = 0;
@@ -2007,12 +1999,16 @@ private string GetArchiveFileNameBasedOnFileSize(string fileName, int upcomingWr
             return null;
         }
 
-        private string TryFallbackToPreviousLogFileName(string fileName, string archiveFileName, bool initializedNewFile)
+        /// <summary>
+        /// Check if archive operation should check previous filename, because FileAppenderCache tells us current filename no longer exists
+        /// </summary>
+        private string TryFallbackToPreviousLogFileName(string archiveFileName, bool initializedNewFile)
         {
-            if (!initializedNewFile || !string.Equals(fileName, archiveFileName, StringComparison.OrdinalIgnoreCase))
+            if (!initializedNewFile && _initializedFiles.Remove(archiveFileName))
             {
-                // Attempt fallback because FileAppenderCache detected previousFileName no longer exists
-                _initializedFiles.Remove(archiveFileName);
+                // Register current filename needs re-initialization
+                InternalLogger.Debug("FileTarget(Name={0}): Invalidates appender for archive file '{1}' since it no longer exists", Name, archiveFileName);
+                _fileAppenderCache.InvalidateAppender(archiveFileName)?.Dispose();
             }
 
             if (!string.IsNullOrEmpty(_previousLogFileName) && !string.Equals(archiveFileName, _previousLogFileName, StringComparison.OrdinalIgnoreCase))
@@ -2047,7 +2043,7 @@ private string GetArchiveFileNameBasedOnTime(string fileName, LogEventInfo logEv
             DateTime? creationTimeSource = TryGetArchiveFileCreationTimeSource(archiveFileName, previousLogEventTimestamp);
             if (!creationTimeSource.HasValue)
             {
-                archiveFileName = TryFallbackToPreviousLogFileName(fileName, archiveFileName, initializedNewFile);
+                archiveFileName = TryFallbackToPreviousLogFileName(archiveFileName, initializedNewFile);
                 if (!string.IsNullOrEmpty(archiveFileName))
                 { 
                     return GetArchiveFileNameBasedOnTime(archiveFileName, logEvent, previousLogEventTimestamp, false);

diff --git a/tests/NLog.UnitTests/Targets/FileTargetTests.cs b/tests/NLog.UnitTests/Targets/FileTargetTests.cs
@@ -1382,7 +1382,8 @@ public void DateArchive_UsesDateFromCurrentTimeSource(DateTimeKind timeKind, boo
                     KeepFileOpen = keepFileOpen,
                     NetworkWrites = networkWrites,
                     ForceManaged = forceManaged,
-                    ForceMutexConcurrentWrites = forceMutexConcurrentWrites
+                    ForceMutexConcurrentWrites = forceMutexConcurrentWrites,
+                    Header = "header",
                 });
 
                 SimpleConfigurator.ConfigureForTargetLogging(fileTarget, LogLevel.Debug);
@@ -1436,6 +1437,9 @@ public void DateArchive_UsesDateFromCurrentTimeSource(DateTimeKind timeKind, boo
                 //the amount of archived files may not exceed the set 'MaxArchiveFiles'
                 Assert.Equal(maxArchiveFiles, files.Length);
 
+                foreach (var file in files)
+                    AssertFileContentsStartsWith(file, "header", Encoding.UTF8);
+
                 SimpleConfigurator.ConfigureForTargetLogging(fileTarget, LogLevel.Debug);
                 //writing one line on a new day will trigger the cleanup of old archived files
                 //as stated by the MaxArchiveFiles property, but will only delete the oldest file
@@ -3211,7 +3215,6 @@ public void Dont_throw_Exception_when_archiving_is_enabled()
             }
         }
 
-
         [Fact]
         public void Dont_throw_Exception_when_archiving_is_enabled_with_async()
         {