Exception.ToString() failed.

[sklivvz]

Minimal repro: dotnet new then modify Program.cs as follows

public class Program
{
    public class Config {}
    public static void Main() { Newtonsoft.Json.JsonConvert.DeserializeObject<Config>(""); }
}

and project.json as follows

{
    "version": "1.0.0-*",
    "compilationOptions": {
        "emitEntryPoint": true
    },

    "dependencies": {
        "NETStandard.Library": "1.0.0-rc2-23811",
        "Newtonsoft.Json": "8.0.2"
    },

    "frameworks": {
        "dnxcore50": { }
    }
}

then dotnet restore, dotnet run

Unhandled Exception:
   Cannot print exception string because Exception.ToString() failed.

Attaching it to visual studio debugger reveals the following error:

Unhandled exception at 0x00007FFFC6988A5C (KernelBase.dll) in min.exe: 0xE0434352 (parameters: 0xFFFFFFFF80070002, 0x0000000000000000, 0x0000000000000000, 0x0000000000000000, 0x00007FFF76A00000).

[0xd4d]

I attached a debugger and this is a friendlier message than what's posted above.

System.IO.FileNotFoundException:

Could not load file or assembly 'System.Runtime.Serialization.Primitives, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a' or one of its dependencies. The system cannot find the file specified.

[ellismg]

/cc @piotrpMSFT

[TheRealPiotrP]

@brthor, can you take a quick look?

[brthor]

Interestingly, the exception here is not in the dotnet cli, or in our host, it's in the client app.

There are two issues here.
The first is that Newtonsoft.Json does not specify any of it's dependencies for .net Core. I've run into this before and they won't be changing this until after rc2.

JamesNK/Newtonsoft.Json#618 (comment)

So the solution there is to keep adding dependencies to the project.json until it works. I end up with this:

{
    "version": "1.0.0-*",
    "compilationOptions": {
        "emitEntryPoint": true
    },

    "dependencies": {
        "NETStandard.Library": "1.0.0-rc2-23811",
        "Newtonsoft.Json": "8.0.2",
        "System.Runtime.Serialization.Primitives" : "1.0.0-rc2-23811",
        "System.Dynamic.Runtime": "1.0.0-rc2-23811",
        "System.Xml.XDocument": "1.0.0-rc2-23811"
    },

    "frameworks": {
        "dnxcore50": { }
    }
}

The second issue is this:

Unhandled Exception:
   Cannot print exception string because Exception.ToString() failed.

It's not clear to me yet what's happening here but it appears to be a failure in coreclr/corefx.

When putting this under a debugger I see System.IO.FileNotFoundException like mentioned above.

[brthor]

Unhandled Exception:
   Cannot print exception string because Exception.ToString() failed.

I think this issue should be investigated in CoreCLR, whatever is printing the exception the app is throwing is failing.

@ellismg Could you redirect this appropriately?

[janvorli]

Here is what happens. The Newtonsoft.Json.JsonConvert.DeserializeObject needs System.Runtime.Serialization.Primitives assembly. But it is not present, so it tries to throw the FileNotFoundException. It creates the exception object and then it wants to set the stack trace for it.
So it looks at the topmost frame of the exception stack trace, finds the Newtonsoft.Json.JsonConvert.DeserializeObject method there and tries to use reflection to get its parameters info. When looking at the 2nd parameter of the method which is of type Newtonsoft.Json.JsonSerializerSettings, it tries to build the metadata structure for this parameter type.
And accidentally, one of the fields of this type is of the StreamingContext type that comes from the System.Runtime.Serialization.Primitives assembly. To get details on the type, it attempts to load this assembly - and since it doesn't exist (that was the reason for the original exception we are trying to build stack trace for), it throws an exception and the result is what you can see.

You can see the relevant part of the stack trace below:

