Skip to content

Modernize Marten's default logger #3788

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.

Sign up for GitHub

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

Merged
jeremydmiller merged 1 commit into from
May 11, 2025
Merged

Modernize Marten's default logger #3788

Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
104 changes: 66 additions & 38 deletions src/Marten/DefaultMartenLogger.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,11 +10,13 @@ namespace Marten;

internal class DefaultMartenLogger: IMartenLogger, IMartenSessionLogger
{
private Stopwatch _stopwatch;
private long? _timestamp;
private readonly DefaultLoggingWriter _loggerOutput;

public DefaultMartenLogger(ILogger inner)
{
Inner = inner;
_loggerOutput = new DefaultLoggingWriter(inner);
}

public ILogger Inner { get; }
Expand All @@ -26,101 +28,127 @@ public IMartenSessionLogger StartSession(IQuerySession session)

public void SchemaChange(string sql)
{
if (Inner.IsEnabled(LogLevel.Information))
{
Inner.LogInformation("Executed schema update SQL:\n{SQL}", sql);
}
_loggerOutput.SchemaChange(sql);
}

public void LogSuccess(NpgsqlCommand command)
{
_stopwatch?.Stop();

if (Inner.IsEnabled(LogLevel.Debug))
{
var message = "Marten executed in {milliseconds} ms, SQL: {SQL}\n{PARAMS}";
var parameters = command.Parameters.OfType<NpgsqlParameter>()
var duration = Stopwatch.GetElapsedTime(_timestamp!.Value);
var parameters = command.Parameters
.Select(p => $" {p.ParameterName}: {p.Value}")
.Join(Environment.NewLine);
Inner.LogDebug(message, _stopwatch?.ElapsedMilliseconds ?? 0, command.CommandText, parameters);
_loggerOutput.LogSuccess(duration.TotalMilliseconds, command.CommandText, parameters);
}
}

public void LogSuccess(NpgsqlBatch batch)
{
if (Inner.IsEnabled(LogLevel.Debug))
{
var duration = Stopwatch.GetElapsedTime(_timestamp!.Value);
foreach (var command in batch.BatchCommands)
{
var message = "Marten executed, SQL: {SQL}\n{PARAMS}";
var parameters = command.Parameters.OfType<NpgsqlParameter>()
.Select(p => $" {p.ParameterName}: {p.Value}")
.Join(Environment.NewLine);
Inner.LogDebug(message, _stopwatch?.ElapsedMilliseconds ?? 0, command.CommandText, parameters);
_loggerOutput.LogSuccess(duration.TotalMilliseconds, command.CommandText, parameters);
}
}
}

public void LogFailure(NpgsqlCommand command, Exception ex)
{
_stopwatch?.Stop();

var message = "Marten encountered an exception executing \n{SQL}\n{PARAMS}";
var parameters = command.Parameters.OfType<NpgsqlParameter>()
var parameters = command.Parameters
.Select(p => $" {p.ParameterName}: {p.Value}")
.Join(Environment.NewLine);
Inner.LogError(ex, message, command.CommandText, parameters);

_loggerOutput.LogError(ex, command.CommandText, parameters);
}

public void LogFailure(NpgsqlBatch batch, Exception ex)
{
_stopwatch?.Stop();

var message = "Marten encountered an exception executing \n{SQL}\n{PARAMS}";

foreach (var command in batch.BatchCommands)
{
var parameters = command.Parameters.OfType<NpgsqlParameter>()
.Select(p => $" {p.ParameterName}: {p.Value}")
.Join(Environment.NewLine);
Inner.LogError(ex, message, command.CommandText, parameters);

_loggerOutput.LogError(ex, command.CommandText, parameters);
}
}

public void RecordSavedChanges(IDocumentSession session, IChangeSet commit)
public void LogFailure(Exception ex, string message)
{
_stopwatch?.Stop();
_loggerOutput.LogError(ex, message);
}

var lastCommit = commit;
public void RecordSavedChanges(IDocumentSession session, IChangeSet commit)
{
if (Inner.IsEnabled(LogLevel.Debug))
{
Inner.LogDebug(
"Persisted {UpdateCount} updates in {ElapsedMilliseconds} ms, {InsertedCount} inserts, and {DeletedCount} deletions",
lastCommit.Updated.Count(), _stopwatch?.ElapsedMilliseconds ?? 0, lastCommit.Inserted.Count(),
lastCommit.Deleted.Count());
var duration = Stopwatch.GetElapsedTime(_timestamp!.Value);
_loggerOutput.RecordSavedChanges(commit.Updated.Count(),
duration.TotalMilliseconds,
commit.Inserted.Count(),
commit.Deleted.Count());
}
}

public void OnBeforeExecute(NpgsqlCommand command)
{
if (Inner.IsEnabled(LogLevel.Debug))
{
_stopwatch = new Stopwatch();
_stopwatch.Start();
_timestamp = Stopwatch.GetTimestamp();
}
}

public void LogFailure(Exception ex, string message)
{
Inner.LogError(ex, message);
}

public void OnBeforeExecute(NpgsqlBatch batch)
{
if (Inner.IsEnabled(LogLevel.Debug))
{
_stopwatch = new Stopwatch();
_stopwatch.Start();
_timestamp = Stopwatch.GetTimestamp();
}
}
}

internal sealed partial class DefaultLoggingWriter
{
private readonly ILogger _logger;

public DefaultLoggingWriter(ILogger logger)
{
_logger = logger;
}

[LoggerMessage(
Level = LogLevel.Information,
Message = "Executed schema update SQL:\n{SQL}")]
public partial void SchemaChange(string sql);

[LoggerMessage(
Level = LogLevel.Debug,
Message = "Marten executed in {milliseconds} ms, SQL: {SQL}\n{PARAMETERS}",
SkipEnabledCheck = true)]
public partial void LogSuccess(double milliseconds, string sql, string parameters);

[LoggerMessage(
Level = LogLevel.Error,
Message = "Marten encountered an exception executing \n{SQL}\n{PARAMETERS}")]
public partial void LogError(Exception ex, string sql, string parameters);

[LoggerMessage(
Level = LogLevel.Error,
Message = "Marten encountered an exception with message: {MESSAGE}")]
public partial void LogError(Exception ex, string message);

[LoggerMessage(
Level = LogLevel.Debug,
Message = "Persisted {UpdateCount} updates in {ElapsedMilliseconds} ms, {InsertedCount} inserts, and {DeletedCount} deletions",
SkipEnabledCheck = true)]
public partial void RecordSavedChanges(int updateCount, double elapsedMilliseconds, int insertedCount, int deletedCount);

}


Loading