Skip to content

Commit d018d7f

Browse files
snakefootsnakefoot
committed
FileTarget - Closing on OpenFileCacheTimeout should depend on least recently used
1 parent c23cb69 commit d018d7f

File tree

5 files changed

+30
-22
lines changed

5 files changed

+30
-22
lines changed

‎src/NLog/Targets/FileAppenders/DiscardAllFileAppender.cs‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -41,6 +41,8 @@ internal sealed class DiscardAllFileAppender : IFileAppender
4141

4242
public DateTime OpenStreamTime { get; }
4343

44+
public DateTime LastWriteTime => OpenStreamTime;
45+
4446
public DateTime FileLastModified => OpenStreamTime;
4547

4648
public DateTime NextArchiveTime => DateTime.MaxValue;

‎src/NLog/Targets/FileAppenders/ExclusiveFileLockingAppender.cs‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,6 +53,8 @@ internal sealed class ExclusiveFileLockingAppender : IFileAppender
5353

5454
public DateTime OpenStreamTime { get; }
5555

56+
public DateTime LastWriteTime => FileLastModified;
57+
5658
public DateTime FileLastModified { get; private set; }
5759

5860
private DateTime FileBirthTime
@@ -97,7 +99,7 @@ private long RefreshFileBirthTimeUtc(bool forceRefresh)
9799
{
98100
FileLastModified = NLog.Time.TimeSource.Current.Time;
99101

100-
if (_fileTarget.ArchiveFileName is null && _fileTarget.ArchiveEvery == FileArchivePeriod.None && _fileTarget.ArchiveAboveSize <= 0)
102+
if (_fileTarget.ArchiveEvery == FileArchivePeriod.None && _fileTarget.ArchiveAboveSize <= 0 && _fileTarget.ArchiveFileName is null)
101103
return 0;
102104

103105
try

‎src/NLog/Targets/FileAppenders/IFileAppender.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,7 @@ internal interface IFileAppender : IDisposable
4444
long FileSize { get; }
4545

4646
DateTime OpenStreamTime { get; }
47+
DateTime LastWriteTime { get; }
4748
DateTime FileLastModified { get; }
4849
DateTime NextArchiveTime { get; }
4950

‎src/NLog/Targets/FileAppenders/MinimalFileLockingAppender.cs‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -50,6 +50,8 @@ internal sealed class MinimalFileLockingAppender : IFileAppender
5050

5151
public DateTime OpenStreamTime { get; }
5252

53+
public DateTime LastWriteTime { get; private set; }
54+
5355
public DateTime FileLastModified
5456
{
5557
get
@@ -99,7 +101,7 @@ public MinimalFileLockingAppender(FileTarget fileTarget, string filePath)
99101
_fileTarget = fileTarget;
100102
_filePath = filePath;
101103
_initialFileOpen = true;
102-
OpenStreamTime = Time.TimeSource.Current.Time;
104+
OpenStreamTime = LastWriteTime = Time.TimeSource.Current.Time;
103105
}
104106

105107
public void Write(byte[] buffer, int offset, int count)
@@ -122,6 +124,8 @@ public void Write(byte[] buffer, int offset, int count)
122124
}
123125
}
124126
}
127+
128+
LastWriteTime = NLog.Time.TimeSource.Current.Time;
125129
}
126130

127131
public void Dispose()

‎src/NLog/Targets/FileTarget.cs‎

Lines changed: 19 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -151,8 +151,8 @@ public Layout FileName
151151
/// <remarks>
152152
/// Default: <see langword="5"/> . Higher number might improve performance when single FileTarget
153153
/// is writing to many files (such as splitting by loglevel or by logger-name).
154-
/// Files are closed in FIFO (First in First out) ordering, so the oldest
155-
/// file-handle is closed first. Careful with number higher than 10-15,
154+
/// Files are closed in LRU (least recently used) ordering, so files unused
155+
/// for longest period are closed first. Careful with number higher than 10-15,
156156
/// because a large number of open files consumes system resources.
157157
/// </remarks>
158158
/// <docgen category='Performance Tuning Options' order='10' />
@@ -309,7 +309,7 @@ public FileArchivePeriod ArchiveEvery
309309
/// <docgen category='Archival Options' order='50' />
310310
public Layout? ArchiveFileName
311311
{
312-
get => _archiveFileName ?? (_archiveSuffixFormat?.IndexOf("{1") >= 0 ? FileName : null);
312+
get => _archiveFileName ?? (_archiveSuffixFormatLegacy ? FileName : null);
313313
set
314314
{
315315
var archiveSuffixFormat = _archiveSuffixFormat;
@@ -448,9 +448,11 @@ public string ArchiveSuffixFormat
448448
}
449449

450450
_archiveSuffixFormat = value;
451+
_archiveSuffixFormatLegacy = _archiveSuffixFormat?.IndexOf("{1") >= 0;
451452
}
452453
}
453454
private string? _archiveSuffixFormat;
455+
private bool _archiveSuffixFormatLegacy;
454456

