Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FileTarget - Skip FileSystemWatcher unless ConcurrentWrites=true #3322

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
2 changes: 2 additions & 0 deletions src/NLog/Config/LoggingRule.cs
Original file line number Diff line number Diff line change
Expand Up @@ -165,6 +165,7 @@ public string LoggerNamePattern
/// <summary>
/// Gets the collection of log levels enabled by this rule.
/// </summary>
[NLogConfigurationIgnoreProperty]
public ReadOnlyCollection<LogLevel> Levels
{
get
Expand All @@ -182,6 +183,7 @@ public ReadOnlyCollection<LogLevel> Levels
return levels.AsReadOnly();
}
}

/// <summary>
/// Default action if all filters won't match
/// </summary>
Expand Down
8 changes: 4 additions & 4 deletions src/NLog/Config/XmlLoggingConfiguration.cs
Original file line number Diff line number Diff line change
Expand Up @@ -293,7 +293,7 @@ public override IEnumerable<string> FileNamesToWatch
public override LoggingConfiguration Reload()
{
if (!string.IsNullOrEmpty(_originalFileName))
return new XmlLoggingConfiguration(_originalFileName);
return new XmlLoggingConfiguration(_originalFileName, LogFactory);
else
return base.Reload();
}
Expand Down Expand Up @@ -459,7 +459,7 @@ private void ParseNLogElement(ILoggingConfigurationElement nlogElement, string f
nlogElement.AssertName("nlog");

bool autoReload = nlogElement.GetOptionalBooleanValue("autoReload", autoReloadDefault);
if (filePath != null)
if (!string.IsNullOrEmpty(filePath))
_fileMustAutoReloadLookup[GetFileLookupKey(filePath)] = autoReload;

try
Expand All @@ -483,8 +483,8 @@ protected override bool ParseNLogSection(ILoggingConfigurationElement configSect
if (configSection.MatchesName("include"))
{
string filePath = _currentFilePath.Peek();
bool autoLoad = filePath != null && _fileMustAutoReloadLookup[GetFileLookupKey(filePath)];
ParseIncludeElement(configSection, filePath != null ? Path.GetDirectoryName(filePath) : null, autoLoad);
bool autoLoad = !string.IsNullOrEmpty(filePath) && _fileMustAutoReloadLookup[GetFileLookupKey(filePath)];
ParseIncludeElement(configSection, !string.IsNullOrEmpty(filePath) ? Path.GetDirectoryName(filePath) : null, autoLoad);
return true;
}
else
Expand Down
25 changes: 24 additions & 1 deletion src/NLog/Internal/FileAppenders/BaseFileAppender.cs
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ protected BaseFileAppender(string fileName, ICreateFileParameters createParamete
/// Gets the path of the file, including file extension.
/// </summary>
/// <value>The name of the file.</value>
public string FileName { get; private set; }
public string FileName { get; }

/// <summary>
/// Gets or sets the creation time for a file associated with the appender. The time returned is in Coordinated
Expand Down Expand Up @@ -316,5 +316,28 @@ private void UpdateCreationTime()
#endif
}
}


protected static bool MonitorForEnableFileDeleteEvent(string fileName, ref DateTime lastSimpleMonitorCheckTimeUtc)
{
long ticksDelta = DateTime.UtcNow.Ticks - lastSimpleMonitorCheckTimeUtc.Ticks;
if (ticksDelta > TimeSpan.TicksPerSecond || ticksDelta < -TimeSpan.TicksPerSecond)
{
lastSimpleMonitorCheckTimeUtc = DateTime.UtcNow;
try
{
if (!File.Exists(fileName))
{
return true;
}
}
catch (Exception ex)
{
InternalLogger.Error(ex, "Failed to check if File.Exists {0}", fileName);
return true;
}
}
return false;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -48,8 +48,9 @@ internal class CountingSingleProcessFileAppender : BaseFileAppender
public static readonly IFileAppenderFactory TheFactory = new Factory();

private FileStream _file;

private long _currentFileLength;
private readonly bool _enableFileDeleteSimpleMonitor;
private DateTime _lastSimpleMonitorCheckTimeUtc;

/// <summary>
/// Initializes a new instance of the <see cref="CountingSingleProcessFileAppender" /> class.
Expand All @@ -62,6 +63,8 @@ public CountingSingleProcessFileAppender(string fileName, ICreateFileParameters
var fileInfo = new FileInfo(fileName);
_currentFileLength = fileInfo.Exists ? fileInfo.Length : 0;
_file = CreateFileStream(false);
_enableFileDeleteSimpleMonitor = parameters.EnableFileDeleteSimpleMonitor;
_lastSimpleMonitorCheckTimeUtc = OpenTimeUtc;
}

/// <summary>
Expand Down Expand Up @@ -135,6 +138,16 @@ public override void Write(byte[] bytes, int offset, int count)
return;
}

if (_enableFileDeleteSimpleMonitor)
{
if (MonitorForEnableFileDeleteEvent(FileName, ref _lastSimpleMonitorCheckTimeUtc))
{
_file.Dispose();
_file = CreateFileStream(false);
_currentFileLength = _file.Length;
}
}

_currentFileLength += count;
_file.Write(bytes, offset, count);
}
Expand Down
19 changes: 8 additions & 11 deletions src/NLog/Internal/FileAppenders/FileAppenderCache.cs
Original file line number Diff line number Diff line change
Expand Up @@ -324,20 +324,17 @@ private BaseFileAppender CreateAppender(string fileName, int freeSpot)
/// </summary>
public void CloseAppenders(string reason)
{
if (_appenders != null)
for (int i = 0; i < _appenders.Length; ++i)
{
for (int i = 0; i < _appenders.Length; ++i)
var oldAppender = _appenders[i];
if (oldAppender == null)
{
var oldAppender = _appenders[i];
if (oldAppender == null)
{
break;
}

CloseAppender(oldAppender, reason, true);
_appenders[i] = null;
oldAppender.Dispose(); // Dispose of Archive Mutex
break;
}

CloseAppender(oldAppender, reason, true);
_appenders[i] = null;
oldAppender.Dispose(); // Dispose of Archive Mutex
}
}