Child-SP          RetAddr           Call Site
000000d3`46dbbd30 00007ffd`c9c04572 KERNELBASE!RaiseException+0x68 [d:\blue\minkernel\kernelbase\xcpt.c @ 828]
000000d3`46dbbe10 00007ffd`8b4f280f VCRUNTIME140!_CxxThrowException+0xc2 [f:\dd\vctools\crt\vcruntime\src\eh\throw.cpp @ 136]
000000d3`46dbbe90 00007ffd`8b853c42 coreclr!EEFileLoadException::Throw+0x47f [d:\git\test\coreclr\src\vm\clrex.cpp @ 2069]
000000d3`46dbc260 00007ffd`8b851547 coreclr!ThrowLoadError+0x182 [d:\git\test\coreclr\src\vm\coreassemblyspec.cpp @ 102]
000000d3`46dbc5b0 00007ffd`8b70ec98 coreclr!AssemblySpec::Bind+0xc87 [d:\git\test\coreclr\src\vm\coreassemblyspec.cpp @ 207]
000000d3`46dbd2d0 00007ffd`8b4a4334 coreclr!AppDomain::BindAssemblySpec+0xd28 [d:\git\test\coreclr\src\vm\appdomain.cpp @ 8871]
000000d3`46dbe110 00007ffd`8b69f656 coreclr!PEFile::LoadAssembly+0x624 [d:\git\test\coreclr\src\vm\pefile.cpp @ 2521]
000000d3`46dbe440 00007ffd`8b82e350 coreclr!Module::LoadAssembly+0x776 [d:\git\test\coreclr\src\vm\ceeload.cpp @ 6167]
000000d3`46dbe830 00007ffd`8b5b28e8 coreclr!Assembly::FindModuleByTypeRef+0xf00 [d:\git\test\coreclr\src\vm\assembly.cpp @ 1748]
000000d3`46dbed50 00007ffd`8b86b3f4 coreclr!ClassLoader::LoadTypeDefOrRefThrowing+0x9f8 [d:\git\test\coreclr\src\vm\clsload.cpp @ 2895]
000000d3`46dbf130 00007ffd`8bc40ae4 coreclr!SigPointer::GetTypeHandleThrowing+0x16e4 [d:\git\test\coreclr\src\vm\siginfo.cpp @ 1505]
000000d3`46dbf6e0 00007ffd`8bc27e8f coreclr!MethodTableBuilder::InitializeFieldDescs+0x1574 [d:\git\test\coreclr\src\vm\methodtablebuilder.cpp @ 4215]
000000d3`46dbfec0 00007ffd`8bc2fc32 coreclr!MethodTableBuilder::BuildMethodTableThrowing+0x1d6f [d:\git\test\coreclr\src\vm\methodtablebuilder.cpp @ 1781]
000000d3`46dc1440 00007ffd`8b5a2ae0 coreclr!ClassLoader::CreateTypeHandleForTypeDefThrowing+0x1802 [d:\git\test\coreclr\src\vm\methodtablebuilder.cpp @ 13440]
000000d3`46dc1c20 00007ffd`8b5a4411 coreclr!ClassLoader::CreateTypeHandleForTypeKey+0x470 [d:\git\test\coreclr\src\vm\clsload.cpp @ 3481]
000000d3`46dc21a0 00007ffd`8b5b57f7 coreclr!ClassLoader::DoIncrementalLoad+0x5a1 [d:\git\test\coreclr\src\vm\clsload.cpp @ 3409]
000000d3`46dc2500 00007ffd`8b5b4299 coreclr!ClassLoader::LoadTypeHandleForTypeKey_Body+0xd77 [d:\git\test\coreclr\src\vm\clsload.cpp @ 4198]
000000d3`46dc28f0 00007ffd`8b5b3c73 coreclr!ClassLoader::LoadTypeHandleForTypeKey+0x4e9 [d:\git\test\coreclr\src\vm\clsload.cpp @ 3918]
000000d3`46dc2b80 00007ffd`8b5b2bc5 coreclr!ClassLoader::LoadTypeDefThrowing+0xf53 [d:\git\test\coreclr\src\vm\clsload.cpp @ 2779]
000000d3`46dc30b0 00007ffd`8b86b3f4 coreclr!ClassLoader::LoadTypeDefOrRefThrowing+0xcd5 [d:\git\test\coreclr\src\vm\clsload.cpp @ 2957]
000000d3`46dc3490 00007ffd`8b5a98b4 coreclr!SigPointer::GetTypeHandleThrowing+0x16e4 [d:\git\test\coreclr\src\vm\siginfo.cpp @ 1505]
000000d3`46dc3a40 00007ffd`8be06c68 coreclr!MetaSig::GetLastTypeHandleThrowing+0x74 [d:\git\test\coreclr\src\vm\siginfo.hpp @ 945]
000000d3`46dc3aa0 00007ffd`2cbb2677 coreclr!SignatureNative::GetSignature+0xee8 [d:\git\test\coreclr\src\vm\runtimehandles.cpp @ 2583]
000000d3`46dc43f0 00007ffd`2cbb2202 mscorlib!System.Reflection.RuntimeMethodInfo.FetchNonReturnParameters()+0x47 [D:\git\test\coreclr\src\mscorlib\src\System\Reflection\MethodInfo.cs @ 319]
000000d3`46dc4440 00007ffd`2c90f315 mscorlib!System.Reflection.RuntimeMethodInfo.GetParameters()+0x12 [D:\git\test\coreclr\src\mscorlib\src\System\Reflection\MethodInfo.cs @ 590]
000000d3`46dc4480 00007ffd`2c90ca45 mscorlib!System.Diagnostics.StackTrace.ToString(TraceFormat)+0x3a5 [D:\git\test\coreclr\src\mscorlib\src\System\Diagnostics\Stacktrace.cs @ 565]
000000d3`46dc4580 00007ffd`2c90bb4e mscorlib!System.Exception.GetStackTrace(Boolean)+0x45 [D:\git\test\coreclr\src\mscorlib\src\System\Exception.cs @ 349]
000000d3`46dc45b0 00007ffd`2c90a747 mscorlib!System.Exception.ToString(Boolean, Boolean)+0x17e [D:\git\test\coreclr\src\mscorlib\src\System\Exception.cs @ 443]
000000d3`46dc4600 00007ffd`8bd6b953 mscorlib!System.Exception.InternalToString()+0x67 [D:\git\test\coreclr\src\mscorlib\src\System\Exception.cs @ 925]