455457
/// <summary>
456458
/// Gets or sets a value indicating whether the footer should be written only when the file is archived.
@@ -499,7 +501,6 @@ public OpenFileAppender(IFileAppender fileAppender, int sequenceNumber)
499501

500502
private readonly SortHelpers.KeySelector<AsyncLogEventInfo, string> _getFileNameFromLayout;
501503

502-
private DateTime _lastWriteTime;
503504
private Timer? _openFileMonitorTimer;
504505

505506
/// <summary>
@@ -770,10 +771,6 @@ private void WriteBytesToFile(string filename, LogEventInfo firstLogEvent, Memor
770771
openFile.FileAppender.Dispose();
771772
throw;
772773
}
773-
finally
774-
{
775-
_lastWriteTime = firstLogEvent.TimeStamp;
776-
}
777774
}
778775

779776
private OpenFileAppender RollArchiveFile(string filename, OpenFileAppender openFile, LogEventInfo firstLogEvent, bool hasWritten)
@@ -787,8 +784,8 @@ private OpenFileAppender RollArchiveFile(string filename, OpenFileAppender openF
787784
lastSequenceNo = openFile.SequenceNumber;
788785

789786
DateTime? previousFileLastModified = skipFileLastModified ? default(DateTime?) : openFile.FileAppender.FileLastModified;
790-
if (_lastWriteTime > DateTime.MinValue && previousFileLastModified > _lastWriteTime && (previousFileLastModified == openFile.FileAppender.OpenStreamTime || firstLogEvent.TimeStamp.Date == previousFileLastModified?.Date))
791-
previousFileLastModified = _lastWriteTime;
787+
if (previousFileLastModified > openFile.FileAppender.LastWriteTime && (previousFileLastModified == openFile.FileAppender.OpenStreamTime || firstLogEvent.TimeStamp.Date == previousFileLastModified?.Date))
788+
previousFileLastModified = openFile.FileAppender.LastWriteTime;
792789

793790
// Close file and roll to next file
794791
if (hasWritten)
@@ -931,12 +928,12 @@ private void PruneOpenFileCache()
931928

932929
while (_openFileCache.Count >= OpenFileCacheSize)
933930
{
934-
// Close the oldest filestream (not the least recently used)
931+
// Closing the least recently used
935932
DateTime oldestFileTime = DateTime.MaxValue;
936933
KeyValuePair<string, OpenFileAppender> oldestOpenFile = default;
937934
foreach (var oldOpenFile in _openFileCache)
938935
{
939-
if (oldOpenFile.Value.FileAppender.OpenStreamTime < oldestFileTime)
936+
if (oldOpenFile.Value.FileAppender.LastWriteTime < oldestFileTime)
940937
{
941938
oldestOpenFile = oldOpenFile;
942939
}
@@ -1035,10 +1032,10 @@ private void OpenFileMonitorTimer(object state)
10351032
if (OpenFileFlushTimeout > 0 && !AutoFlush)
10361033
{
10371034
DateTime flushTime = Time.TimeSource.Current.Time.AddSeconds(-(OpenFileFlushTimeout + 1) * 1.5);
1038-
if (_lastWriteTime > flushTime)
1035+
// Only Flush when something has been written
1036+
foreach (var openFile in _openFileCache)
10391037
{
1040-
// Only Flush when something has been written
1041-
foreach (var openFile in _openFileCache)
1038+
if (openFile.Value.FileAppender.LastWriteTime > flushTime)
10421039
{
10431040
openFile.Value.FileAppender.Flush();
10441041
}
@@ -1062,22 +1059,24 @@ private void OpenFileMonitorTimer(object state)
10621059
private void PruneOpenFileCacheUsingTimeout()
10631060
{
10641061
DateTime closeTime = Time.TimeSource.Current.Time.AddSeconds(-OpenFileCacheTimeout);
1065-
bool oldFilesMustBeClosed = false;
1062+
bool unusedFileMustBeClosed = false;
10661063

10671064
foreach (var openFile in _openFileCache)
10681065
{
1069-
if (openFile.Value.FileAppender.OpenStreamTime < closeTime)
1066+
// Closing the least recently used, because dangerous to momentarily close "active" file-handles,
1067+
// since other background services might take over the file-handle and block application logging.
1068+
if (openFile.Value.FileAppender.LastWriteTime < closeTime)
10701069
{
1071-
oldFilesMustBeClosed = true;
1070+
unusedFileMustBeClosed = true;
10721071
break;
10731072
}
10741073
}
10751074

1076-
if (oldFilesMustBeClosed)
1075+
if (unusedFileMustBeClosed)
10771076
{
10781077
foreach (var openFile in _openFileCache.ToList())
10791078
{
1080-
if (openFile.Value.FileAppender.OpenStreamTime < closeTime)
1079+
if (openFile.Value.FileAppender.LastWriteTime < closeTime)
10811080
{
10821081
CloseFile(openFile.Key, openFile.Value);
10831082
}

0 commit comments

Comments
 (0)