Skip to content

Commit

Permalink
Merge pull request #2662 from snakefoot/FileTargetMultipleFileArchive
Browse files Browse the repository at this point in the history 
FileTarget - Improve handling of archive with multiple active files
  • Loading branch information
@304NotModified
304NotModified authored Apr 15, 2018
2 parents 70aec5b + 4f2c54f commit f313565
Show file tree
Hide file tree
Showing 3 changed files with 97 additions and 68 deletions.
6 changes: 3 additions & 3 deletions src/NLog/Internal/FileAppenders/FileAppenderCache.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -441,7 +441,7 @@ private BaseFileAppender GetAppender(string fileName)
catch (Exception ex)
{
InternalLogger.Error(ex, "Failed to get file creation time for file '{0}'.", appender.FileName);
InvalidateAppender(appender.FileName);
InvalidateAppender(appender.FileName)?.Dispose();
throw;
}
}
Expand Down Expand Up @@ -471,7 +471,7 @@ private BaseFileAppender GetAppender(string fileName)
catch (Exception ex)
{
InternalLogger.Error(ex, "Failed to get last write time for file '{0}'.", appender.FileName);
InvalidateAppender(appender.FileName);
InvalidateAppender(appender.FileName)?.Dispose();
throw;
}
}
Expand Down Expand Up @@ -500,7 +500,7 @@ private BaseFileAppender GetAppender(string fileName)
catch (Exception ex)
{
InternalLogger.Error(ex, "Failed to get length for file '{0}'.", appender.FileName);
InvalidateAppender(appender.FileName);
InvalidateAppender(appender.FileName)?.Dispose();
throw;
}
}
Expand Down
72 changes: 44 additions & 28 deletions src/NLog/Targets/FileTarget.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1433,42 +1433,54 @@ private string GetArchiveDateFormatString(string defaultFormat)
return formatString;
}

private DateTime GetArchiveDate(string fileName, LogEventInfo logEvent)
private DateTime? GetArchiveDate(string fileName, LogEventInfo logEvent, bool initializedNewFile)
{
var lastWriteTimeUtc = _fileAppenderCache.GetFileLastWriteTimeUtc(fileName, true);
var lastWriteTimeSource = _fileAppenderCache.GetFileCreationTimeSource(fileName, true);

//todo null check
var lastWriteTime = TimeSource.Current.FromSystemTime(lastWriteTimeUtc.Value);

InternalLogger.Trace("Calculating archive date. Last write time: {0}; Previous log event time: {1}", lastWriteTime, _previousLogEventTimestamp);
DateTime? previousLogEventTimestamp = string.Equals(fileName, _previousLogFileName, StringComparison.OrdinalIgnoreCase) ? _previousLogEventTimestamp : null;
if (!previousLogEventTimestamp.HasValue && !initializedNewFile)
{
if (_initializedFiles.TryGetValue(fileName, out var initializedTimeSamp))
{
previousLogEventTimestamp = initializedTimeSamp;
}
}

bool previousLogIsMoreRecent = _previousLogEventTimestamp.HasValue && (_previousLogEventTimestamp.Value > lastWriteTime);
if (previousLogIsMoreRecent)
InternalLogger.Trace("Calculating archive date. Last write time: {0}; Previous log event time: {1}", lastWriteTimeSource, previousLogEventTimestamp);
if (!lastWriteTimeSource.HasValue)
{
InternalLogger.Trace("Using previous log event time (is more recent)");
return _previousLogEventTimestamp.Value;
if (!previousLogEventTimestamp.HasValue)
{
InternalLogger.Info("FileTarget(Name={0}): Unable to acquire useful timestamp to archive file: {1}", Name, fileName);
}
return previousLogEventTimestamp;
}

if (_previousLogEventTimestamp.HasValue && PreviousLogOverlappedPeriod(logEvent, lastWriteTime))
if (lastWriteTimeSource.HasValue && previousLogEventTimestamp.HasValue)
{
InternalLogger.Trace("Using previous log event time (previous log overlapped period)");
return _previousLogEventTimestamp.Value;
if (previousLogEventTimestamp.Value > lastWriteTimeSource.Value)
{
InternalLogger.Trace("Using previous log event time (is more recent)");
return previousLogEventTimestamp.Value;
}

if (PreviousLogOverlappedPeriod(logEvent, previousLogEventTimestamp.Value, lastWriteTimeSource.Value))
{
InternalLogger.Trace("Using previous log event time (previous log overlapped period)");
return previousLogEventTimestamp.Value;
}
}

InternalLogger.Trace("Using last write time");
return lastWriteTime;
return lastWriteTimeSource.Value;
}

