[BUG] MetaDataDictionaryConverter - NullReferenceException

[snakefoot]

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 b__0(Microsoft.AspNetCore.Http.HttpContext)}}	Microsoft.AspNetCore.Http.RequestDelegate
	▶ Method	{System.Threading.Tasks.Task 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}

[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.

[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.

[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)

[Mpdreamz]

I think we are hitting this bug in System Text Json: dotnet/runtime#58690

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

[snakefoot]

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.

[doeringp]

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?

[snakefoot]

@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.

[doeringp]

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