Failed to write event through SerilogLogger: System.ArgumentException: An item with the same key has already been added. Key: EventId

[gplogix]

In file SerilogLogger, in the function LogEvent PrepareWrite<TState>(LogEventLevel level, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter), if the state is IEnumerable<KeyValuePair<string, object> already contains a property "EventId", the following exception is triggered :
Failed to write event through SerilogLogger: System.ArgumentException: An item with the same key has already been added. Key: EventId.

Solution :
Replace :
properties.Add("EventId", _eventIdPropertyCache.GetOrCreatePropertyValue(in eventId));
By :
properties["EventId"] = _eventIdPropertyCache.GetOrCreatePropertyValue(in eventId);

[nblumhardt]

Thanks for the report 👍

[aradalvand]

I'm also experiencing a different but still weird treatment of EventId:

With this [LoggerMessage]:

internal static partial class ViewFromAggregateSynchronizerLogs
{
    [LoggerMessage(
        EventId = 4,
        Level = LogLevel.Information,
        Message = "Synchronized {ViewName} with {EventType}:{EventId} — Created: {CreatedCount} / Updated: {UpdatedCount}."
    )]
    public static partial void LogSynchronized(this ILogger logger, ViewName viewName, string eventType, string eventId, int createdCount, int updatedCount);
}

Without Serilog:

Now, I get this result when plugging in Serilog:

Weird! Notice {"Id": 4, "Name": "LogSynchronized"} in the log message. Apparently my actual string eventId argument gets ignored, and the log's EventId is output in that position.

[nblumhardt]

A 9.0.2-dev-* version with a fix for this is on its way to NuGet, it'd be great to confirm that it works for you, @gplogix.

@aradalvand, the built-in EventId property overrides any user-defined properties given the same name. This was a very early design decision in this library; currently, renaming the user-defined property is the way to go. Open to other proposals, please feel free to open a new ticket if you have any suggestions. Cheers!

[aradalvand]

the built-in EventId property overrides any user-defined properties given the same name. This was a very early design decision in this library; currently, renaming the user-defined property is the way to go

@nblumhardt This is a pernicious departure from how the default Microsoft logger works; how about we introduce an opt-in configuration option to make this behavior consistent with the Microsoft logger?

What I find more surprising is the fact that I couldn't seem to find any issues or docs talking about this. Could you point me to any?

[aradalvand]

currently, renaming the user-defined property is the way to go

Also, why doesn't this apply to inline log statements then? This works, for example:

logger.LogInformation("Foo {EventId}", eventId);

[nblumhardt]

This works, for example:

No explicit event id is being specified, there.

This is a pernicious departure from how the default Microsoft logger works

There are a few similar points of divergence between the two. Serilog and this package both pre-date the default Microsoft logger, so the behavior chosen for this one was just what seemed best at the time. The Serilog.Extensions.Logging codebase was originally contributed by Microsoft, around the .NET Core 1.0 era, before there was a built-in logging implementation to compare it with :-)

how about we introduce an opt-in configuration option

This is what I mean by being open to other proposals 👍. It'd need concrete details in order to move forward (rough sketch of the design, analysis of possible breaking changes, alternatives considered, etc.).

[gplogix]

A 9.0.2-dev-* version with a fix for this is on its way to NuGet, it'd be great to confirm that it works for you, @gplogix.

@aradalvand, the built-in EventId property overrides any user-defined properties given the same name. This was a very early design decision in this library; currently, renaming the user-defined property is the way to go. Open to other proposals, please feel free to open a new ticket if you have any suggestions. Cheers!

Yes working (Tested with configuration "Microsoft.XXX" filter set to "Trace" and Blazor Web Assembly 9.0.4). All mouse events containing eventid do not crash serilog anymore

[nblumhardt]

Thanks @gplogix! 👍