ecs-dotnet [BUG] MetaDataDictionaryConverter

Starting ASP.NET6 Application with NLog EcsLayout where it fails to serialize object of type Microsoft.AspNetCore.Routing.RouteEndpoint coming from this log-message from Microsoft ASP.NET (Logger-Category = "Microsoft.AspNetCore.Routing.EndpointMiddleware"):

Executing endpoint '{EndpointName}'

Exception Details (Looks like it fails with a nested-value of type Microsoft.AspNetCore.Routing.Patterns.RoutePattern):

System.NullReferenceException
  HResult=0x80004003
  Message=Object reference not set to an instance of an object.
  Source=System.Text.Json
  StackTrace:
>	System.Text.Json.dll!System.Text.Json.Serialization.JsonDictionaryConverter<System.Collections.Generic.IReadOnlyDictionary<string, object>, string, object>.OnTryWrite(System.Text.Json.Utf8JsonWriter writer, System.Collections.Generic.IReadOnlyDictionary<string, object> dictionary, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<System.Collections.Generic.IReadOnlyDictionary<string, object>>.TryWrite(System.Text.Json.Utf8JsonWriter writer, System.Collections.Generic.IReadOnlyDictionary<string, object> value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.Metadata.JsonPropertyInfo<System.Collections.Generic.IReadOnlyDictionary<string, object>>.GetMemberAndWriteJson(object obj, ref System.Text.Json.WriteStack state, System.Text.Json.Utf8JsonWriter writer)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.Converters.ObjectDefaultConverter<Microsoft.AspNetCore.Routing.Patterns.RoutePattern>.OnTryWrite(System.Text.Json.Utf8JsonWriter writer, Microsoft.AspNetCore.Routing.Patterns.RoutePattern value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<Microsoft.AspNetCore.Routing.Patterns.RoutePattern>.TryWrite(System.Text.Json.Utf8JsonWriter writer, Microsoft.AspNetCore.Routing.Patterns.RoutePattern value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.Metadata.JsonPropertyInfo<Microsoft.AspNetCore.Routing.Patterns.RoutePattern>.GetMemberAndWriteJson(object obj, ref System.Text.Json.WriteStack state, System.Text.Json.Utf8JsonWriter writer)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.Converters.ObjectDefaultConverter<Microsoft.AspNetCore.Routing.RouteEndpoint>.OnTryWrite(System.Text.Json.Utf8JsonWriter writer, Microsoft.AspNetCore.Routing.RouteEndpoint value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<Microsoft.AspNetCore.Routing.RouteEndpoint>.TryWrite(System.Text.Json.Utf8JsonWriter writer, Microsoft.AspNetCore.Routing.RouteEndpoint value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<System.__Canon>.WriteCore(System.Text.Json.Utf8JsonWriter writer, System.__Canon value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<Microsoft.AspNetCore.Routing.RouteEndpoint>.WriteCoreAsObject(System.Text.Json.Utf8JsonWriter writer, object value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.JsonSerializer.WriteUsingSerializer<object>(System.Text.Json.Utf8JsonWriter writer, object value, System.Text.Json.Serialization.Metadata.JsonTypeInfo jsonTypeInfo)	Unknown
 	System.Text.Json.dll!System.Text.Json.JsonSerializer.Serialize(System.Text.Json.Utf8JsonWriter writer, object value, System.Type inputType, System.Text.Json.JsonSerializerOptions options)	Unknown
 	Elastic.CommonSchema.dll!Elastic.CommonSchema.Serialization.MetaDataDictionaryConverter.Write(System.Text.Json.Utf8JsonWriter writer, System.Collections.Generic.IDictionary<string, object> value, System.Text.Json.JsonSerializerOptions options) Line 69	C#
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<System.Collections.Generic.IDictionary<string, object>>.TryWrite(System.Text.Json.Utf8JsonWriter writer, System.Collections.Generic.IDictionary<string, object> value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<System.__Canon>.WriteCore(System.Text.Json.Utf8JsonWriter writer, System.__Canon value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.Serialization.JsonConverter<System.Collections.Generic.IDictionary<string, object>>.WriteCoreAsObject(System.Text.Json.Utf8JsonWriter writer, object value, System.Text.Json.JsonSerializerOptions options, ref System.Text.Json.WriteStack state)	Unknown
 	System.Text.Json.dll!System.Text.Json.JsonSerializer.WriteUsingSerializer<object>(System.Text.Json.Utf8JsonWriter writer, object value, System.Text.Json.Serialization.Metadata.JsonTypeInfo jsonTypeInfo)	Unknown
 	System.Text.Json.dll!System.Text.Json.JsonSerializer.Serialize(System.Text.Json.Utf8JsonWriter writer, object value, System.Type inputType, System.Text.Json.JsonSerializerOptions options)	Unknown

		public override void Write(Utf8JsonWriter writer, IDictionary<string, object> value, JsonSerializerOptions options)
		{
			writer.WriteStartObject();

			foreach (var kvp in value)
			{
				var propertyName = SnakeCaseJsonNamingPolicy.ToSnakeCase(kvp.Key);
				writer.WritePropertyName(propertyName);

				if (kvp.Value == null)
					writer.WriteNullValue();
				else
				{
					var inputType = kvp.Value.GetType();
					JsonSerializer.Serialize(writer, kvp.Value, inputType, options);  // <-- throws
				}
			}

			writer.WriteEndObject();
		}

	Name	Value	Type
	inputType.ToString()	"Microsoft.AspNetCore.Routing.RouteEndpoint"	string

	Name	Value	Type
◢	kvp.Value	{ASP.NetCore6_NLog_Web_Example.Controllers.HomeController.Index (ASP.NetCore6_NLog_Web_Example)}	object {Microsoft.AspNetCore.Routing.RouteEndpoint}
	DisplayName	"ASP.NetCore6_NLog_Web_Example.Controllers.HomeController.Index (ASP.NetCore6_NLog_Web_Example)"	string
	◢ Metadata	{Microsoft.AspNetCore.Http.EndpointMetadataCollection}	Microsoft.AspNetCore.Http.EndpointMetadataCollection
	Count	10	int
	◢ Results View	Expanding the Results View will enumerate the IEnumerable
	▶ [0]	{System.Runtime.CompilerServices.NullableContextAttribute}	object {System.Runtime.CompilerServices.NullableContextAttribute}
	▶ [1]	{System.Runtime.CompilerServices.NullableAttribute}	object {System.Runtime.CompilerServices.NullableAttribute}
	▶ [2]	{Microsoft.AspNetCore.Mvc.ControllerAttribute}	object {Microsoft.AspNetCore.Mvc.ControllerAttribute}
	▶ [3]	"ASP.NetCore6_NLog_Web_Example.Controllers.HomeController.Index (ASP.NetCore6_NLog_Web_Example)"	object {Microsoft.AspNetCore.Mvc.Controllers.ControllerActionDescriptor}
	▶ [4]	{Microsoft.AspNetCore.Routing.DataTokensMetadata}	object {Microsoft.AspNetCore.Routing.DataTokensMetadata}
	▶ [5]	Name: default	object {Microsoft.AspNetCore.Routing.RouteNameMetadata}
	▶ [6]	{Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter}	object {Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter}
	▶ [7]	{Microsoft.AspNetCore.Mvc.ViewFeatures.SaveTempDataAttribute}	object {Microsoft.AspNetCore.Mvc.ViewFeatures.SaveTempDataAttribute}
	▶ [8]	{Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter}	object {Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter}
	▶ [9]	{Microsoft.AspNetCore.Routing.SuppressLinkGenerationMetadata}	object {Microsoft.AspNetCore.Routing.SuppressLinkGenerationMetadata}
	Order	1	int
	◢ RequestDelegate	{Method = {System.Threading.Tasks.Task <CreateRequestDelegate>b__0(Microsoft.AspNetCore.Http.HttpContext)}}	Microsoft.AspNetCore.Http.RequestDelegate
	▶ Method	{System.Threading.Tasks.Task <CreateRequestDelegate>b__0(Microsoft.AspNetCore.Http.HttpContext)}	System.Reflection.MethodInfo {System.Reflection.RuntimeMethodInfo}
	▶ Target	{Microsoft.AspNetCore.Mvc.Routing.ControllerRequestDelegateFactory.<>c__DisplayClass10_0}	object {Microsoft.AspNetCore.Mvc.Routing.ControllerRequestDelegateFactory.<>c__DisplayClass10_0}
	▶ Non-Public members
	◢ RoutePattern	"{controller=Home}/{action=Index}/{id?}"	Microsoft.AspNetCore.Routing.Patterns.RoutePattern
	▶ Defaults	Count = 2	System.Collections.Generic.IReadOnlyDictionary<string, object> {System.Collections.Generic.Dictionary<string, object>}
	InboundPrecedence	1.13	decimal
	OutboundPrecedence	3.33	decimal
	▶ ParameterPolicies	Count = 0	System.Collections.Generic.IReadOnlyDictionary<string, System.Collections.Generic.IReadOnlyList<Microsoft.AspNetCore.Routing.Patterns.RoutePatternParameterPolicyReference>> {System.Collections.ObjectModel.ReadOnlyDictionary<string, System.Collections.Generic.IReadOnlyList<Microsoft.AspNetCore.Routing.Patterns.RoutePatternParameterPolicyReference>>}
	▶ Parameters	Count = 3	System.Collections.Generic.IReadOnlyList<Microsoft.AspNetCore.Routing.Patterns.RoutePatternParameterPart> {System.Collections.Generic.List<Microsoft.AspNetCore.Routing.Patterns.RoutePatternParameterPart>}
	▶ PathSegments	{Microsoft.AspNetCore.Routing.Patterns.RoutePatternPathSegment[3]}	System.Collections.Generic.IReadOnlyList<Microsoft.AspNetCore.Routing.Patterns.RoutePatternPathSegment> {Microsoft.AspNetCore.Routing.Patterns.RoutePatternPathSegment[]}
	RawText	"{controller=Home}/{action=Index}/{id?}"	string
	▶ RequiredValues	{Microsoft.AspNetCore.Routing.RouteValueDictionary}	System.Collections.Generic.IReadOnlyDictionary<string, object> {Microsoft.AspNetCore.Routing.RouteValueDictionary}

Sep 07 '22 18:09 snakefoot

Maybe the System.Text.Json is not a good choice for handling random objects, since it seems very fragile.

Maybe MetaDataDictionaryConverter should only support simple-types (bool, int, DateTime, etc.), and perform ToString on everything else.

Sep 07 '22 18:09 snakefoot

Think these usual suspects should never be passed to System.Text.Json:

System.IO.Stream (abstract-interface)
System.Reflection.MemberInfo (abstract-interface)
System.Type
System.Reflection.Assembly

So any type matching the above types, should be converted directly to string.

Sep 07 '22 19:09 snakefoot

Tried to make a custom build of MetaDataDictionaryConverter that recognized the dangerous types above, and it helped a lot, but there were still some warnings when running ASP.NET6 application:

2022-09-07 21:26:59.5910 Error FileTarget(Name=allfile): Exception in Write Exception: System.ArgumentNullException: Value cannot be null. (Parameter 'obj')
   at System.OrdinalIgnoreCaseComparer.GetHashCode(String obj)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo.ParameterLookupKey.GetHashCode()
   at System.Collections.Generic.Dictionary`2.FindValue(TKey key)
   at System.Collections.Generic.Dictionary`2.TryGetValue(TKey key, TValue& value)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo.InitializeConstructorParameters(JsonParameterInfoValues[] jsonParameters, Boolean sourceGenMode)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo..ctor(Type type, JsonConverter converter, Type runtimeType, JsonSerializerOptions options)
   at System.Text.Json.JsonSerializerOptions.<InitializeForReflectionSerializer>g__CreateJsonTypeInfo|112_0(Type type, JsonSerializerOptions options)
   at System.Text.Json.JsonSerializerOptions.GetClassFromContextOrCreate(Type type)
   at System.Text.Json.JsonSerializerOptions.GetOrAddClass(Type type)
   at System.Text.Json.WriteStackFrame.InitializeReEntry(Type type, JsonSerializerOptions options)
   at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.Converters.IEnumerableDefaultConverter`2.OnWriteResume(Utf8JsonWriter writer, TCollection value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.JsonCollectionConverter`2.OnTryWrite(Utf8JsonWriter writer, TCollection value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.Metadata.JsonPropertyInfo`1.GetMemberAndWriteJson(Object obj, WriteStack& state, Utf8JsonWriter writer)
   at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryWrite(Utf8JsonWriter writer, T value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.JsonConverter`1.WriteCore(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.JsonConverter`1.WriteCoreAsObject(Utf8JsonWriter writer, Object value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.JsonSerializer.WriteUsingSerializer[TValue](Utf8JsonWriter writer, TValue& value, JsonTypeInfo jsonTypeInfo)
   at System.Text.Json.JsonSerializer.Serialize(Utf8JsonWriter writer, Object value, Type inputType, JsonSerializerOptions options)
   at Elastic.CommonSchema.Serialization.MetadataDictionaryConverter.Write(Utf8JsonWriter writer, MetadataDictionary value, JsonSerializerOptions options)
   at Elastic.CommonSchema.Serialization.EcsJsonConverterBase`1.WriteProp[TValue](Utf8JsonWriter writer, String key, TValue value)
   at Elastic.CommonSchema.Serialization.EcsDocumentJsonConverter`1.Write(Utf8JsonWriter writer, TBase value, JsonSerializerOptions options)
   at System.Text.Json.Serialization.JsonConverter`1.TryWrite(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.JsonConverter`1.WriteCore(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.JsonSerializer.WriteUsingSerializer[TValue](Utf8JsonWriter writer, TValue& value, JsonTypeInfo jsonTypeInfo)
   at System.Text.Json.JsonSerializer.Serialize[TValue](Utf8JsonWriter writer, TValue value, JsonSerializerOptions options)
   at Elastic.CommonSchema.EcsDocument.Serialize(Utf8JsonWriter writer)
   at Elastic.CommonSchema.Serialization.ReusableUtf8JsonWriter.ReusableJsonWriter.Serialize(EcsDocument ecsEvent)
   at Elastic.CommonSchema.EcsDocument.Serialize(StringBuilder stringBuilder)

Sep 07 '22 19:09 snakefoot

I think we are hitting this bug in System Text Json: https://github.com/dotnet/runtime/issues/58690

Which won't get fixed until 7.0. Which is due out in november: https://github.com/dotnet/runtime/milestone/82

Sep 09 '22 10:09 Mpdreamz

Created #221 to prevent dying on "bad types" that are commonly used.

Created #222 to prevent NLog sending "unsafe types" to the fragile System.Text.Json-serializer.

Sep 11 '22 12:09 snakefoot

In my opinion the MetaDataDictionaryConverter should behave like NLog which supports the Message Templates standard when formatting placeholders in messages (see https://github.com/NLog/NLog/wiki/How-to-use-structured-logging#formatting-of-the-message).

By default or when using the $ stringification operator, ...

logger.LogInformation("Hello, I am {person}", new Person("John", "Doe"));
logger.LogInformation("Hello, I am {$person}", new Person("John", "Doe"));

... metadata should be serialized by calling the ToString()-method:

{
    "@timestamp": "2022-11-28T13:58:21.4222655+01:00",
    "log.level": "Info",
    "message": "Hello, I am Person { FirstName = John, LastName = Doe }",
    "metadata": {
        "person": "Person { FirstName = John, LastName = Doe }"
    },
   ... [removed for brevity]
}

But in the current version 1.5.3 of Elastic.CommonSchema.NLog metadata is always serialized as JSON:

{
    "@timestamp": "2022-11-28T13:58:21.4222655+01:00",
    "log.level": "Info",
    "message": "Hello, I am Person { FirstName = John, LastName = Doe }",
    "metadata": {
        "person": {
            "first_name": "John",
            "last_name": "Doe"
        }
    },
   ... [removed for brevity]
}

Only when the @ structure capturing operator is used in the message template, ...

logger.LogInformation("Hello, I am {@person}", new Person("John", "Doe"));

... I'd expect the metadata value to be serialized as JSON:

{
    "@timestamp": "2022-11-28T13:59:07.6100035+01:00",
    "log.level": "Info",
    "message": "Hello, I am {\"FirstName\":\"John\", \"LastName\":\"Doe\"}",
    "metadata": {
        "person": {
            "first_name": "John",
            "last_name": "Doe"
        }
    },
    ... [removed for brevity]
}

This allows the creator of the log message to determine whether or not to serialize the log arguments.

Maybe we can reuse NLog's code for serializing metadata?

Nov 28 '22 13:11 doeringp

@doeringp This allows the creator of the log message to determine whether or not to serialize the log arguments.

Pull-Request #222 is implementing that behavior for NLog.

Nov 28 '22 17:11 snakefoot

I tried #222. It works great 👏 Can we get this merged?

Nov 29 '22 09:11 doeringp

[BUG] MetaDataDictionaryConverter - NullReferenceException