ecs-dotnet icon indicating copy to clipboard operation
ecs-dotnet copied to clipboard

[BUG] EcsTextFormatter with Serilog not working with .net 6 preview 4

Open rabberbock opened this issue 4 years ago • 2 comments

ECS integration/library project(s) (e.g. Elastic.CommonSchema.Serilog): Elastic.CommonSchema.Serilog

ECS .NET assembly version (e.g. 1.4.2): 1.5.3

.NET framework / OS: .net 6 preview 4

Description of the problem, including expected versus actual behavior: No Logs are output to the Console when using Serilog Console Sink.

Steps to reproduce: https://github.com/rabberbock/ElasticEcsTest

Thanks for the awesome work!

rabberbock avatar Jun 02 '21 19:06 rabberbock

Thanks for reporting @rabberbock.

I've had a brief look at this, using the MessageTests.SeesMessage() unit test with net6.0.

A TypeInitialization exception is thrown

Elastic.CommonSchema.Serilog.Tests.MessageTests.SeesMessage

System.TypeInitializationException: The type initializer for 'Elastic.CommonSchema.Serialization.JsonConfiguration' threw an exception.

System.TypeInitializationException
The type initializer for 'Elastic.CommonSchema.Serialization.JsonConfiguration' threw an exception.
   at Elastic.CommonSchema.Base.Serialize() in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Base.Serialization.cs:line 56
   at Elastic.CommonSchema.Serilog.EcsTextFormatter.Format(LogEvent logEvent, TextWriter output) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema.Serilog\EcsTextFormatter.cs:line 27
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.<ToFormattedStrings>b__11_0(LogEvent l) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 45
   at System.Linq.Enumerable.SelectListIterator`2.ToList() in System.Linq.dll:token 0x60001dd+0x17
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source) in System.Linq.dll:token 0x600011b+0x1b
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.ToFormattedStrings(List`1 logEvents) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 41
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.ToEcsEvents(List`1 logEvents) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 51
   at Elastic.CommonSchema.Serilog.Tests.MessageTests.<SeesMessage>b__1_0(ILogger logger, Func`1 getLogEvents) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\MessageTests.cs:line 34
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.TestLogger(Action`2 act) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 37
   at Elastic.CommonSchema.Serilog.Tests.MessageTests.SeesMessage() in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\MessageTests.cs:line 27

System.NotSupportedException
Built-in type converters have not been initialized. There is no converter available for type 'System.DateTimeOffset'. To root all built-in converters, use a 'JsonSerializerOptions'-based method of the 'JsonSerializer'.
   at System.Text.Json.ThrowHelper.ThrowNotSupportedException_BuiltInConvertersNotRooted(Type type) in System.Text.Json.dll:token 0x600012a+0x10
   at System.Text.Json.JsonSerializerOptions.GetConverter(Type typeToConvert) in System.Text.Json.dll:token 0x6000389+0xb2
   at Elastic.CommonSchema.Serialization.JsonConfiguration..cctor() in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Serialization\JsonConfiguration.cs:line 26

This originates from the lookup of the DateTimeOffsetConverter from the serializer options here

https://github.com/elastic/ecs-dotnet/blob/8db1ee692126fcd58fd715146cf6117a396faf33/src/Elastic.CommonSchema/Serialization/JsonConfiguration.cs#L26-L27

Removing the use of this and instead using JsonSerializer directly, yields another exception, this time from within System.Text.Json

Elastic.CommonSchema.Serilog.Tests.MessageTests.SeesMessage

System.NullReferenceException: Object reference not set to an instance of an object.

System.NullReferenceException
Object reference not set to an instance of an object.
   at System.Text.Json.JsonSerializer.LookupProperty(Object obj, ReadOnlySpan`1 unescapedPropertyName, ReadStack& state, Boolean& useExtensionProperty, Boolean createExtensionProperty) in System.Text.Json.dll:token 0x600032e+0x3
   at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value) in System.Text.Json.dll:token 0x60008d7+0x81
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value) in System.Text.Json.dll:token 0x60006f3+0x195
   at System.Text.Json.Serialization.JsonResumableConverter`1.Read(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options) in System.Text.Json.dll:token 0x6000701+0x20
   at Elastic.CommonSchema.Serialization.EcsJsonConverterBase`1.ReadProp[TValue](Utf8JsonReader& reader, String key) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Serialization\EcsJsonConverterBase.cs:line 65
   at Elastic.CommonSchema.Serialization.EcsJsonConverterBase`1.ReadProp[TValue](Utf8JsonReader& reader, String key, T b, Action`2 set) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Serialization\EcsJsonConverterBase.cs:line 72
   at Elastic.CommonSchema.Serialization.BaseJsonConverter`1.ReadProperties(Utf8JsonReader& reader, TBase ecsEvent, Nullable`1& timestamp, String& loglevel) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Serialization\BaseJsonFormatter.Generated.cs:line 27
   at Elastic.CommonSchema.Serialization.BaseJsonConverter`1.Read(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Serialization\BaseJsonConverter.cs:line 34
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value) in System.Text.Json.dll:token 0x60006f3+0xd4
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state) in System.Text.Json.dll:token 0x60006df+0xae
   at System.Text.Json.JsonSerializer.ReadCore[TValue](JsonConverter jsonConverter, Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state) in System.Text.Json.dll:token 0x6000332+0xa
   at System.Text.Json.JsonSerializer.Deserialize[TValue](JsonConverter jsonConverter, ReadOnlySpan`1 json, JsonSerializerOptions options, ReadStack& state) in System.Text.Json.dll:token 0x6000346+0x59
   at System.Text.Json.JsonSerializer.Deserialize[TValue](ReadOnlySpan`1 json, Type returnType, JsonSerializerOptions options) in System.Text.Json.dll:token 0x6000345+0x33
   at System.Text.Json.JsonSerializer.Deserialize[TValue](String json, JsonSerializerOptions options) in System.Text.Json.dll:token 0x6000341+0xe
   at Elastic.CommonSchema.Serialization.EcsSerializerFactory`1.Deserialize(String json) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Serialization\EcsSerializerFactory.cs:line 24
   at Elastic.CommonSchema.Base.Deserialize(String json) in C:\Users\russc\source\ecs-dotnet\src\Elastic.CommonSchema\Base.Serialization.cs:line 47
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.<>c.<ToEcsEvents>b__12_0(String s) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 52
   at System.Linq.Enumerable.SelectListIterator`2.ToList() in System.Linq.dll:token 0x60001dd+0x17
   at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source) in System.Linq.dll:token 0x600011b+0x1b
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.ToEcsEvents(List`1 logEvents) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 51
   at Elastic.CommonSchema.Serilog.Tests.MessageTests.<SeesMessage>b__1_0(ILogger logger, Func`1 getLogEvents) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\MessageTests.cs:line 34
   at Elastic.CommonSchema.Serilog.Tests.LogTestsBase.TestLogger(Action`2 act) in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\LogTestsBase.cs:line 37
   at Elastic.CommonSchema.Serilog.Tests.MessageTests.SeesMessage() in C:\Users\russc\source\ecs-dotnet\tests\Elastic.CommonSchema.Serilog.Tests\MessageTests.cs:line 27


{"@timestamp":"2021-06-03T11:06:28.6090709+10:00","log.level":"Information","message":"My log message!","metadata":{"message_template":"My log message!"},"ecs":{"version":"1.5.0"},"event":{"severity":2,"timezone":"E. Australia Standard Time","created":"2021-06-03T11:06:28.6090709+10:00"},"host":{"name":"XTREME"},"log":{"logger":"Elastic.CommonSchema.Serilog.Tests.MessageTests","original":null},"process":{"thread":{"id":15},"pid":18480,"name":"ReSharperTestRunner64","executable":"ReSharperTestRunner64"}}

The log event is serialized successfully, but then fails on deserialization.

net6.0 is still a prerelease and somewhat of a moving target right now. I've pushed up investigation to https://github.com/elastic/ecs-dotnet/tree/bug/153 for the moment

russcam avatar Jun 03 '21 01:06 russcam

I am also getting this issue when trying to use a default converter.

MeepTech avatar Dec 08 '21 21:12 MeepTech

Since we recently moved our tests over to net6 and made .NET 6 the default SDK we have not seen this :crossed_fingers:

Going to treat this as solved. Thanks for reporting from the bleeding edge @MeepTech !

Mpdreamz avatar Sep 01 '22 15:09 Mpdreamz