Fix Serilog direct log submission failing when writing unknown custom properties#8010
Merged
Fix Serilog direct log submission failing when writing unknown custom properties#8010
Conversation
not writing the log causes the writer to get into an invalid state
This seems to break Serilog? But we handle it differently, but previously this was causing direct log submission to die.
Execution-Time Benchmarks Report ⏱️Execution-time results for samples comparing This PR (8010) and master. ✅ No regressions detected - check the details below Full Metrics ComparisonFakeDbCommand
HttpMessageHandler
Comparison explanationExecution-time benchmarks measure the whole time it takes to execute a program, and are intended to measure the one-off costs. Cases where the execution time results for the PR are worse than latest master results are highlighted in **red**. The following thresholds were used for comparing the execution times:
Note that these results are based on a single point-in-time result for each branch. For full results, see the dashboard. Graphs show the p99 interval based on the mean and StdDev of the test run, as well as the mean value of the run (shown as a diamond below the graph). Duration chartsFakeDbCommand (.NET Framework 4.8)gantt
title Execution time (ms) FakeDbCommand (.NET Framework 4.8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (69ms) : 67, 70
master - mean (68ms) : 67, 70
section Bailout
This PR (8010) - mean (72ms) : 71, 74
master - mean (72ms) : 71, 73
section CallTarget+Inlining+NGEN
This PR (8010) - mean (1,011ms) : 954, 1067
master - mean (1,016ms) : 942, 1090
FakeDbCommand (.NET Core 3.1)gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (106ms) : 102, 109
master - mean (106ms) : 104, 108
section Bailout
This PR (8010) - mean (107ms) : 105, 108
master - mean (107ms) : 106, 108
section CallTarget+Inlining+NGEN
This PR (8010) - mean (710ms) : 673, 747
master - mean (710ms) : 683, 736
FakeDbCommand (.NET 6)gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (93ms) : 91, 95
master - mean (94ms) : 92, 96
section Bailout
This PR (8010) - mean (94ms) : 93, 96
master - mean (95ms) : 93, 96
section CallTarget+Inlining+NGEN
This PR (8010) - mean (668ms) : 647, 689
master - mean (668ms) : 635, 701
FakeDbCommand (.NET 8)gantt
title Execution time (ms) FakeDbCommand (.NET 8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (92ms) : 89, 95
master - mean (92ms) : 90, 94
section Bailout
This PR (8010) - mean (93ms) : 92, 95
master - mean (93ms) : 91, 94
section CallTarget+Inlining+NGEN
This PR (8010) - mean (628ms) : 614, 642
master - mean (629ms) : 614, 644
HttpMessageHandler (.NET Framework 4.8)gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (194ms) : 190, 197
master - mean (194ms) : 190, 197
section Bailout
This PR (8010) - mean (197ms) : 194, 200
master - mean (197ms) : 193, 201
section CallTarget+Inlining+NGEN
This PR (8010) - mean (1,114ms) : 1058, 1170
master - mean (1,120ms) : 1054, 1186
HttpMessageHandler (.NET Core 3.1)gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (278ms) : 270, 286
master - mean (279ms) : 270, 288
section Bailout
This PR (8010) - mean (279ms) : 272, 287
master - mean (277ms) : 274, 281
section CallTarget+Inlining+NGEN
This PR (8010) - mean (905ms) : 868, 942
master - mean (905ms) : 854, 955
HttpMessageHandler (.NET 6)gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (270ms) : 266, 275
master - mean (271ms) : 266, 275
section Bailout
This PR (8010) - mean (270ms) : 266, 273
master - mean (270ms) : 266, 274
section CallTarget+Inlining+NGEN
This PR (8010) - mean (886ms) : 845, 927
master - mean (891ms) : 840, 942
HttpMessageHandler (.NET 8)gantt
title Execution time (ms) HttpMessageHandler (.NET 8)
dateFormat x
axisFormat %Q
todayMarker off
section Baseline
This PR (8010) - mean (269ms) : 265, 273
master - mean (270ms) : 265, 274
section Bailout
This PR (8010) - mean (269ms) : 265, 273
master - mean (270ms) : 266, 273
section CallTarget+Inlining+NGEN
This PR (8010) - mean (825ms) : 802, 847
master - mean (824ms) : 802, 846
|
||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
BenchmarksBenchmark execution time: 2025-12-23 23:25:04 Comparing candidate commit 2e6e977 in PR branch Found 14 performance improvements and 2 performance regressions! Performance is the same for 155 metrics, 15 unstable metrics. scenario:Benchmarks.Trace.ActivityBenchmark.StartStopWithChild net6.0
scenario:Benchmarks.Trace.Asm.AppSecBodyBenchmark.AllCycleMoreComplexBody net6.0
scenario:Benchmarks.Trace.Asm.AppSecBodyBenchmark.ObjectExtractorMoreComplexBody net6.0
scenario:Benchmarks.Trace.Asm.AppSecBodyBenchmark.ObjectExtractorSimpleBody netcoreapp3.1
scenario:Benchmarks.Trace.Asm.AppSecWafBenchmark.RunWafRealisticBenchmark netcoreapp3.1
scenario:Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces netcoreapp3.1
scenario:Benchmarks.Trace.CharSliceBenchmark.OptimizedCharSlice net6.0
scenario:Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery netcoreapp3.1
scenario:Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch netcoreapp3.1
scenario:Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearchAsync netcoreapp3.1
scenario:Benchmarks.Trace.SpanBenchmark.StartFinishScope net6.0
scenario:Benchmarks.Trace.SpanBenchmark.StartFinishScope netcoreapp3.1
scenario:Benchmarks.Trace.SpanBenchmark.StartFinishTwoScopes net6.0
|
andrewlock
approved these changes
Dec 24, 2025
Member
andrewlock
left a comment
There was a problem hiding this comment.
Thanks! I wonder if we could/should handle this.
Also, I believe the OTLP log formatter similarly copies a bunch of this code, we probably need to fix it there too?
| _value = value; | ||
| } | ||
|
|
||
| public override void Render(TextWriter output, string format = null, IFormatProvider formatProvider = null) |
Member
There was a problem hiding this comment.
I'm actually wondering if we should be able to handle this 🤔 e.g. why couldn't we duck type LogEventPropertyValue, write to StringBuilder (using a StringWriter as the TextWriter), and then write that as a simple string in our SerilogLogFormatter? 🤔
Not necessarily required for the fix, because we don't do that today, but should be possible and not too hard?
Interesting that serilog file writing doesn't handle that though
NachoEchevarria
approved these changes
Dec 24, 2025
andrewlock
added a commit
that referenced
this pull request
Jan 8, 2026
#8034) ## Summary of changes Handle the case where a customer is using a custom `LogEventPropertyValue` implementation and direct log submission ## Reason for change #8010 handled a case where we were generating invalid JSON by dropping the offending value. This PR adds support for serializing the value as a string instead. ## Implementation details Ducktyped `LogEventPropertyValue` and called its `Render` method with a cached `StringBuilder` to get the value, then use the same mechanisms ## Test coverage Should be covered by the tests added in #8010 ## Other details
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary of changes
This fixes a
JsonWriterExceptionthat we were hitting when attempting to serialize custom properties in Serilog log messages when we had Direct Log Submission enabled. This would then result in direct log submission to stop working.Reason for change
When writing a custom property in Serilog we only write the JSON when Debug logging is enabled, when it isn't enabled we actually end up putting the writer into an invalid state, we then hit the following exception:
From what I can tell this causes direct log submission to stop working.
I've seen this in Error Tracking and it may be related to a customer escalation regarding issues with Serilog direct log submission to seemingly stop working.
Implementation details
Test coverage
I've reproduced this, but it is strange, I guess Serilog doesn't actually support this? I don't understand completely what was going on, but if I added a custom property and enriched all logs with it but did not have direct log submission enabled there would be no logs found in the tests but they did make it to the file. 😕
Other details
I only toggled this custom property on when direct log submission is enabled due to the above Test Coverage note.