Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -40,12 +40,23 @@ Example of the configuration section in appsettings.json:
"Path": "app.log",
"Append": true,
"MinLevel": "Warning", // min level for the file logger
"IncludeScopes": false, // set to true to include logging scopes
"FileSizeLimitBytes": 0, // use to activate rolling file behaviour
"MaxRollingFiles": 0 // use to specify max number of log files
}
}
```

## Logging scopes
Logging scopes can be included in the default log entry format by setting `FileLoggerOptions.IncludeScopes` to `true` (the default is `false`):
```csharp
loggingBuilder.AddFile("app.log", fileLoggerOpts => {
fileLoggerOpts.IncludeScopes = true;
});
```
Active scopes are written from outermost to innermost before the message, for example: `=> Request 123 => Processing order`.
`IncludeScopes` applies only to the built-in formatter and does not change custom `FormatLogEntry` behavior.

## Rolling File
This feature is activated with `FileLoggerOptions` properties: `FileSizeLimitBytes` and `MaxRollingFiles`. Lets assume that file logger is configured for "test.log":

Expand Down
7 changes: 5 additions & 2 deletions src/NReco.Logging.File/FileLogger.cs
Original file line number Diff line number Diff line change
Expand Up @@ -25,19 +25,20 @@
private readonly string logName;
private readonly FileLoggerProvider LoggerPrv;

public FileLogger(string logName, FileLoggerProvider loggerPrv) {

Check warning on line 28 in src/NReco.Logging.File/FileLogger.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLogger.FileLogger(string, FileLoggerProvider)'
this.logName = logName;
this.LoggerPrv = loggerPrv;
}
public IDisposable BeginScope<TState>(TState state) {

Check warning on line 32 in src/NReco.Logging.File/FileLogger.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLogger.BeginScope<TState>(TState)'
return null;
// Support BeginScope when FileLogger is used directly, matching ConsoleLogger.
return LoggerPrv.ScopeProvider?.Push(state);
}

public bool IsEnabled(LogLevel logLevel) {

Check warning on line 37 in src/NReco.Logging.File/FileLogger.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLogger.IsEnabled(LogLevel)'
return logLevel>=LoggerPrv.MinLevel;
}

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state,

Check warning on line 41 in src/NReco.Logging.File/FileLogger.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLogger.Log<TState>(LogLevel, EventId, TState, Exception, Func<TState, Exception, string>)'
Exception exception, Func<TState, Exception, string> formatter) {
if (!IsEnabled(logLevel)) {
return;
Expand All @@ -58,14 +59,16 @@
new LogMessage(logName, logLevel, eventId, message, exception)));
}
else {
// Pass no scope provider unless explicitly enabled so the original formatting path does no scope work.
LoggerPrv.WriteEntry(
Format.StringLogEntryFormatter.Instance.LowAllocLogEntryFormat(
logName,
LoggerPrv.UseUtcTimestamp ? DateTime.UtcNow : DateTime.Now,
logLevel,
eventId,
message,
exception));
exception,
LoggerPrv.Options.IncludeScopes ? LoggerPrv.ScopeProvider : null));
}
}

Expand Down
5 changes: 5 additions & 0 deletions src/NReco.Logging.File/FileLoggerConfig.cs
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,11 @@ public class FileLoggerConfig {
/// Minimal logging level for the file logger.
/// </summary>
public LogLevel MinLevel { get; set; } = LogLevel.Trace;

/// <summary>
/// Gets or sets a value that indicates whether scopes are included. Defaults to false.
/// </summary>
public bool IncludeScopes { get; set; }
}

}
1 change: 1 addition & 0 deletions src/NReco.Logging.File/FileLoggerExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@

namespace NReco.Logging.File {

public static class FileLoggerExtensions {

Check warning on line 22 in src/NReco.Logging.File/FileLoggerExtensions.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLoggerExtensions'

/// <summary>
/// Adds a file logger.
Expand Down Expand Up @@ -126,6 +126,7 @@
fileLoggerOptions.MinLevel = config.MinLevel;
fileLoggerOptions.FileSizeLimitBytes = config.FileSizeLimitBytes;
fileLoggerOptions.MaxRollingFiles = config.MaxRollingFiles;
fileLoggerOptions.IncludeScopes = config.IncludeScopes;

if (configure != null)
configure(fileLoggerOptions);
Expand Down
6 changes: 6 additions & 0 deletions src/NReco.Logging.File/FileLoggerOptions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,12 @@ public class FileLoggerOptions {
/// </summary>
public bool UseUtcTimestamp { get; set; }

/// <summary>
/// Gets or sets a value that indicates whether scopes are included. Defaults to false.
/// </summary>
/// <remarks>To preserve the existing <see cref="LogMessage"/> API, scopes are included only by the built-in formatter. Custom <see cref="FormatLogEntry"/> delegates do not receive scope data.</remarks>
public bool IncludeScopes { get; set; }

/// <summary>
/// Custom formatter for the log entry line.
/// </summary>
Expand Down
9 changes: 8 additions & 1 deletion src/NReco.Logging.File/FileLoggerProvider.cs
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@
/// Generic file logger provider.
/// </summary>
[ProviderAlias("File")]
public class FileLoggerProvider : ILoggerProvider {
public class FileLoggerProvider : ILoggerProvider, ISupportExternalScope {

private string LogFileName;

Expand All @@ -36,12 +36,13 @@
private readonly FileWriter fWriter;

internal FileLoggerOptions Options { get; private set; }
internal IExternalScopeProvider ScopeProvider { get; private set; }

private bool Append => Options.Append;
private long FileSizeLimitBytes => Options.FileSizeLimitBytes;
private int MaxRollingFiles => Options.MaxRollingFiles;

public LogLevel MinLevel {

Check warning on line 45 in src/NReco.Logging.File/FileLoggerProvider.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLoggerProvider.MinLevel'
get => Options.MinLevel;
set { Options.MinLevel = value; }
}
Expand Down Expand Up @@ -78,13 +79,13 @@
set { Options.HandleFileError = value; }
}

public FileLoggerProvider(string fileName) : this(fileName, true) {

Check warning on line 82 in src/NReco.Logging.File/FileLoggerProvider.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLoggerProvider.FileLoggerProvider(string)'
}

public FileLoggerProvider(string fileName, bool append) : this(fileName, new FileLoggerOptions() { Append = append }) {

Check warning on line 85 in src/NReco.Logging.File/FileLoggerProvider.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLoggerProvider.FileLoggerProvider(string, bool)'
}

public FileLoggerProvider(string fileName, FileLoggerOptions options) {

Check warning on line 88 in src/NReco.Logging.File/FileLoggerProvider.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLoggerProvider.FileLoggerProvider(string, FileLoggerOptions)'
Options = options;
LogFileName = Environment.ExpandEnvironmentVariables(fileName);

Expand All @@ -95,10 +96,16 @@
TaskCreationOptions.LongRunning);
}

public ILogger CreateLogger(string categoryName) {

Check warning on line 99 in src/NReco.Logging.File/FileLoggerProvider.cs

View workflow job for this annotation

GitHub Actions / build

Missing XML comment for publicly visible type or member 'FileLoggerProvider.CreateLogger(string)'
return loggers.GetOrAdd(categoryName, CreateLoggerImplementation);
}

/// <inheritdoc />
public void SetScopeProvider(IExternalScopeProvider scopeProvider) {
// Keep this centrally so existing loggers also observe a replacement, matching ConsoleLogger's defensive behavior.
ScopeProvider = scopeProvider;
}

public void Dispose() {
entryQueue.CompleteAdding();
try {
Expand Down
59 changes: 57 additions & 2 deletions src/NReco.Logging.File/Format/StringLogEntryFormatter.cs
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
using System;
using System.Buffers;
using System.Collections.Generic;
using System.Runtime.CompilerServices;
using System.Text;
using Microsoft.Extensions.Logging;
Expand All @@ -14,6 +15,11 @@ namespace NReco.Logging.File.Format {
public class StringLogEntryFormatter {

internal static readonly StringLogEntryFormatter Instance = new StringLogEntryFormatter();
// ForEachScope cannot use the ref-struct ValueStringBuilder as callback state, so scopes are collected into a
// reusable list first and appended to the final ValueStringBuilder directly. This list holds one entry per
// active scope, so its capacity stays as small as the scope nesting and never needs to be trimmed.
[ThreadStatic]
private static List<string> cachedScopes;

public StringLogEntryFormatter() {
}
Expand Down Expand Up @@ -64,6 +70,31 @@ public string StringBuilderLogEntryFormat(LogMessage logMsg, DateTime timeStamp)
/// This is a low-allocation optimized tab-separated log entry formatter that formats output identical to <see cref="StringBuilderLogEntryFormat"/>
/// </summary>
public string LowAllocLogEntryFormat(string logName, DateTime timeStamp, LogLevel logLevel, EventId eventId, string message, Exception exception) {
return LowAllocLogEntryFormatCore(logName, timeStamp, logLevel, eventId, message, exception, null);
}

internal string LowAllocLogEntryFormat(string logName, DateTime timeStamp, LogLevel logLevel, EventId eventId, string message, Exception exception, IExternalScopeProvider scopeProvider) {
if (scopeProvider == null) {
return LowAllocLogEntryFormatCore(logName, timeStamp, logLevel, eventId, message, exception, null);
}

var scopes = cachedScopes ?? new List<string>();
// Check the list out of the cache so re-entrant logging on this thread cannot modify it.
cachedScopes = null;
try {
// Render each scope exactly once. Only the resulting strings are kept, so user scope objects are not
// held alive after the entry is formatted.
scopeProvider.ForEachScope(static (scope, state) => state.Add(scope?.ToString()), scopes);

return LowAllocLogEntryFormatCore(logName, timeStamp, logLevel, eventId, message, exception, scopes.Count > 0 ? scopes : null);
} finally {
scopes.Clear();
// Return this list only if a re-entrant log entry has not already replenished the cache.
cachedScopes ??= scopes;
}
}

private string LowAllocLogEntryFormatCore(string logName, DateTime timeStamp, LogLevel logLevel, EventId eventId, string message, Exception exception, List<string> scopes) {
const int MaxStackAllocatedBufferLength = 256;
var logMessageLength = CalculateLogMessageLength();
char[] charBuffer = null;
Expand All @@ -74,7 +105,8 @@ public string LowAllocLogEntryFormat(string logName, DateTime timeStamp, LogLeve

// default formatting logic
using var logBuilder = new ValueStringBuilder(buffer);
if (!string.IsNullOrEmpty(message)) {
// Scopes are useful context even when an exception is logged without a message.
if (!string.IsNullOrEmpty(message) || scopes != null) {
timeStamp.TryFormatO(logBuilder.RemainingRawChars, out var charsWritten);
logBuilder.AppendSpan(charsWritten);
logBuilder.Append('\t');
Expand All @@ -90,7 +122,17 @@ public string LowAllocLogEntryFormat(string logName, DateTime timeStamp, LogLeve
logBuilder.AppendSpan(charsWritten);
}
logBuilder.Append("]\t");
logBuilder.Append(message);
if (scopes != null) {
// Match SimpleConsoleFormatter: render active scopes outer-to-inner with "=>" separators.
for (var i = 0; i < scopes.Count; i++) {
logBuilder.Append(i == 0 ? "=> " : " => ");
logBuilder.Append(scopes[i]);
}
logBuilder.Append('\t');
}
if (!string.IsNullOrEmpty(message)) {
logBuilder.Append(message);
}
}

if (exception != null) {
Expand All @@ -114,8 +156,21 @@ int CalculateLogMessageLength() {
+ 3 /* "]\t[" */
+ (eventId.Name?.Length ?? eventId.Id.GetFormattedLength())
+ 2 /* "]\t" */
+ GetScopesLength()
+ (message?.Length ?? 0);
}

int GetScopesLength() {
if (scopes is null) {
return 0;
}

var scopesLength = 1 /* '\t' */;
for (var i = 0; i < scopes.Count; i++) {
scopesLength += (i == 0 ? 3 /* "=> " */ : 4 /* " => " */) + (scopes[i]?.Length ?? 0);
}
return scopesLength;
}
}

public string LowAllocLogEntryFormat(LogMessage logMsg, DateTime timeStamp)
Expand Down
97 changes: 97 additions & 0 deletions test/NReco.Logging.Tests/FileProviderTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@
logger.LogInformation("Line1");
factory.Dispose();

Assert.Equal(1, System.IO.File.ReadAllLines(tmpFile).Length);

Check warning on line 27 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Do not use Assert.Equal() to check for collection size. Use Assert.Single instead. (https://xunit.net/xunit.analyzers/rules/xUnit2013)

Check warning on line 27 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Do not use Assert.Equal() to check for collection size. Use Assert.Single instead. (https://xunit.net/xunit.analyzers/rules/xUnit2013)

factory = new LoggerFactory();
logger = factory.CreateLogger("TEST");
Expand All @@ -32,7 +32,7 @@
logger.LogInformation("Line2");
factory.Dispose();

Assert.Equal(1, System.IO.File.ReadAllLines(tmpFile).Length); // file should be overwritten

Check warning on line 35 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Do not use Assert.Equal() to check for collection size. Use Assert.Single instead. (https://xunit.net/xunit.analyzers/rules/xUnit2013)

Check warning on line 35 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Do not use Assert.Equal() to check for collection size. Use Assert.Single instead. (https://xunit.net/xunit.analyzers/rules/xUnit2013)

} finally {
System.IO.File.Delete(tmpFile);
Expand Down Expand Up @@ -268,7 +268,7 @@
);

}
Task.WaitAll(writeTasks.ToArray());

Check warning on line 271 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Test methods should not use blocking task operations, as they can cause deadlocks. Use an async test method and await instead. (https://xunit.net/xunit.analyzers/rules/xUnit1031)

Check warning on line 271 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Test methods should not use blocking task operations, as they can cause deadlocks. Use an async test method and await instead. (https://xunit.net/xunit.analyzers/rules/xUnit1031)

factory.Dispose();
int lines = 0;
Expand Down Expand Up @@ -480,7 +480,7 @@
var t = Task.Run(() => {
writeSomethingToLogger(logger, 2000);
});
Assert.True(t.Wait(1000), "Logger queue blocks app's log calls.");

Check warning on line 483 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Test methods should not use blocking task operations, as they can cause deadlocks. Use an async test method and await instead. (https://xunit.net/xunit.analyzers/rules/xUnit1031)

Check warning on line 483 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Test methods should not use blocking task operations, as they can cause deadlocks. Use an async test method and await instead. (https://xunit.net/xunit.analyzers/rules/xUnit1031)

factory.Dispose();

Expand Down Expand Up @@ -511,11 +511,108 @@

var logLines = System.IO.File.ReadAllLines(logFileName);
Assert.Single(logLines);
Assert.False(logLines[0].Contains("TEST2"));

Check warning on line 514 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Do not use Assert.False() to check for substrings. Use Assert.DoesNotContain instead. (https://xunit.net/xunit.analyzers/rules/xUnit2009)

Check warning on line 514 in test/NReco.Logging.Tests/FileProviderTests.cs

View workflow job for this annotation

GitHub Actions / build

Do not use Assert.False() to check for substrings. Use Assert.DoesNotContain instead. (https://xunit.net/xunit.analyzers/rules/xUnit2009)
} finally {
CleanupTempDir(tmpDir, new[] { factory });
}
}

[Fact]
public void ScopesAreDisabledByDefault() {
var tmpFile = Path.GetTempFileName();
try {
using (var factory = new LoggerFactory()) {
factory.AddProvider(new FileLoggerProvider(tmpFile, false));
var logger = factory.CreateLogger("TEST");
using (logger.BeginScope("Scope")) {
logger.LogInformation("Message");
}
}

var logEntry = System.IO.File.ReadAllText(tmpFile);
// Scopes should not appear unless they are explicitly enabled.
Assert.DoesNotContain("Scope", logEntry);
Assert.Contains("\tMessage", logEntry);
} finally {
System.IO.File.Delete(tmpFile);
}
}

[Fact]
public void WriteNestedScopesInOuterToInnerOrder() {
var tmpFile = Path.GetTempFileName();
try {
using (var factory = new LoggerFactory()) {
factory.AddProvider(new FileLoggerProvider(tmpFile, new FileLoggerOptions() {
Append = false,
IncludeScopes = true
}));
var logger = factory.CreateLogger("TEST");
using (logger.BeginScope("Outer")) {
using (logger.BeginScope("Inner")) {
logger.LogInformation("Nested");
}
logger.LogInformation("Outer only");
}
logger.LogInformation("No scope");
}

var logEntries = System.IO.File.ReadAllLines(tmpFile);
// Disposing the inner scope should leave the outer scope active; disposing both should leave neither.
Assert.Equal("=> Outer => Inner", logEntries[0].Split('\t')[4]);
Assert.Equal("Nested", logEntries[0].Split('\t')[5]);

Assert.Equal("=> Outer", logEntries[1].Split('\t')[4]);
Assert.Equal("Outer only", logEntries[1].Split('\t')[5]);

Assert.Equal("No scope", logEntries[2].Split('\t')[4]);
} finally {
System.IO.File.Delete(tmpFile);
}
}

[Fact]
public void LoggerCreatedBeforeScopeProviderUsesScopes() {
var tmpFile = Path.GetTempFileName();
try {
using (var provider = new FileLoggerProvider(tmpFile, new FileLoggerOptions() {
Append = false,
IncludeScopes = true
})) {
var logger = provider.CreateLogger("TEST");
provider.SetScopeProvider(new LoggerExternalScopeProvider());
using (logger.BeginScope("Scope")) {
logger.LogInformation("Message");
}
}

// A logger created before SetScopeProvider should use the provider assigned later.
Assert.Contains("\t=> Scope\tMessage", System.IO.File.ReadAllText(tmpFile));
} finally {
System.IO.File.Delete(tmpFile);
}
}

[Fact]
public void CustomFormatLogEntryIgnoresScopes() {
var tmpFile = Path.GetTempFileName();
try {
using (var factory = new LoggerFactory()) {
factory.AddProvider(new FileLoggerProvider(tmpFile, new FileLoggerOptions() {
Append = false,
IncludeScopes = true,
FormatLogEntry = logMessage => $"Custom: {logMessage.Message}"
}));
var logger = factory.CreateLogger("TEST");
using (logger.BeginScope("Scope")) {
logger.LogInformation("Message");
}
}

Assert.Equal($"Custom: Message{Environment.NewLine}", System.IO.File.ReadAllText(tmpFile));
} finally {
System.IO.File.Delete(tmpFile);
}
}
}
}
Loading
Loading