private bool PreviousLogOverlappedPeriod(LogEventInfo logEvent, DateTime lastWrite)
private bool PreviousLogOverlappedPeriod(LogEventInfo logEvent, DateTime previousLogEventTimestamp, DateTime lastFileWrite)
{
DateTime timestamp;
if (!_previousLogEventTimestamp.HasValue)
return false;
else
timestamp = _previousLogEventTimestamp.Value;
DateTime timestamp = previousLogEventTimestamp;

string formatString = GetArchiveDateFormatString(string.Empty);
string lastWriteTimeString = lastWrite.ToString(formatString, CultureInfo.InvariantCulture);
string lastWriteTimeString = lastFileWrite.ToString(formatString, CultureInfo.InvariantCulture);
string logEventTimeString = logEvent.TimeStamp.ToString(formatString, CultureInfo.InvariantCulture);

if (lastWriteTimeString != logEventTimeString)
Expand Down Expand Up @@ -1570,8 +1582,8 @@ private void DoAutoArchive(string fileName, LogEventInfo eventInfo, bool initial
}
}

DateTime archiveDate = GetArchiveDate(fileName, eventInfo);
var archiveFileName = fileArchiveStyle.GenerateArchiveFileName(archiveFilePattern, archiveDate, existingArchiveFiles);
DateTime? archiveDate = GetArchiveDate(fileName, eventInfo, initializedNewFile);
var archiveFileName = archiveDate.HasValue ? fileArchiveStyle.GenerateArchiveFileName(archiveFilePattern, archiveDate.Value, existingArchiveFiles) : null;
if (archiveFileName != null)
{
if (initializedNewFile)
Expand Down Expand Up @@ -1813,23 +1825,27 @@ private string GetArchiveFileNameBasedOnFileSize(string fileName, int upcomingWr
return null;
}

fileName = GetPotentialFileForArchiving(fileName);

if (fileName == null)
var previousFileName = GetPotentialFileForArchiving(fileName);
if (previousFileName == null)
{
return null;
}

var length = _fileAppenderCache.GetFileLength(fileName, true);
var length = _fileAppenderCache.GetFileLength(previousFileName, true);
if (length == null)
{
return null;
}

if (previousFileName != fileName)
{
upcomingWriteSize = 0; // Not going to write to this file
}

var shouldArchive = length.Value + upcomingWriteSize > ArchiveAboveSize;
if (shouldArchive)
{
return fileName;
return previousFileName;
}
return null;

Expand Down
87 changes: 50 additions & 37 deletions tests/NLog.UnitTests/Targets/FileTargetTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2697,8 +2697,7 @@ public void FileTarget_ArchiveNumbering_remove_correct_wildcard()
const int maxArchiveFiles = 5;

var tempPath = ArchiveFileNameHelper.GenerateTempPath();
var logFile1 = Path.Combine(tempPath, "log{0}.txt");
var logFile2 = Path.Combine(tempPath, "log-other{0}.txt");
var logFile = Path.Combine(tempPath, "{0}{1}.txt");

var defaultTimeSource = TimeSource.Current;
try
Expand All @@ -2712,64 +2711,77 @@ public void FileTarget_ArchiveNumbering_remove_correct_wildcard()
}
TimeSource.Current = timeSource;

var fileTarget1 = new FileTarget
{
FileName = string.Format(logFile1, "${shortdate}"),
ArchiveAboveSize = 100,
LineEnding = LineEndingMode.LF,
Layout = "${message}",
MaxArchiveFiles = maxArchiveFiles,
};

var fileTarget2 = new FileTarget
var fileTarget = new FileTarget
{
FileName = string.Format(logFile2, "${shortdate}"),
FileName = string.Format(logFile, "${logger}","${shortdate}"),
ArchiveAboveSize = 100,
LineEnding = LineEndingMode.LF,
Layout = "${message}",
MaxArchiveFiles = maxArchiveFiles,
};

SimpleConfigurator.ConfigureForTargetLogging(fileTarget1, LogLevel.Debug);
LoggingRule rule = new LoggingRule("*", LogLevel.Debug, fileTarget2);
LogManager.Configuration.LoggingRules.Add(rule);
LogManager.ReconfigExistingLoggers();
SimpleConfigurator.ConfigureForTargetLogging(fileTarget, LogLevel.Debug);
var logger1 = LogManager.GetLogger("log");
var logger2 = LogManager.GetLogger("log-other");

timeSource.AddToLocalTime(TimeSpan.Zero - TimeSpan.FromDays(1));