Expand Down
5 changes: 5 additions & 0 deletions src/NLog/Internal/FileAppenders/ICreateFileParameters.cs
Original file line number Diff line number Diff line change
Expand Up @@ -95,5 +95,10 @@ internal interface ICreateFileParameters
/// Should archive mutex be created?
/// </summary>
bool IsArchivingEnabled { get; }

/// <summary>
/// Should manual simple detection of file deletion be enabled?
/// </summary>
bool EnableFileDeleteSimpleMonitor { get; }
}
}
13 changes: 13 additions & 0 deletions src/NLog/Internal/FileAppenders/SingleProcessFileAppender.cs
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,8 @@ internal class SingleProcessFileAppender : BaseFileAppender
public static readonly IFileAppenderFactory TheFactory = new Factory();

private FileStream _file;
private readonly bool _enableFileDeleteSimpleMonitor;
private DateTime _lastSimpleMonitorCheckTimeUtc;

/// <summary>
/// Initializes a new instance of the <see cref="SingleProcessFileAppender" /> class.
Expand All @@ -58,6 +60,8 @@ internal class SingleProcessFileAppender : BaseFileAppender
public SingleProcessFileAppender(string fileName, ICreateFileParameters parameters) : base(fileName, parameters)
{
_file = CreateFileStream(false);
_enableFileDeleteSimpleMonitor = parameters.EnableFileDeleteSimpleMonitor;
_lastSimpleMonitorCheckTimeUtc = OpenTimeUtc;
}

/// <summary>
Expand All @@ -73,6 +77,15 @@ public override void Write(byte[] bytes, int offset, int count)
return;
}

if (_enableFileDeleteSimpleMonitor)
{
if (MonitorForEnableFileDeleteEvent(FileName, ref _lastSimpleMonitorCheckTimeUtc))
{
_file.Dispose();
_file = CreateFileStream(false);
}
}

