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 - Validate File CreationTimeUtc when non-Windows #1931

Merged
merged 1 commit into from
Feb 5, 2017
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
13 changes: 4 additions & 9 deletions src/NLog/Internal/FileAppenders/BaseFileAppender.cs
Original file line number Diff line number Diff line change
Expand Up @@ -337,24 +337,19 @@ private FileStream TryCreateFileStream(bool allowFileSharedWriting)

private void UpdateCreationTime()
{
if (File.Exists(this.FileName))
FileInfo fileInfo = new FileInfo(this.FileName);
if (fileInfo.Exists)
{
#if !SILVERLIGHT
this.CreationTimeUtc = File.GetCreationTimeUtc(this.FileName);
#else
this.CreationTimeUtc = File.GetCreationTime(this.FileName);
#endif
this.CreationTimeUtc = FileCharacteristicsHelper.ValidateFileCreationTime(fileInfo, (f) => f.GetCreationTimeUtc(), (f) => f.GetLastWriteTimeUtc()).Value;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not trying to be nitpicking, but isn't this infecting the performance? AFAIK lamba's have there costs, and this code is called a lot?

Copy link
Contributor Author

@snakefoot snakefoot Feb 3, 2017

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This code is called when opening the file. So it is only when using the RetryingMultiProcessAppender it is called a lot. But one can usually only allocate 500 FileStream-objects per second.

Also the lambdas are completely static without capture of this, so the compiler should turn them into zero allocations.

Ran a performance profiler of memory allocations using the RetryingMultiProcessAppender, and it within the BaseFileAppender.UpdateCreationTime() then the most expensive was the FileInfo-allocation, and the second most expensive was assigning the CreationTimeUtc where it used DateTime.ToLocalTime().

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

}
else
{
File.Create(this.FileName).Dispose();
this.CreationTimeUtc = DateTime.UtcNow;

#if !SILVERLIGHT
this.CreationTimeUtc = DateTime.UtcNow;
// Set the file's creation time to avoid being thwarted by Windows' Tunneling capabilities (https://support.microsoft.com/en-us/kb/172190).
File.SetCreationTimeUtc(this.FileName, this.CreationTimeUtc);
#else
this.CreationTimeUtc = File.GetCreationTime(this.FileName);
#endif
}
}
Expand Down
8 changes: 5 additions & 3 deletions src/NLog/Internal/FileAppenders/FileAppenderCache.cs
Original file line number Diff line number Diff line change
Expand Up @@ -416,11 +416,12 @@ public Mutex GetArchiveMutex(string fileName)
{
try
{
result = appender.GetFileCreationTimeUtc();
result = FileCharacteristicsHelper.ValidateFileCreationTime(appender, (f) => f.GetFileCreationTimeUtc(), (f) => f.CreationTimeUtc, (f) => f.GetFileLastWriteTimeUtc());
if (result.HasValue)
{
// Check if cached value is still valid, and update if not (Will automatically update CreationTimeSource)
if (result.Value != appender.CreationTimeUtc)
DateTime cachedTimeUtc = appender.CreationTimeUtc;
if (result.Value != cachedTimeUtc)
{
appender.CreationTimeUtc = result.Value;
}
Expand All @@ -439,7 +440,8 @@ public Mutex GetArchiveMutex(string fileName)
var fileInfo = new FileInfo(filePath);
if (fileInfo.Exists)
{
return Time.TimeSource.Current.FromSystemTime(fileInfo.GetCreationTimeUtc());
result = FileCharacteristicsHelper.ValidateFileCreationTime(fileInfo, (f) => f.GetCreationTimeUtc(), (f) => f.GetLastWriteTimeUtc()).Value;
return Time.TimeSource.Current.FromSystemTime(result.Value);
}
}

Expand Down
26 changes: 17 additions & 9 deletions src/NLog/Internal/FileAppenders/UnixMultiProcessFileAppender.cs
Original file line number Diff line number Diff line change
Expand Up @@ -76,6 +76,17 @@ BaseFileAppender IFileAppenderFactory.Open(string fileName, ICreateFileParameter

public UnixMultiProcessFileAppender(string fileName, ICreateFileParameters parameters) : base(fileName, parameters)
{
UnixFileInfo fileInfo = null;
bool fileExists = false;
try
{
fileInfo = new UnixFileInfo(fileName);
fileExists = fileInfo.Exists;
}
catch
{
}

int fd = Syscall.open(fileName, OpenFlags.O_CREAT | OpenFlags.O_WRONLY | OpenFlags.O_APPEND, (FilePermissions)(6 | (6 << 3) | (6 << 6)));
if (fd == -1)
{
Expand All @@ -93,21 +104,18 @@ public UnixMultiProcessFileAppender(string fileName, ICreateFileParameters param

try
{
bool fileExists = File.Exists(fileName);

this.file = new UnixStream(fd, true);

long filePosition = this.file.Position;
if (fileExists || filePosition > 0)
{
this.CreationTimeUtc = File.GetCreationTimeUtc(this.FileName);
if (this.CreationTimeUtc < DateTime.UtcNow - TimeSpan.FromSeconds(2) && filePosition == 0)
if (fileInfo != null)
{
this.CreationTimeUtc = FileCharacteristicsHelper.ValidateFileCreationTime(fileInfo, (f) => File.GetCreationTimeUtc(f.FullName), (f) => { f.Refresh(); return f.LastStatusChangeTimeUtc; }, (f) => DateTime.UtcNow).Value;
}
else
{
// File wasn't created "almost now".
Thread.Sleep(50);
// Having waited for a short amount of time usually means the file creation process has continued
// code execution just enough to the above point where it has fixed up the creation time.
this.CreationTimeUtc = File.GetCreationTimeUtc(this.FileName);
this.CreationTimeUtc = FileCharacteristicsHelper.ValidateFileCreationTime(fileName, (f) => File.GetCreationTimeUtc(f), (f) => DateTime.UtcNow).Value;
}
}
else
Expand Down
19 changes: 19 additions & 0 deletions src/NLog/Internal/FileCharacteristicsHelper.cs
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@

namespace NLog.Internal
{
using System;
using System.IO;

/// <summary>
Expand Down Expand Up @@ -64,5 +65,23 @@ public static FileCharacteristicsHelper CreateHelper(bool forcedManaged)
/// <param name="fileStream">The file stream.</param>
/// <returns>The file characteristics, if the file information was retrieved successfully, otherwise null.</returns>
public abstract FileCharacteristics GetFileCharacteristics(string fileName, FileStream fileStream);

public static DateTime? ValidateFileCreationTime<T>(T fileInfo, Func<T, DateTime?> primary, Func<T, DateTime?> fallback, Func<T, DateTime?> finalFallback = null)
{
DateTime? fileCreationTime = primary(fileInfo);
if (fileCreationTime.HasValue && fileCreationTime.Value.Year < 1980)
{
// Non-Windows-FileSystems doesn't always provide correct CreationTime/BirthTime
if (!PlatformDetector.IsDesktopWin32)
{
fileCreationTime = fallback(fileInfo);
if (finalFallback != null && (!fileCreationTime.HasValue || fileCreationTime.Value.Year < 1980))
{
fileCreationTime = finalFallback(fileInfo);
}
}
}
return fileCreationTime;
}
}
}