Req: Add diagnostic tracing to help find a badly behaving circular reference.

[colinangusmackay]

Is the feature request related to a problem

Somewhere between v17.2.1 and 17.4.2 an issue with a circular reference arose. The object graph I have is made up of Entity Framework objects which have a lot of bi-directional navigation properties. The end result of which is that when I updated the package to 17.4.2, the test fails with a StackOverflowException, so no stack trace. So no way to work out where things went wrong.

I tried adding:

verifySettings.AddExtraSettings(json =>
{
    json.TraceWriter = new Tracer(OutputHelper);
});

Hoping to use my custom ITraceWriter to get some diagnostic information, but it failed with:

System.InvalidCastException
Unable to cast object of type 'Newtonsoft.Json.Serialization.TraceJsonWriter' to type 'VerifyTests.VerifyJsonWriter'.
   at VerifyTests.WriteOnlyJsonConverter.WriteJson(JsonWriter writer, Object value, JsonSerializer serializer) in /_/src/Verify/Serialization/WriteOnlyJsonConverter.cs:line 18

Describe the solution

In order to diagnose the underlying issue, I'd like to be able to supply a custom ITraceWriter (or similar mechanism) so that I can hopefully see where the issue is.

Describe alternatives considered

I tried manually serialising the object into a JSON string with my custom ITraceWrite, but it serialised correctly with no issue. So, it looks like some of the customisations Verify makes to the serialisation process are the issue. I could just use the JSON string as is, but I'd lose some of the built in converters and scrubbers.

I also tried to create a minimal version to supply as a bug report, but it also serialises with Verify fine. I'm guessing you have to go quite deep into the property navigation before the problems start arising. It was able to avoid repeating direct ancestors, but not if the object was referenced elsewhere.

Additional context

This feature request is just to provide additional diagnostic tools to help narrow down another problem.

[SimonCropp]

shouldnt that be a feature request to json.net?

[SimonCropp]

re

Unable to cast object of type 'Newtonsoft.Json.Serialization.TraceJsonWriter' to type 'VerifyTests.VerifyJsonWriter

i wasnt able to reproduce that. can u share a repro?

[colinangusmackay]

shouldnt that be a feature request to json.net?

No, because it serialises correctly using JSON.NET directly using the same settings.

i wasnt able to reproduce that. can u share a repro?

I'll see what I can do.

[colinangusmackay]

