public void ThrowsOnNegativeFileSizeLimit()
{
var options = new W3CLoggerOptions();
var ex = Assert.Throws <ArgumentOutOfRangeException>(() => options.FileSizeLimit = -1);
Assert.Contains("FileSizeLimit must be positive", ex.Message);
}
private IOptionsMonitor <W3CLoggerOptions> CreateOptionsAccessor()
{
var options = new W3CLoggerOptions();
var optionsAccessor = Mock.Of <IOptionsMonitor <W3CLoggerOptions> >(o => o.CurrentValue == options);
return(optionsAccessor);
}
public async Task WritesToTextFile()
{
var mockSystemDateTime = new MockSystemDateTime
{
Now = _today
};
var path = Path.Combine(TempPath, Path.GetRandomFileName());
try
{
string fileName;
var options = new W3CLoggerOptions()
{
LogDirectory = path
};
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
logger.EnqueueMessage(_messageOne);
fileName = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0000.txt"));
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(fileName, _messageOne.Length).DefaultTimeout();
}
Assert.True(File.Exists(fileName));
Assert.Equal(_messageOne + Environment.NewLine, File.ReadAllText(fileName));
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public void ThrowsOnNegativeFlushInterval()
{
var options = new W3CLoggerOptions();
var ex = Assert.Throws <ArgumentOutOfRangeException>(() => options.FlushInterval = TimeSpan.FromSeconds(-1));
Assert.Contains("FlushInterval must be positive", ex.Message);
}
public void DoesNotInitializeWithOptionalFields()
{
var options = new W3CLoggerOptions();
// Optional fields shouldn't be logged by default
Assert.False(options.LoggingFields.HasFlag(W3CLoggingFields.UserName));
Assert.False(options.LoggingFields.HasFlag(W3CLoggingFields.Cookie));
}
public async Task WritesToNewFileOnOptionsChange()
{
var now = DateTimeOffset.Now;
if (now.Hour == 23)
{
// Don't bother trying to run this test when it's almost midnight.
return;
}
var path = Path.Combine(TempPath, Path.GetRandomFileName());
Directory.CreateDirectory(path);
try
{
var options = new W3CLoggerOptions()
{
LogDirectory = path,
LoggingFields = W3CLoggingFields.Time,
FileSizeLimit = 10000
};
var fileName1 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0000.txt"));
var fileName2 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0001.txt"));
var monitor = new OptionsWrapperMonitor <W3CLoggerOptions>(options);
await using (var logger = new FileLoggerProcessor(monitor, new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.EnqueueMessage(_messageOne);
await WaitForFile(fileName1, _messageOne.Length).DefaultTimeout();
options.LoggingFields = W3CLoggingFields.Date;
monitor.InvokeChanged();
logger.EnqueueMessage(_messageTwo);
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(fileName2, _messageTwo.Length).DefaultTimeout();
}
var actualFiles = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(2, actualFiles.Length);
Assert.True(File.Exists(fileName1));
Assert.True(File.Exists(fileName2));
Assert.Equal(_messageOne + Environment.NewLine, File.ReadAllText(fileName1));
Assert.Equal(_messageTwo + Environment.NewLine, File.ReadAllText(fileName2));
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task RespectsMaxFileCount()
{
var path = Path.Combine(TempPath, Path.GetRandomFileName());
Directory.CreateDirectory(path);
File.WriteAllText(Path.Combine(path, "randomFile.txt"), "Text");
var mockSystemDateTime = new MockSystemDateTime
{
Now = _today
};
try
{
string lastFileName;
var options = new W3CLoggerOptions()
{
LogDirectory = path,
RetainedFileCountLimit = 3,
FileSizeLimit = 5
};
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
for (int i = 0; i < 10; i++)
{
logger.EnqueueMessage(_messageOne);
}
lastFileName = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0009.txt"));
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(lastFileName, _messageOne.Length).DefaultTimeout();
for (int i = 0; i < 6; i++)
{
await WaitForRoll(Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.{i:0000}.txt"))).DefaultTimeout();
}
}
var actualFiles = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(4, actualFiles.Length);
Assert.Equal("randomFile.txt", actualFiles[0]);
for (int i = 1; i < 4; i++)
{
Assert.True((actualFiles[i].StartsWith($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}", StringComparison.InvariantCulture)));
}
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task RollsTextFiles()
{
var path = Path.Combine(TempPath, Path.GetRandomFileName());
try
{
string fileName1;
string fileName2;
var now = DateTimeOffset.Now;
var options = new W3CLoggerOptions()
{
LogDirectory = path,
FileSizeLimit = 5
};
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.EnqueueMessage(_messageOne);
logger.EnqueueMessage(_messageTwo);
fileName1 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0000.txt"));
fileName2 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0001.txt"));
// Pause for a bit before disposing so logger can finish logging
try
{
await WaitForFile(fileName2, _messageTwo.Length).DefaultTimeout();
}
catch
{
// Midnight could have struck between taking the DateTime & writing the log
// It also could have struck between writing file 1 & file 2
var tomorrow = now.AddDays(1);
if (!File.Exists(fileName1))
{
fileName1 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{tomorrow.Year:0000}{tomorrow.Month:00}{tomorrow.Day:00}.0000.txt"));
fileName2 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{tomorrow.Year:0000}{tomorrow.Month:00}{tomorrow.Day:00}.0001.txt"));
}
else if (!File.Exists(fileName2))
{
fileName2 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{tomorrow.Year:0000}{tomorrow.Month:00}{tomorrow.Day:00}.0000.txt"));
}
}
}
Assert.True(File.Exists(fileName1));
Assert.True(File.Exists(fileName2));
Assert.Equal(_messageOne + Environment.NewLine, File.ReadAllText(fileName1));
Assert.Equal(_messageTwo + Environment.NewLine, File.ReadAllText(fileName2));
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task RollsTextFilesBasedOnDate()
{
var mockSystemDateTime = new MockSystemDateTime
{
Now = _today
};
var tomorrow = _today.AddDays(1);
var path = Path.Combine(TempPath, Path.GetRandomFileName());
var options = new W3CLoggerOptions()
{
LogDirectory = path
};
try
{
string fileNameToday;
string fileNameTomorrow;
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
logger.EnqueueMessage(_messageOne);
fileNameToday = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0000.txt"));
await WaitForFile(fileNameToday, _messageOne.Length).DefaultTimeout();
mockSystemDateTime.Now = tomorrow;
logger.EnqueueMessage(_messageTwo);
fileNameTomorrow = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{tomorrow.Year:0000}{tomorrow.Month:00}{tomorrow.Day:00}.0000.txt"));
await WaitForFile(fileNameTomorrow, _messageTwo.Length).DefaultTimeout();
}
Assert.True(File.Exists(fileNameToday));
Assert.Equal(_messageOne + Environment.NewLine, File.ReadAllText(fileNameToday));
Assert.True(File.Exists(fileNameTomorrow));
Assert.Equal(_messageTwo + Environment.NewLine, File.ReadAllText(fileNameTomorrow));
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task WritesDateTime()
{
var path = Path.GetTempFileName() + "_";
var now = DateTime.Now;
var options = new W3CLoggerOptions()
{
LoggingFields = W3CLoggingFields.Date | W3CLoggingFields.Time | W3CLoggingFields.TimeTaken,
LogDirectory = path
};
try
{
await using (var logger = new TestW3CLogger(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
var elements = new string[W3CLoggingMiddleware._fieldsLength];
AddToList(elements, W3CLoggingMiddleware._dateIndex, _timestampOne.ToString("yyyy-MM-dd", CultureInfo.InvariantCulture));
AddToList(elements, W3CLoggingMiddleware._timeIndex, _timestampOne.ToString("HH:mm:ss", CultureInfo.InvariantCulture));
logger.Log(elements);
await logger.Processor.WaitForWrites(4).DefaultTimeout();
var lines = logger.Processor.Lines;
Assert.Equal("#Version: 1.0", lines[0]);
Assert.StartsWith("#Start-Date: ", lines[1]);
var startDate = DateTime.Parse(lines[1].Substring(13), CultureInfo.InvariantCulture);
// Assert that the log was written in the last 10 seconds
Assert.True(now.Subtract(startDate).TotalSeconds < 10);
Assert.Equal("#Fields: date time time-taken", lines[2]);
Assert.StartsWith("2021-01-02 03:04:05 ", lines[3]);
// Assert that the log's time-taken is within 10 seconds of DateTime.Now minus our arbitary start time (01/02/21 at 3:04:05)
Assert.True(now.Subtract(_timestampOne).TotalSeconds - Convert.ToDouble(lines[3].Substring(20), CultureInfo.InvariantCulture) < 10);
}
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task HandlesNullValuesAsync()
{
var path = Path.GetTempFileName() + "_";
var now = DateTime.UtcNow;
var options = new W3CLoggerOptions()
{
LoggingFields = W3CLoggingFields.UriQuery | W3CLoggingFields.Host | W3CLoggingFields.ProtocolStatus,
LogDirectory = path
};
try
{
await using (var logger = new TestW3CLogger(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
var elements = new string[W3CLoggingMiddleware._fieldsLength];
AddToList(elements, W3CLoggingMiddleware._uriQueryIndex, null);
AddToList(elements, W3CLoggingMiddleware._hostIndex, null);
AddToList(elements, W3CLoggingMiddleware._protocolStatusIndex, null);
logger.Log(elements);
await logger.Processor.WaitForWrites(4).DefaultTimeout();
var lines = logger.Processor.Lines;
Assert.Equal("#Version: 1.0", lines[0]);
Assert.StartsWith("#Start-Date: ", lines[1]);
var startDate = DateTime.Parse(lines[1].Substring(13), CultureInfo.InvariantCulture);
// Assert that the log was written in the last 10 seconds
Assert.True(now.Subtract(startDate).TotalSeconds < 10);
Assert.Equal("#Fields: cs-uri-query sc-status cs-host", lines[2]);
Assert.Equal("- - -", lines[3]);
}
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public void ThrowsOnEmptyFileName()
{
var options = new W3CLoggerOptions();
Assert.Throws <ArgumentNullException>(() => options.FileName = "");
}
public async Task InstancesWriteToSameDirectory()
{
var mockSystemDateTime = new MockSystemDateTime
{
Now = _today
};
var path = Path.Combine(TempPath, Path.GetRandomFileName());
Directory.CreateDirectory(path);
try
{
var options = new W3CLoggerOptions()
{
LogDirectory = path,
RetainedFileCountLimit = 10,
FileSizeLimit = 5
};
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
for (int i = 0; i < 3; i++)
{
logger.EnqueueMessage(_messageOne);
}
var filePath = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0002.txt"));
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(filePath, _messageOne.Length).DefaultTimeout();
}
// Second instance should pick up where first one left off
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
for (int i = 0; i < 3; i++)
{
logger.EnqueueMessage(_messageOne);
}
var filePath = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0005.txt"));
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(filePath, _messageOne.Length).DefaultTimeout();
}
var actualFiles1 = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(6, actualFiles1.Length);
for (int i = 0; i < 6; i++)
{
Assert.Contains($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.{i:0000}.txt", actualFiles1[i]);
}
// Third instance should roll to 5 most recent files
options.RetainedFileCountLimit = 5;
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
logger.EnqueueMessage(_messageOne);
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0006.txt")), _messageOne.Length).DefaultTimeout();
await WaitForRoll(Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0000.txt"))).DefaultTimeout();
await WaitForRoll(Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0001.txt"))).DefaultTimeout();
}
var actualFiles2 = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(5, actualFiles2.Length);
for (int i = 0; i < 5; i++)
{
Assert.Equal($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.{i + 2:0000}.txt", actualFiles2[i]);
}
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task RespectsMaxFileCount()
{
var path = Path.Combine(TempPath, Path.GetRandomFileName());
Directory.CreateDirectory(path);
File.WriteAllText(Path.Combine(path, "randomFile.txt"), "Text");
try
{
string lastFileName;
var now = DateTimeOffset.Now;
var tomorrow = now.AddDays(1);
var options = new W3CLoggerOptions()
{
LogDirectory = path,
RetainedFileCountLimit = 3,
FileSizeLimit = 5
};
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
for (int i = 0; i < 10; i++)
{
logger.EnqueueMessage(_messageOne);
}
lastFileName = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0009.txt"));
// Pause for a bit before disposing so logger can finish logging
try
{
await WaitForFile(lastFileName, _messageOne.Length).DefaultTimeout();
for (int i = 0; i < 6; i++)
{
await WaitForRoll(Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.{i:0000}.txt"))).DefaultTimeout();
}
}
catch
{
// Midnight could have struck between taking the DateTime & writing the log.
// It also could have struck any time after writing the first file.
// So we keep going even if waiting timed out, in case we're wrong about the assumed file name
}
}
var actualFiles = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(4, actualFiles.Length);
Assert.Equal("randomFile.txt", actualFiles[0]);
for (int i = 1; i < 4; i++)
{
// File name will either start with today's date or tomorrow's date (if midnight struck during the execution of the test)
Assert.True((actualFiles[i].StartsWith($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}", StringComparison.InvariantCulture)) ||
(actualFiles[i].StartsWith($"{options.FileName}{tomorrow.Year:0000}{tomorrow.Month:00}{tomorrow.Day:00}", StringComparison.InvariantCulture)));
}
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public void ThrowsOnEmptyLogDirectory()
{
var options = new W3CLoggerOptions();
Assert.Throws <ArgumentNullException>(() => options.LogDirectory = "");
}
public async Task WritesToNewFileOnNewInstance()
{
var mockSystemDateTime = new MockSystemDateTime
{
Now = _today
};
var path = Path.Combine(TempPath, Path.GetRandomFileName());
Directory.CreateDirectory(path);
try
{
var options = new W3CLoggerOptions()
{
LogDirectory = path,
FileSizeLimit = 5
};
var fileName1 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0000.txt"));
var fileName2 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0001.txt"));
var fileName3 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{_today.Year:0000}{_today.Month:00}{_today.Day:00}.0002.txt"));
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
logger.EnqueueMessage(_messageOne);
logger.EnqueueMessage(_messageTwo);
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(fileName2, _messageTwo.Length).DefaultTimeout();
}
// Even with a big enough FileSizeLimit, we still won't try to write to files from a previous instance.
options.FileSizeLimit = 10000;
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.SystemDateTime = mockSystemDateTime;
logger.EnqueueMessage(_messageThree);
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(fileName3, _messageThree.Length).DefaultTimeout();
}
var actualFiles = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(3, actualFiles.Length);
Assert.True(File.Exists(fileName1));
Assert.True(File.Exists(fileName2));
Assert.True(File.Exists(fileName3));
Assert.Equal(_messageOne + Environment.NewLine, File.ReadAllText(fileName1));
Assert.Equal(_messageTwo + Environment.NewLine, File.ReadAllText(fileName2));
Assert.Equal(_messageThree + Environment.NewLine, File.ReadAllText(fileName3));
}
finally
{
Helpers.DisposeDirectory(path);
}
}
public async Task WritesToNewFileOnNewInstance()
{
var now = DateTimeOffset.Now;
if (now.Hour == 23)
{
// Don't bother trying to run this test when it's almost midnight.
return;
}
var path = Path.Combine(TempPath, Path.GetRandomFileName());
Directory.CreateDirectory(path);
try
{
var options = new W3CLoggerOptions()
{
LogDirectory = path,
FileSizeLimit = 5
};
var fileName1 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0000.txt"));
var fileName2 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0001.txt"));
var fileName3 = Path.Combine(path, FormattableString.Invariant($"{options.FileName}{now.Year:0000}{now.Month:00}{now.Day:00}.0002.txt"));
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.EnqueueMessage("Message one");
logger.EnqueueMessage("Message two");
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(fileName2).DefaultTimeout();
}
// Even with a big enough FileSizeLimit, we still won't try to write to files from a previous instance.
options.FileSizeLimit = 10000;
await using (var logger = new FileLoggerProcessor(new OptionsWrapperMonitor <W3CLoggerOptions>(options), new HostingEnvironment(), NullLoggerFactory.Instance))
{
logger.EnqueueMessage("Message three");
// Pause for a bit before disposing so logger can finish logging
await WaitForFile(fileName3).DefaultTimeout();
}
var actualFiles = new DirectoryInfo(path)
.GetFiles()
.Select(f => f.Name)
.OrderBy(f => f)
.ToArray();
Assert.Equal(3, actualFiles.Length);
Assert.True(File.Exists(fileName1));
Assert.True(File.Exists(fileName2));
Assert.True(File.Exists(fileName3));
Assert.Equal("Message one" + Environment.NewLine, File.ReadAllText(fileName1));
Assert.Equal("Message two" + Environment.NewLine, File.ReadAllText(fileName2));
Assert.Equal("Message three" + Environment.NewLine, File.ReadAllText(fileName3));
}
finally
{
Helpers.DisposeDirectory(path);
}
}
