Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix crash on operations requests when trace logging is turned on #1396

Merged
merged 5 commits into from
Nov 17, 2023

Conversation

bkoelman
Copy link
Member

@bkoelman bkoelman commented Nov 16, 2023

There are several ways to prevent the crash from happening.

The problem is that the parameter of the operations action method includes contextual information such as IJsonApiRequest and ITargettedFields, which reference elements from the resource graph, which contain members of type Type and PropertyInfo. The JSON serializer chokes on these, throwing a NotSupportedException.

The easiest fix would be to catch these errors and omit the parameter from the logs. Or add several [JsonIgnore] annotations in the resource graph.

But we can do better by adding custom JsonConverters that prevent drilling down into reflection members, and instead write only the relevant information. For example, when writing ResourceType only its PublicName is relevant in the logs. Furthermore we need to "help" the serializer a bit when it sees an array of IIdentifiable to instead use the runtime-type for its elements, so it serializes all properties of, for example, Product, instead of only its ID.

Fixes #1397.

QUALITY CHECKLIST

@bkoelman bkoelman force-pushed the fix-trace-logging-in-operations branch 3 times, most recently from e006c3d to 3185bec Compare November 16, 2023 11:16
Copy link

codecov bot commented Nov 16, 2023

Codecov Report

Attention: 6 lines in your changes are missing coverage. Please review.

Comparison is base (24b9546) 90.65% compared to head (4d2ffd8) 90.79%.

Files Patch % Lines
src/JsonApiDotNetCore/Middleware/TraceLogWriter.cs 83.78% 5 Missing and 1 partial ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##           master    #1396      +/-   ##
==========================================
+ Coverage   90.65%   90.79%   +0.13%     
==========================================
  Files         342      342              
  Lines       11047    11069      +22     
  Branches     1817     1811       -6     
==========================================
+ Hits        10015    10050      +35     
+ Misses        679      667      -12     
+ Partials      353      352       -1     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

@bkoelman bkoelman force-pushed the fix-trace-logging-in-operations branch from 3185bec to ce07172 Compare November 16, 2023 11:48
@bkoelman bkoelman marked this pull request as ready for review November 16, 2023 12:09
@arcarrillo
Copy link

arcarrillo commented Nov 17, 2023

hi @bkoelman,
After downloading and executing the project with this branch, I continue having the following serialization error:

Message
Unable to cast object of type 'ResourceFieldInTraceJsonConverter' to type 'System.Text.Json.Serialization.JsonConverter1[JsonApiDotNetCore.Resources.Annotations.AttrAttribute]'.`

StackTrace:

   at System.Text.Json.Serialization.JsonCollectionConverter`2.GetElementConverter(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.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.Converters.ListOfTConverter`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.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.WriteStringUsingSerializer[TValue](TValue& value, JsonTypeInfo jsonTypeInfo)
   at System.Text.Json.JsonSerializer.Serialize[TValue](TValue value, JsonSerializerOptions options)
   at JsonApiDotNetCore.Middleware.TraceLogWriter`1.SerializeObject(Object value) in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Middleware\TraceLogWriter.cs:line 181
   at JsonApiDotNetCore.Middleware.TraceLogWriter`1.WriteObject(StringBuilder builder, Object value) in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Middleware\TraceLogWriter.cs:line 166
   at JsonApiDotNetCore.Middleware.TraceLogWriter`1.WriteProperty(StringBuilder builder, PropertyInfo property, Object instance) in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Middleware\TraceLogWriter.cs:line 155
   at JsonApiDotNetCore.Middleware.TraceLogWriter`1.WriteProperties(StringBuilder builder, Object propertyContainer) in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Middleware\TraceLogWriter.cs:line 144
   at JsonApiDotNetCore.Middleware.TraceLogWriter`1.FormatMessage(String memberName, Object parameters) in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Middleware\TraceLogWriter.cs:line 121
   at JsonApiDotNetCore.Middleware.TraceLogWriter`1.LogMethodStart(Object parameters, String memberName) in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Middleware\TraceLogWriter.cs:line 100
   at JsonApiDotNetCore.Controllers.BaseJsonApiOperationsController.<PostOperationsAsync>d__7.MoveNext() in C:\Users\rodriguezalberto\repos\JsonApiDotNetCore\src\JsonApiDotNetCore\Controllers\BaseJsonApiOperationsController.cs:line 107
   at WAJsonApiDotnetCore.Controllers.AtomicOperationsController.<PostOperationsAsync>d__1.MoveNext() in C:\Users\rodriguezalberto\source\repos\samplepoc\WAJsonApiDotnetCore\WAJsonApiDotnetCore\Controllers\AtomicOperationsController.cs:line 40
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.TaskOfIActionResultExecutor.<Execute>d__0.MoveNext()
   at System.Threading.Tasks.ValueTask`1.get_Result()
   at System.Runtime.CompilerServices.ValueTaskAwaiter`1.GetResult()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<<InvokeActionMethodAsync>g__Logged|12_1>d.MoveNext()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<<InvokeNextActionFilterAsync>g__Awaited|10_0>d.MoveNext()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync()
--- End of stack trace from previous location ---
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<<InvokeNextExceptionFilterAsync>g__Awaited|26_0>d.MoveNext()

It seems that the error comes from trying to convert this serializer to a converter working with derived classes.
One possible solution could be declaring the converter generic instead a specific converter for every ResourceFieldAttribute derived class. Something like this:

    private sealed class ResourceFieldInTraceJsonConverterFactory : JsonConverterFactory
    {
        public override bool CanConvert(Type typeToConvert)
        {
            return typeToConvert.IsAssignableTo(typeof(ResourceFieldAttribute));
        }

        public override JsonConverter CreateConverter(Type typeToConvert, JsonSerializerOptions options)
        {
            Type genericClass = typeof(ResourceFieldInTraceJsonConverter<>);
            Type constructedClass = genericClass.MakeGenericType(typeToConvert);
            return Activator.CreateInstance(constructedClass) as JsonConverter;
        }

        private sealed class ResourceFieldInTraceJsonConverter<T> : JsonConverter<T> where T : ResourceFieldAttribute
        {
            public override T Read(ref Utf8JsonReader reader, Type typeToConvert, JsonSerializerOptions options)
            {
                throw new NotSupportedException();
            }

            public override void Write(Utf8JsonWriter writer, T value, JsonSerializerOptions options)
            {
                writer.WriteStringValue(value.PublicName);
            }
        }
    }

If you like the solution, you could adopt it. If not, I'll be waiting for the next commit, 🙂
Thanks!!

Edit: After implement the changes showed above, the serializer began to work and gave me a detailed message of the operation.

@bkoelman
Copy link
Member Author

@arcarrillo Thanks for trying this out. The issue you're experiencing went unnoticed because we reference System.Text.Json v7 from tests for unrelated reasons, which apparently is more flexible. I've integrated your fix and addressed another issue related to resource inheritance.

@arcarrillo
Copy link

@arcarrillo Thanks for trying this out. The issue you're experiencing went unnoticed because we reference System.Text.Json v7 from tests for unrelated reasons, which apparently is more flexible. I've integrated your fix and addressed another issue related to resource inheritance.

Thanks a lot @bkoelman. Now it's working perfect!!!

@bkoelman bkoelman merged commit fe2aa73 into master Nov 17, 2023
13 checks passed
@bkoelman bkoelman deleted the fix-trace-logging-in-operations branch November 17, 2023 14:47
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

Serialization error on Trace level with Atomic Operations
2 participants