Collectives™ on Stack Overflow
Find centralized, trusted content and collaborate around the technologies you use most.
Learn more about Collectives
Teams
Q&A for work
Connect and share knowledge within a single location that is structured and easy to search.
Learn more about Teams
I am getting this error occasionally with the MSSQLServer sink. I can't see what's wrong with this guid. Any ideas? I've verified in every place I can find the data type of the source guid is "Guid" not a string. I'm just a bit mystified.
Guid should contain 32 digits with 4 dashes (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx).Couldn't store <"7526f485-ec2d-4ec8-bd73-12a7d1c49a5d"> in UserId Column. Expected type is Guid.
The guid in this example is:
7526f485-ec2d-4ec8-bd73-12a7d1c49a5d
xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx
seems to match the template to me?
Further details:
This is an occasional issue, but when it arises it arises a lot. It seems to be tied to specific Guids. Most Guids are fine, but a small subset have this issue. Our app logs thousands of messages a day, but these messages are not logged (because of the issue) so it is difficult for me to track down exactly where the specific logs that are causing this error come from. However, we use a centralized logging method that is run something like this. This test passes for me, but it mirrors the setup and code we use for logging generally, which normally succeeds. As I said, this is an intermittent issue:
[Fact]
public void Foobar()
// arrange
var columnOptions = new ColumnOptions
AdditionalColumns = new Collection<SqlColumn>
new SqlColumn {DataType = SqlDbType.UniqueIdentifier, ColumnName = "UserId"},
columnOptions.Store.Remove(StandardColumn.MessageTemplate);
columnOptions.Store.Remove(StandardColumn.Properties);
columnOptions.Store.Remove(StandardColumn.LogEvent);
columnOptions.Properties.ExcludeAdditionalProperties = true;
var badGuid = new Guid("7526f485-ec2d-4ec8-bd73-12a7d1c49a5d");
var connectionString = "Server=(localdb)\\MSSQLLocalDB;Database=SomeDb;Trusted_Connection=True;MultipleActiveResultSets=true";
var logConfiguration = new LoggerConfiguration()
.MinimumLevel.Information()
.Enrich.FromLogContext()
.WriteTo.MSSqlServer(connectionString, "Logs",
restrictedToMinimumLevel: LogEventLevel.Information, autoCreateSqlTable: false,
columnOptions: columnOptions)
.WriteTo.Console(restrictedToMinimumLevel: LogEventLevel.Information);
Log.Logger = logConfiguration.CreateLogger();
// Suspect the issue is with this line
LogContext.PushProperty("UserId", badGuid);
// Best practice would be to do something like this:
// using (LogContext.PushProperty("UserId", badGuid)
Log.Logger.Information(new FormatException("Foobar"),"This is a test");
Log.CloseAndFlush();
One thing I have noticed since constructing this test code is that the "PushProperty" for the UserId property is not captured and disposed. Since behaviour is "undefined" in this case, I am inclined to fix it anyway and see if the problem goes away.
full stack:
2020-04-20T08:38:17.5145399Z Exception while emitting periodic batch from Serilog.Sinks.MSSqlServer.MSSqlServerSink: System.ArgumentException: Guid should contain 32 digits with 4 dashes (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx).Couldn't store <"7526f485-ec2d-4ec8-bd73-12a7d1c49a5d"> in UserId Column. Expected type is Guid.
---> System.FormatException: Guid should contain 32 digits with 4 dashes (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx).
at System.Guid.GuidResult.SetFailure(Boolean overflow, String failureMessageID)
at System.Guid.TryParseExactD(ReadOnlySpan`1 guidString, GuidResult& result)
at System.Guid.TryParseGuid(ReadOnlySpan`1 guidString, GuidResult& result)
at System.Guid..ctor(String g)
at System.Data.Common.ObjectStorage.Set(Int32 recordNo, Object value)
at System.Data.DataColumn.set_Item(Int32 record, Object value)
--- End of inner exception stack trace ---
at System.Data.DataColumn.set_Item(Int32 record, Object value)
at System.Data.DataRow.set_Item(DataColumn column, Object value)
at Serilog.Sinks.MSSqlServer.MSSqlServerSink.FillDataTable(IEnumerable`1 events)
at Serilog.Sinks.MSSqlServer.MSSqlServerSink.EmitBatchAsync(IEnumerable`1 events)
at Serilog.Sinks.PeriodicBatching.PeriodicBatchingSink.OnTick()
RESOLUTION
This issue was caused because someone created a log message with a placeholder that had the same name as our custom data column, but was passing in a string version of a guid instead of one typed as a guid.
Very simple example:
var badGuid = "7526f485-ec2d-4ec8-bd73-12a7d1c49a5d";
var badGuidConverted = Guid.Parse(badGuid); // just proving the guid is actually valid.
var goodGuid = Guid.NewGuid();
using (LogContext.PushProperty("UserId",goodGuid))
Log.Logger.Information("This is a problem with my other user {userid} that will crash serilog. This message will never end up in the database.", badGuid);
The quick fix is to edit the message template to change the placeholder from {userid} to something else.
Since our code was centralized around the place where the PushProperty occurs, I put some checks in there to monitor for this and throw a more useful error message in the future when someone does this again.
–
–
I don't see anything obvious in the specific code above that would cause the issue. The fact that you call PushProperty before setting up Serilog would be something I would change (i.e. set up Serilog first, then call PushProperty) but that doesn't seem to be the root cause of the issue you're having.
My guess, is that you have some code paths that are logging the UserId as a string, instead of a Guid. Serilog is expecting a Guid value type, so if you give it a string representation of a Guid it won't work and will give you that type of exception.
Maybe somewhere in the codebase you're calling .ToString on the UserId before logging? Or perhaps using string interpolation e.g. Log.Information("User is {UserId}", $"{UserId}");?
For example:
var badGuid = "7526f485-ec2d- 4ec8-bd73-12a7d1c49a5d";
LogContext.PushProperty("UserId", badGuid);
Log.Information(new FormatException("Foobar"), "This is a test");
Or even just logging a message with the UserId property directly:
var badGuid = "7526f485-ec2d-4ec8-bd73-12a7d1c49a5d";
Log.Information("The {UserId} is doing work", badGuid);
Both snippets above would throw the same exception you're having, because they use string values rather than real Guid values.
–
–
Thanks for contributing an answer to Stack Overflow!
- Please be sure to answer the question. Provide details and share your research!
But avoid …
- Asking for help, clarification, or responding to other answers.
- Making statements based on opinion; back them up with references or personal experience.
To learn more, see our tips on writing great answers.