[janvorli]

@sergiy-k FYI

[janvorli]

@jkotas I wonder if we should rather catch exceptions stemming from the System.Exception.GetStackTrace in the System.Exception.ToString and return empty stack trace in such cases rather than failing to convert the exception to string at all.
Or, maybe better, go a bit more fine-grained and catch exceptions in the loop that extracts parameter info in the System.Diagnostics.StackTrace.ToString and put just the method name without parameters to the stack trace in case atttempt to get the ParameterInfo[] throws.
I am a bit worried though that this could be a breaking change.

[jkotas]

go a bit more fine-grained and catch exceptions in the loop that extracts parameter info in the System.Diagnostics.StackTrace.ToString and put just the method name without parameters to the stack trace in case atttempt to get the ParameterInfo[] throws.

This sounds good to me.

I am a bit worried though that this could be a breaking change.

It is fine change to do for CoreCLR / .NET Core. (For full .NET Framework, it would require more careful thought.)

[jkotas]

cc @noahfalk

[noahfalk]

@jkotas thanks for the heads up
@janvorli - From the diagnostics perspective adding additional try/catch around the reflection seems like a fine solution.

I'm surprised that we can have a method on the stack whose parameter type we are unable to load? If the DeserializeObject method has a parameter type that can't be loaded I would expect an error during jitting that prevents the method from ever being invoked and getting on the stack in the first place. If somehow jitting determined the type was unnecessary for correct code generation wouldn't we be at risk of not being able to retrieve GC info during a GC? I suspect there is still something here I didn't grasp.

[jkotas]

JsonSerializerSettings is a class. If it is just used as parameter type, the JIT just needs to know that it is a reference type. It does not need to load the type to figure out the GC info.

[janvorli]

The parameter of type Newtonsoft.Json.JsonSerializerSettings passed to the DeserializeObject is null in our case. That should explain why there was no problem jitting the method.

[janvorli]

With the simple fix I've suggested, running the app now gets this:

Unhandled Exception: System.IO.FileNotFoundException: Could not load file or assembly 'System.Runtime.Serialization.Primitives, Version=4.0.0.0, Culture=neutral
, PublicKeyToken=b03f5f7f11d50a3a' or one of its dependencies. The system cannot find the file specified.
   at Newtonsoft.Json.JsonConvert.DeserializeObject
   at Newtonsoft.Json.JsonConvert.DeserializeObject[T]
   at ConsoleApplication.Program.Main()

[noahfalk]

Makes sense, thanks!

[noahfalk]

@janvorli - LGTM

[janvorli]

Fixed by dotnet/coreclr#3858

[osexpert]

It fails a different place for me:

CLR Info

Version: v4.7.3062.00
Filesize: 0x9EC000
Timestamp: 0x5AB9567C
Dac file: mscordacwks_Amd64_Amd64_4.7.3062.00.dll

Type: System.Runtime.InteropServices.SEHException
Message: External component has thrown an exception.
HResult: 0x80004005
Address: 0x220C5F0
Exception stack trace:

• System.RuntimeTypeHandle.ConstructName(System.RuntimeTypeHandle, System.TypeNa
  meFormatFlags, System.Runtime.CompilerServices.StringHandleOnStack)
• System.RuntimeType+RuntimeTypeCache.ConstructName(System.String ByRef, System.
  TypeNameFormatFlags)
• System.RuntimeType.get_Name()
• System.Diagnostics.StackTrace.ToString(TraceFormat)
• System.Exception.GetStackTrace(Boolean)
• System.Exception.ToString(Boolean, Boolean)
• System.Exception.InternalToString()

The original error is FileNotFoundException.

This fix (catch pi = mb.GetParameters();) will probably not fix my problem.