I'm at a loss just now. I just tried to reproduce this at home, but it also worked too. I'm guessing there is some really weird interaction happening with my work solution or environment. (Mac vs Windows; Rider vs VisualStudio; some combination of packages; something else that I'm not aware of)

If I figure it out, I'll let you know.

[colinangusmackay]

It's arrays! It doesn't like arrays.

EDIT: I tried using a list instead, it didn't like that either.

using System;
using System.Diagnostics;
using System.Threading.Tasks;
using Newtonsoft.Json.Serialization;
using VerifyTests;
using VerifyXunit;
using Xunit;
using Xunit.Abstractions;

namespace TestProject1;

public class Tracer : ITraceWriter
{
    private readonly ITestOutputHelper _output;

    public Tracer(ITestOutputHelper output)
    {
        _output = output;
    }
    public void Trace(TraceLevel level, string message, Exception? ex)
    {
        _output.WriteLine($"{level}: {message}");
        if (ex != null)
            _output.WriteLine(ex.ToString());
    }

    public TraceLevel LevelFilter => TraceLevel.Verbose;
}

public class MyObject
{
    public int A { get; set; }
    public string B { get; set; }
}

[UsesVerify]
public class UnitTest1
{
    private readonly ITestOutputHelper _output;

    public UnitTest1(ITestOutputHelper output)
    {
        _output = output;
    }
    
    [Fact]
    public async Task TestAsync()
    {
        var arrayOfObj = new MyObject[]
        {
            new () {A = 123, B = "Bee"},
            new () {A = 456, B = "Movie"},
        };
        
        var settings = new VerifySettings();
        settings.AddExtraSettings(json =>
        {
            json.TraceWriter = new Tracer(_output);
        });
        await Verifier.Verify(arrayOfObj, settings);
    }
}

And the output of that test is:

System.InvalidCastException
Unable to cast object of type 'Newtonsoft.Json.Serialization.TraceJsonWriter' to type 'VerifyTests.VerifyJsonWriter'.
   at VerifyTests.WriteOnlyJsonConverter.WriteJson(JsonWriter writer, Object value, JsonSerializer serializer) in /_/src/Verify/Serialization/WriteOnlyJsonConverter.cs:line 18
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeConvertable(JsonWriter writer, JsonConverter converter, Object value, JsonContract contract, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(JsonWriter writer, Object value, JsonContract valueContract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(JsonWriter writer, Object value, JsonContract valueContract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.Serialize(JsonWriter jsonWriter, Object value, Type objectType)
   at Newtonsoft.Json.JsonSerializer.SerializeInternal(JsonWriter jsonWriter, Object value, Type objectType)
   at JsonFormatter.AsJson(Object input, List`1 appends, VerifySettings settings, Counter counter) in /_/src/Verify/Serialization/JsonFormatter.cs:line 23
   at InnerVerifier.TryGetTargetBuilder(Object target, StringBuilder& builder, String& extension) in /_/src/Verify/Verifier/InnerVerifier_Inner.cs:line 82
   at InnerVerifier.VerifyInner(Object target, Func`1 cleanup, IEnumerable`1 targets) in /_/src/Verify/Verifier/InnerVerifier_Inner.cs:line 7
   at InnerVerifier.Verify[T](T target) in /_/src/Verify/Verifier/InnerVerifier_Json.cs:line 80
   at VerifyXunit.Verifier.<>c__DisplayClass1_0.<<Verify>b__0>d.MoveNext() in /_/src/Verify.Xunit/Verifier.cs:line 30
--- End of stack trace from previous location ---
   at TestProject1.UnitTest1.TestAsync() in /Users/colinmackay/dev/VerifyWithTraceWriter/TestProject1/TestProject1/UnitTest1.cs:line 60
   at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_1.<<InvokeTestMethodAsync>b__1>d.MoveNext() in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\Runners\TestInvoker.cs:line 264
--- End of stack trace from previous location ---
   at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in C:\Dev\xunit\xunit\src\xunit.execution\Sdk\Frameworks\ExecutionTimer.cs:line 48
   at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in C:\Dev\xunit\xunit\src\xunit.core\Sdk\ExceptionAggregator.cs:line 90



Info: Started serializing TestProject1.MyObject[]. Path ''.
Info: Started serializing TestProject1.MyObject with converter ArrayConverter. Path ''.
Error: Error serializing TestProject1.MyObject[]. Unable to cast object of type 'Newtonsoft.Json.Serialization.TraceJsonWriter' to type 'VerifyTests.VerifyJsonWriter'. Path ''.
System.InvalidCastException: Unable to cast object of type 'Newtonsoft.Json.Serialization.TraceJsonWriter' to type 'VerifyTests.VerifyJsonWriter'.
   at VerifyTests.WriteOnlyJsonConverter.WriteJson(JsonWriter writer, Object value, JsonSerializer serializer) in /_/src/Verify/Serialization/WriteOnlyJsonConverter.cs:line 18
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeConvertable(JsonWriter writer, JsonConverter converter, Object value, JsonContract contract, JsonContainerContract collectionContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(JsonWriter writer, Object value, JsonContract valueContract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerProperty)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeList(JsonWriter writer, IEnumerable values, JsonArrayContract contract, JsonProperty member, JsonContainerContract collectionContract, JsonProperty containerProperty)

[SimonCropp]

i dont think it is arrays. replace the verify target with a string and i suspect u will get the same exception

looking at the json.net implementation, i cant see a way to support ITraceWriter. happy to accept a PR if u can see a way.

Can you provide me with a minimal repro that causes your circular reference. one without the ITraceWriter code

[colinangusmackay]

i dont think it is arrays. replace the verify target with a string and i suspect u will get the same exception

I changes the Verify line to:

await Verifier.Verify("this is a simple string", settings);

and it worked:

Received: UnitTest1.TestAsync.received.txt
this is a simple string

If I use just a single object (not in an array) it also works:

Received: UnitTest1.TestAsync.received.txt
{
  A: 123,
  B: Bee
}

looking at the json.net implementation, i cant see a way to support ITraceWriter. happy to accept a PR if u can see a way.

It seems to support it without arrays, I see the trace come through with a single MyObject being verified:

Info: Started serializing TestProject1.MyObject. Path ''.
Info: Finished serializing TestProject1.MyObject. Path ''.
Verbose: Serialized JSON: 
{
  "A": 123,
  "B": "Bee"
}

Can you provide me with a minimal repro that causes your circular reference. one without the ITraceWriter code

I can't give you a circular reference reproduction because I don't know where it occurs. That's when I discovered the issue with adding in an ITraceWriter because when I went looking to discover what was causing it, I discovered that I couldn't add the trace diagnostics. Sorry - I didn't mean to cause confusion with the circular reference, that was just background information (the thing that originally broke when I update the Verify.xunit package reference) that led me to the issue with the ITraceWriter. I was hoping that with the trace writer I'd be able to find and fix the circular reference (It's a set of EF entity classes, so I'm hoping it was just some bi-directional navigation property that we don't really need, just added because it makes EF happy and we could replace it by configuring the model builder to not need the navigation property in that location)

Back to your request for a PR. When I get some time I will definitely have a look into it because it would be a really useful thing to have - it already seems to work to some extent, just not with lists or arrays.

In the mean time, I'm happy to close this request if you want. You've been more than helpful trying to get my test working.

[thomas-parrish]

We're also having this issue since Upgrading. I can confirm that the issue was introduced in 17.4.0, and did not exist in 17.3.1.

[SimonCropp]

@thomas-parrish can u provide a repro

[SimonCropp]

@colinangusmackay or @thomas-parrish can one of u supply a repro as a failing unit test in a Pull Request

[thomas-parrish]

I'll see if I can replicate with generic code, but that may take some time. I can tell you that the failing code looks like this:

var results = new
{
    List1 = UsingDbContext(ctx => ctx.Table1.Include(it => it.Table2).ToList()),
    List2 = UsingDbContext(ctx =>ctx.Table3
            .Include(it => it.Table4)
            .ThenInclude(it => it.Table2).ToList()),
};

await Verify(results);

where UsingDbContext wraps a new db context in a using statement and calls save changes after the action passed in.

[SimonCropp]

any update on that repro. i would really like to fix this bug, but not being able to reproduce it is a blocker

[thomas-parrish]

any update on that repro. i would really like to fix this bug, but not being able to reproduce it is a blocker

I haven't been able to produce something I can share yet. Best I can offer is that it's an interaction specific to EF.

If I call verify on the objects that are loaded directly from the database, I get a stack overflow.

If I Json Serialize and then immediately deserialize those same objects (while preserving circular references), I can verify successfully without a stack overflow.

[SimonCropp]

@thomas-parrish can u debug into Verify to see where the recursion is?

[thomas-parrish]

@thomas-parrish can u debug into Verify to see where the recursion is?

This is the call stack when the exception is thrown:

	System.Private.CoreLib.dll!System.RuntimeTypeHandle.GetGenericTypeDefinition(System.RuntimeType type) Line 550	C#
 	System.Private.CoreLib.dll!System.RuntimeType.GetGenericTypeDefinition() Line 154	C#
 	Newtonsoft.Json.dll!Newtonsoft.Json.Utilities.ReflectionUtils.IsNullableType(System.Type t)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Converters.StringEnumConverter.CanConvert(System.Type objectType)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.JsonSerializer.GetMatchingConverter(System.Collections.Generic.IList<Newtonsoft.Json.JsonConverter> converters, System.Type objectType)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(Newtonsoft.Json.JsonWriter writer, object value, Newtonsoft.Json.Serialization.JsonContract valueContract, Newtonsoft.Json.Serialization.JsonProperty member, Newtonsoft.Json.Serialization.JsonContainerContract containerContract, Newtonsoft.Json.Serialization.JsonProperty containerProperty)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(Newtonsoft.Json.JsonWriter writer, object value, Newtonsoft.Json.Serialization.JsonObjectContract contract, Newtonsoft.Json.Serialization.JsonProperty member, Newtonsoft.Json.Serialization.JsonContainerContract collectionContract, Newtonsoft.Json.Serialization.JsonProperty containerProperty)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(Newtonsoft.Json.JsonWriter writer, object value, Newtonsoft.Json.Serialization.JsonContract valueContract, Newtonsoft.Json.Serialization.JsonProperty member, Newtonsoft.Json.Serialization.JsonContainerContract containerContract, Newtonsoft.Json.Serialization.JsonProperty containerProperty)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeObject(Newtonsoft.Json.JsonWriter writer, object value, Newtonsoft.Json.Serialization.JsonObjectContract contract, Newtonsoft.Json.Serialization.JsonProperty member, Newtonsoft.Json.Serialization.JsonContainerContract collectionContract, Newtonsoft.Json.Serialization.JsonProperty containerProperty)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.SerializeValue(Newtonsoft.Json.JsonWriter writer, object value, Newtonsoft.Json.Serialization.JsonContract valueContract, Newtonsoft.Json.Serialization.JsonProperty member, Newtonsoft.Json.Serialization.JsonContainerContract containerContract, Newtonsoft.Json.Serialization.JsonProperty containerProperty)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.Serialization.JsonSerializerInternalWriter.Serialize(Newtonsoft.Json.JsonWriter jsonWriter, object value, System.Type objectType)	Unknown
 	Newtonsoft.Json.dll!Newtonsoft.Json.JsonSerializer.SerializeInternal(Newtonsoft.Json.JsonWriter jsonWriter, object value, System.Type objectType)	Unknown
 	Verify.dll!ArrayConverter.Write(VerifyTests.VerifyJsonWriter writer, object value) Line 14	C#
 	Verify.dll!VerifyTests.WriteOnlyJsonConverter.WriteJson(Newtonsoft.Json.JsonWriter writer, object value, Newtonsoft.Json.JsonSerializer serializer) Line 19	C#

[SimonCropp]

@thomas-parrish so if you can step through the stack overflow. you should be able to tell what is causing it, and produce a repro

[SimonCropp]

any progress on that repro?

[SimonCropp]

can u try version 18.0.0-beta.3

[thomas-parrish]

can u try version 18.0.0-beta.3

Very sorry for the delay, I was absolutely hammered last week and couldn't find time to dig in (oddly enough, I tried almost the exact same circular reference setup that k-maru did, and couldn't reproduce, but didn't have time to dig further.)

This does appear to be fixed in 18.0.0-beta.3, however.