_file.Write(bytes, offset, count);
}

Expand Down
2 changes: 1 addition & 1 deletion src/NLog/Internal/MultiFileWatcher.cs
Original file line number Diff line number Diff line change
Expand Up @@ -131,7 +131,7 @@ internal void Watch(string fileName)
var directory = Path.GetDirectoryName(fileName);
if (!Directory.Exists(directory))
{
InternalLogger.Warn("Cannot watch {0} for changes as it doesn't exist", directory);
InternalLogger.Warn("Cannot watch file {0} for changes as directory {1} doesn't exist", fileName, directory);
return;
}

Expand Down
24 changes: 16 additions & 8 deletions src/NLog/Targets/FileTarget.cs
Original file line number Diff line number Diff line change
Expand Up @@ -440,7 +440,6 @@ public bool ConcurrentWrites
get
{
#if SupportsMutex

return _concurrentWrites ?? PlatformDetector.SupportsSharableMutex;
#else
return _concurrentWrites ?? false; // Better user experience for mobile platforms
Expand Down Expand Up @@ -740,11 +739,14 @@ private void RefreshArchiveFilePatternToWatch(string fileName, LogEventInfo logE
{
_fileAppenderCache.CheckCloseAppenders -= AutoCloseAppendersAfterArchive;

if (KeepFileOpen)
_fileAppenderCache.CheckCloseAppenders += AutoCloseAppendersAfterArchive;
bool mustWatchArchiving = IsArchivingEnabled && KeepFileOpen && ConcurrentWrites;
bool mustWatchActiveFile = KeepFileOpen && EnableFileDelete && !NetworkWrites && !ReplaceFileContentsOnEachWrite && !EnableFileDeleteSimpleMonitor;
if (mustWatchArchiving || mustWatchActiveFile)
{
_fileAppenderCache.CheckCloseAppenders += AutoCloseAppendersAfterArchive; // Activates FileSystemWatcher
}

#if !SILVERLIGHT && !__IOS__ && !__ANDROID__ && !NETSTANDARD1_3
bool mustWatchArchiving = IsArchivingEnabled && ConcurrentWrites && KeepFileOpen;
if (mustWatchArchiving)
{
string fileNamePattern = GetArchiveFileNamePattern(fileName, logEvent);
Expand Down Expand Up @@ -901,6 +903,12 @@ private IFileAppenderFactory GetFileAppenderFactory()

private bool IsArchivingEnabled => ArchiveAboveSize != ArchiveAboveSizeDisabled || ArchiveEvery != FileArchivePeriod.None;

private bool IsSimpleKeepFileOpen => KeepFileOpen && !NetworkWrites && !ReplaceFileContentsOnEachWrite && !ConcurrentWrites;

private bool EnableFileDeleteSimpleMonitor => EnableFileDelete && !PlatformDetector.IsWin32 && IsSimpleKeepFileOpen;

bool ICreateFileParameters.EnableFileDeleteSimpleMonitor => EnableFileDeleteSimpleMonitor;

/// <summary>
/// Initializes file logging by creating data structures that
/// enable efficient multi-file logging.
Expand Down Expand Up @@ -1359,7 +1367,7 @@ private void ArchiveFileMove(string fileName, string archiveFileName)
}
catch (IOException ex)
{
if (KeepFileOpen && !ConcurrentWrites)
if (IsSimpleKeepFileOpen)
throw; // No need to retry, when only single process access

if (!EnableFileDelete && KeepFileOpen)
Expand Down Expand Up @@ -1503,7 +1511,7 @@ private string GetArchiveDateFormatString(string defaultFormat)
return previousLogEventTimestamp;
}

if (!AutoFlush && KeepFileOpen && !ConcurrentWrites && !NetworkWrites && previousLogEventTimestamp < lastWriteTimeSource)
if (!AutoFlush && IsSimpleKeepFileOpen && previousLogEventTimestamp < lastWriteTimeSource)
{
InternalLogger.Trace("FileTarget(Name={0}): Using previous LogEvent-TimeStamp {1}, because AutoFlush=false affects File-LastModified {2}", Name, previousLogEventTimestamp, lastWriteTimeSource);
return previousLogEventTimestamp;
Expand Down Expand Up @@ -1940,7 +1948,7 @@ private string GetArchiveFileNameBasedOnTime(string fileName, LogEventInfo logEv
}

// Linux FileSystems doesn't always have file-birth-time, so NLog tries to provide a little help
DateTime? fallbackTimeSourceLinux = (previousLogEventTimestamp != DateTime.MinValue && KeepFileOpen && !ConcurrentWrites && !NetworkWrites) ? previousLogEventTimestamp : (DateTime?)null;
DateTime? fallbackTimeSourceLinux = (previousLogEventTimestamp != DateTime.MinValue && IsSimpleKeepFileOpen) ? previousLogEventTimestamp : (DateTime?)null;
var creationTimeSource = _fileAppenderCache.GetFileCreationTimeSource(fileName, fallbackTimeSourceLinux);
if (creationTimeSource == null)
{
Expand All @@ -1951,7 +1959,7 @@ private string GetArchiveFileNameBasedOnTime(string fileName, LogEventInfo logEv
{
if (TruncateArchiveTime(previousLogEventTimestamp, FileArchivePeriod.Minute) < TruncateArchiveTime(creationTimeSource.Value, FileArchivePeriod.Minute) && PlatformDetector.IsUnix)
{
if (KeepFileOpen && !ConcurrentWrites && !NetworkWrites)
if (IsSimpleKeepFileOpen)
{
InternalLogger.Debug("FileTarget(Name={0}): Adjusted file creation time from {1} to {2}. Linux FileSystem probably don't support file birthtime.", Name, creationTimeSource, previousLogEventTimestamp);
creationTimeSource = previousLogEventTimestamp;
Expand Down
23 changes: 13 additions & 10 deletions tests/NLog.UnitTests/Targets/FileTargetTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -120,17 +120,20 @@ public void SimpleFileTest(bool concurrentWrites, bool keepFileOpen, bool networ
}
}

#if !MONO
[Theory]
#else
[Theory(Skip="Not supported on MONO on Travis, because of FileSystemWatcher not working")]
#endif
[MemberData(nameof(SimpleFileTest_TestParameters))]
public void SimpleFileDeleteTest(bool concurrentWrites, bool keepFileOpen, bool networkWrites, bool forceManaged, bool forceMutexConcurrentWrites, bool optimizeBufferReuse)
{
bool isSimpleKeepFileOpen = keepFileOpen && !networkWrites && !concurrentWrites && IsTravis();
if (IsTravis() && concurrentWrites && keepFileOpen && !networkWrites)
{
Console.WriteLine("[SKIP] Not supported on MONO on Travis, because of FileSystemWatcher not working");
return;
}

var logFile = Path.GetTempFileName();
var logFile2 = Path.Combine(Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString()), Path.GetFileName(logFile));

try
{
var fileTarget = WrapFileTarget(new FileTarget
Expand All @@ -156,12 +159,12 @@ public void SimpleFileDeleteTest(bool concurrentWrites, bool keepFileOpen, bool

Directory.CreateDirectory(Path.GetDirectoryName(logFile2));
File.Move(logFile, logFile2);
if (keepFileOpen)
#if MONO
Thread.Sleep(500); // Allow AutoClose-Timer-Thread to react (FileWatcher depends on operating system, fallback to polling every 3 secs)
#else

if (isSimpleKeepFileOpen)
Thread.Sleep(1500); // Ensure EnableFileDeleteSimpleMonitor will trigger
else if (keepFileOpen && !networkWrites)
Thread.Sleep(150); // Allow AutoClose-Timer-Thread to react (FileWatcher schedules timer after 50 msec)
#endif

logger.Info("bbb");

LogManager.Configuration = null;
Expand Down