Generate100BytesLog((char)('0'));
Generate100BytesLog((char)('0'), logger1);
Generate100BytesLog((char)('0'), logger2);
for (int i = 0; i <= maxArchiveFiles - 3; i++)
{
Generate100BytesLog((char)('1' + i));
Assert.True(File.Exists(Path.Combine(tempPath, string.Format(logFile1, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString()))),
$"{string.Format(logFile1, "." + i.ToString())} is missing");
Assert.True(File.Exists(Path.Combine(tempPath, string.Format(logFile2, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString()))),
$"{string.Format(logFile2, "." + i.ToString())} is missing");
Generate100BytesLog((char)('1' + i), logger1);
Generate100BytesLog((char)('1' + i), logger2);
var logFile1 = string.Format(logFile, logger1.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd"));
var logFile2 = string.Format(logFile, logger2.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd"));
Assert.True(File.Exists(logFile1),
$"{logFile1} is missing");
Assert.True(File.Exists(logFile2),
$"{logFile2} is missing");
logFile1 = string.Format(logFile, logger1.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString());
logFile2 = string.Format(logFile, logger2.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString());
Assert.True(File.Exists(logFile1),
$"{logFile1} is missing");
Assert.True(File.Exists(logFile2),
$"{logFile2} is missing");
}

TimeSource.Current = defaultTimeSource; // restore default time source
Generate100BytesLog((char)('a'));
Generate100BytesLog((char)('a'), logger1);
Generate100BytesLog((char)('a'), logger2);
for (int i = 0; i < maxArchiveFiles; i++)
{
Generate100BytesLog((char)('b' + i));
Assert.True(File.Exists(Path.Combine(tempPath, string.Format(logFile1, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString()))),
$"{string.Format(logFile1, "." + i.ToString())} is missing");
Assert.True(File.Exists(Path.Combine(tempPath, string.Format(logFile2, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString()))),
$"{string.Format(logFile2, "." + i.ToString())} is missing");
Generate100BytesLog((char)('b' + i), logger1);
Generate100BytesLog((char)('b' + i), logger2);
var logFile1 = string.Format(logFile, logger1.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString());
var logFile2 = string.Format(logFile, logger2.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString());
Assert.True(File.Exists(logFile1),
$"{logFile1} is missing");
Assert.True(File.Exists(logFile2),
$"{logFile2} is missing");
}

for (int i = maxArchiveFiles; i < 10; i++)
{
Generate100BytesLog((char)('b' + i));
Generate100BytesLog((char)('b' + i), logger1);
Generate100BytesLog((char)('b' + i), logger2);
var numberToBeRemoved = i - maxArchiveFiles;
Assert.False(File.Exists(Path.Combine(tempPath, string.Format(logFile1, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + numberToBeRemoved.ToString()))),
$"archive FirstFile {numberToBeRemoved} has not been removed! We are created file {i}");
Assert.False(File.Exists(Path.Combine(tempPath, string.Format(logFile2, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + numberToBeRemoved.ToString()))),
$"archive SecondFile {numberToBeRemoved} has not been removed! We are created file {i}");
Assert.True(File.Exists(Path.Combine(tempPath, string.Format(logFile1, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString()))),

var logFile1 = string.Format(logFile, logger1.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + numberToBeRemoved.ToString());
var logFile2 = string.Format(logFile, logger2.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + numberToBeRemoved.ToString());

Assert.False(File.Exists(logFile1),
$"archive FirstFile {numberToBeRemoved} has not been removed! We are created file {i}");
Assert.True(File.Exists(Path.Combine(tempPath, string.Format(logFile2, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString()))),
Assert.False(File.Exists(logFile2),
$"archive SecondFile {numberToBeRemoved} has not been removed! We are created file {i}");

logFile1 = string.Format(logFile, logger1.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString());
logFile2 = string.Format(logFile, logger2.Name, TimeSource.Current.Time.Date.ToString("yyyy-MM-dd") + "." + i.ToString());

Assert.True(File.Exists(logFile1),
$"{logFile1} is missing");
Assert.True(File.Exists(logFile2),
$"{logFile2} is missing");
}

LogManager.Configuration = null;
Expand Down Expand Up @@ -2829,8 +2841,9 @@ public void FileTarget_SameDirectory_MaxArchiveFiles_One()
}
}

private void Generate100BytesLog(char c)
private void Generate100BytesLog(char c, ILogger logger = null)
{
logger = logger ?? this.logger;
for (var i = 0; i < 25; ++i)
{
//3 chars with newlines = 4 bytes
Expand Down

0 comments on commit f313565

Please sign in to comment.