Intermittent AccessViolationException in Mock<>.Object

[mayerj]

stack.txt
We are seeing an intermittent (but locally reproducible) issue in our CI environment (TFS/vstest). It seems to happen roughly 10% of the time I run our CI tests.

It is an AccessViolationException inside the stack below. This callstack is visible from the diagnostic logs in vstest, but Moq seems to catch it and actually just returns null from Mock<>.Object.

While it is always a specific test that fails, there are many other tests that are running in parallel at the same time. I have not been able to get a smaller repro yet.

I don't know if this is a problem in Moq, Castle, or even .NET 4.7.2.

We are using Moq 4.12.0 (this also happened on 4.10.1, I upgraded to see if it fixed it).

Here is the callstack:

SP IP
00:U 000000a9a7cf9c20 00007ffa00000000 CLRStub@00007ffa00000000
01:U 000000a9a7cf9c28 00000000000000b6 CLRStub@00000000000000b6
02:U 000000a9a7cf9c30 000000a9a7cf9d20 CLRStub@000000a9a7cf9d20
03:U 000000a9a7cf9c38 000000a9a7cfa240 CLRStub@000000a9a7cfa240
04:U 000000a9a7cf9c40 0000000000000017 CLRStub@0000000000000017
05:M 000000a9a7cfcf50 00007ffaa31b4e42 System.Signature..ctor(System.IRuntimeMethodInfo, System.RuntimeType)(+0x0 IL,+0x32 Native)
06:M 000000a9a7cfcfa0 00007ffaa33cbc41 System.Reflection.RuntimeConstructorInfo.get_Signature()(+0x19 IL,+0x31 Native)
07:M 000000a9a7cfcfe0 00007ffaa33cbbd7 System.Reflection.RuntimeConstructorInfo.GetParametersNoCopy()(+0x8 IL,+0x17 Native)
08:M 000000a9a7cfd010 00007ffaa33daffe System.Reflection.RuntimeConstructorInfo.GetParameters()(+0x0 IL,+0xe Native)
09:M 000000a9a7cfd050 00007ffaa4e596c1 Castle.DynamicProxy.Generators.BaseProxyGenerator.GenerateConstructor(Castle.DynamicProxy.Generators.Emitters.ClassEmitter, System.Reflection.ConstructorInfo, Castle.DynamicProxy.Generators.Emitters.SimpleAST.FieldReference[])(+0xb IL,+0x61 Native)
0a:M 000000a9a7cfd100 00007ffaa4e59580 Castle.DynamicProxy.Generators.BaseProxyGenerator.GenerateConstructors(Castle.DynamicProxy.Generators.Emitters.ClassEmitter, System.Type, Castle.DynamicProxy.Generators.Emitters.SimpleAST.FieldReference[])(+0x23 IL,+0x60 Native)
0b:M 000000a9a7cfd160 00007ffaa4e5d2a9 Castle.DynamicProxy.Generators.ClassProxyGenerator.GenerateType(System.String, System.Type[], Castle.DynamicProxy.Generators.INamingScope)(+0x119 IL,+0x2b9 Native)
0c:M 000000a9a7cfd1e0 00007ffaa4e40f44 Castle.Core.Internal.SynchronizedDictionary2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].GetOrAdd(System.__Canon, System.Func2<System.__Canon,System.__Canon>)(+0x57 IL,+0xc4 Native)
0d:M 000000a9a7cfd230 00007ffaa4e40d65 Castle.DynamicProxy.Generators.BaseProxyGenerator.ObtainProxyType(Castle.DynamicProxy.Generators.CacheKey, System.Func3<System.String,Castle.DynamicProxy.Generators.INamingScope,System.Type>)(+0x33 IL,+0x95 Native) 0e:M 000000a9a7cfd280 00007ffaa4e5c178 Castle.DynamicProxy.ProxyGenerator.CreateClassProxy(System.Type, System.Type[], Castle.DynamicProxy.ProxyGenerationOptions, System.Object[], Castle.DynamicProxy.IInterceptor[])(+0x57 IL,+0x88 Native) 0f:M 000000a9a7cfd2d0 00007ffaa3e48b56 Moq.CastleProxyFactory.CreateProxy(System.Type, Moq.IInterceptor, System.Type[], System.Object[])(+0xc2 IL,+0x256 Native) 10:M 000000a9a7cfd360 00007ffaa3e48894 Moq.Mock1[[System.__Canon, mscorlib]].InitializeInstance()(+0x31 IL,+0xd4 Native)
11:M 000000a9a7cfd3c0 00007ffaa3e48797 Moq.Mock1[[System.__Canon, mscorlib]].OnGetObject()(+0x13 IL,+0x17 Native) 12:M 000000a9a7cfd3f0 00007ffaa3e48725 Moq.Mock1[[System.__Canon, mscorlib]].get_Object()(+0x0 IL,+0x15 Native)
13:M 000000a9a7cfd430 00007ffaa553cd8b MyTests.SetupMocks(TestMocks)(+0xce IL,+0x43b Native)
14:M 000000a9a7cfd640 00007ffaa3e3ee72 MyTests.Test()(+0x9 IL,+0x82 Native)
15:M 000000a9a7cfdfd0 00007ffaa33e1337 System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)(+0xe7 Native)
16:M 000000a9a7cfe050 00007ffaa3fe0fa1 System.Reflection.MethodBase.Invoke(System.Object, System.Object[])(+0x0 IL,+0x21 Native)
17:M 000000a9a7cfe090 00007ffaa3e343c2 Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Extensions.MethodInfoExtensions.InvokeAsSynchronousTask(System.Reflection.MethodInfo, System.Object, System.Object[])(+0x1d IL,+0x42 Native)
18:M 000000a9a7cfe0e0 00007ffaa553908d Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.ThreadOperations.ExecuteWithAbortSafety(System.Action)(+0x0 IL,+0x1d Native)
19:M 000000a9a7cfe130 00007ffaa5538009 Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.TestMethodInfo.ExecuteInternal(System.Object[])(+0x77 IL,+0x139 Native)
1a:M 000000a9a7cfe1a0 00007ffaa5537e67 Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.Execution.TestMethodInfo+<>c__DisplayClass48_0.b__0()(+0x0 IL,+0x27 Native)
1b:M 000000a9a7cfe1e0 00007ffaa31d7eef System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)(+0x79 IL,+0x16f Native)
1c:M 000000a9a7cfe2b0 00007ffaa31d6564 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)(+0x0 IL,+0x14 Native)
1d:M 000000a9a7cfe2e0 00007ffaa31d63dd System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)(+0x4d Native)
1e:M 000000a9a7cfe330 00007ffaa3c33f30 System.Threading.ThreadHelper.ThreadStart()(+0x50 Native)
1f:U 000000a9a7cfe3b0 00007ffb026d6c58 clr!CallDescrWorkerWithHandler+0x4e
20:U 000000a9a7cfe3f0 00007ffb026d751d clr!MethodDescCallSite::CallTargetWorker+0xf8
21:U 000000a9a7cfe4f0 00007ffb02791ce9 clr!ThreadNative::KickOffThread_Worker+0x109
22:U 000000a9a7cfe750 00007ffb026d7ce1 clr!ManagedThreadBase_DispatchInner+0x39
23:U 000000a9a7cfe790 00007ffb026d7c50 clr!ManagedThreadBase_DispatchMiddle+0x6c
24:U 000000a9a7cfe890 00007ffb026d7b8d clr!ManagedThreadBase_DispatchOuter+0x75
25:U 000000a9a7cfe920 00007ffb026daa94 clr!ManagedThreadBase_DispatchInCorrectAD+0x15
26:U 000000a9a7cfe950 00007ffb026dab96 clr!Thread::DoADCallBack+0x278
27:U 000000a9a7cfeb10 00007ffb026daaeb clr!ManagedThreadBase_DispatchInner+0x2e4b
28:U 000000a9a7cfeb50 00007ffb026d7c50 clr!ManagedThreadBase_DispatchMiddle+0x6c
29:U 000000a9a7cfec50 00007ffb026d7b8d clr!ManagedThreadBase_DispatchOuter+0x75
2a:U 000000a9a7cfece0 00007ffb026d7d1f clr!ManagedThreadBase_FullTransitionWithAD+0x2f
2b:U 000000a9a7cfed40 00007ffb02791bcb clr!ThreadNative::KickOffThread+0xdb
2c:U 000000a9a7cfee10 00007ffb027c3f7f clr!Thread::intermediateThreadProc+0x86
2d:U 000000a9a7cff8d0 00007ffb1a354034 kernel32!BaseThreadInitThunk+0x14
2e:U 000000a9a7cff900 00007ffb1ce83691 ntdll!RtlUserThreadStart+0x21

[stakx]

Thanks for reporting. Hard to tell what's going on without repro code and information about the runtime / target framework used, could you provide some more detail?

[mayerj]

I am working on a repro. It is only occurring 5-10% of the time.

I've attached a 2nd callstack as well. This is on .NET Framework 4.7.2.

stack2.txt

[mayerj]

The original AV seems to be in the CodeCoverage engine.

(3f64.48a8): Access violation - code c0000005 (first/second chance not available)
Microsoft_IntelliTrace_Profiler!ModuleInfo::GetOrCreateMethodInfo+0x113:
00007ffadb873403 8907 mov dword ptr [rdi],eax ds:0000000000000102=????????
0:023> k

Child-SP RetAddr Call Site

00 0000001a34c77bf0 00007ffadb8c9402 Microsoft_IntelliTrace_Profiler!ModuleInfo::GetOrCreateMethodInfo+0x113
01 0000001a34c77ce0 00007ffa9927b84d Microsoft_IntelliTrace_Profiler!il_disassembler::initialize_function+0x32
02 0000001a34c77d20 00007ffa992441dd covrun64!vanguard::instrumentation::managed::initialize_function+0x155
03 0000001a34c77e50 00007ffa99252995 covrun64!vanguard::runtime::managed::module::instrument+0x715
04 0000001a34c78530 00007ffa99251366 covrun64!vanguard::runtime::engine::on_module_load_int+0x1601
05 0000001a34c79490 00007ffa992390b8 covrun64!vanguard::runtime::engine::on_module_load+0x46
06 0000001a34c794c0 00007ffadb8cb6ef covrun64!on_module_load+0x24
07 0000001a34c794f0 00007ffadb85f367 Microsoft_IntelliTrace_Profiler!VanguardInstrumentationMethod::ModuleLoaded+0x5f
08 0000001a34c79620 00007ffadb88d594 Microsoft_IntelliTrace_Profiler!InstrumentationMethodCollection::ModuleLoaded+0x47
09 0000001a34c79660 00007ffb02b8d329 Microsoft_IntelliTrace_Profiler!ProfilerCallbacks::ModuleLoadFinished+0x334
0a 0000001a34c79850 00007ffb02a5e867 clr!EEToProfInterfaceImpl::ModuleLoadFinished+0x81
0b 0000001a34c798b0 00007ffb028137de clr!Module::NotifyProfilerLoadFinished+0x267d27
0c 0000001a34c79950 00007ffb027f7ce9 clr!DomainFile::PostLoadLibrary+0x37
0d 0000001a34c79980 00007ffb027f79ec clr!DomainFile::DoIncrementalLoad+0x155
0e 0000001a34c799d0 00007ffb027f76e5 clr!AppDomain::TryIncrementalLoad+0xdd
0f 0000001a34c79dc0 00007ffb027f4b12 clr!AppDomain::LoadDomainFile+0x155
10 0000001a34c79e80 00007ffb027f493b clr!AppDomain::LoadDomainAssemblyInternal+0x228
11 0000001a34c79f80 00007ffb0280c4f9 clr!AppDomain::LoadDomainAssembly+0x8c
12 0000001a34c7a2a0 00007ffb02811c93 clr!Module::LoadAssembly+0x340
13 0000001a34c7a510 00007ffb02719905 clr!Assembly::FindModuleByTypeRef+0x233
14 0000001a34c7a890 00007ffb026e214d clr!ClassLoader::LoadTypeDefOrRefThrowing+0x2f0
15 0000001a34c7a990 00007ffb0271e4c9 clr!SigPointer::GetTypeHandleThrowing+0x5d1
16 0000001a34c7ac70 00007ffb0149f486 clr!SignatureNative::GetSignature+0x319

[siprbaum]

There was just recently also an AccessViolationException in nunit (nunit/nunit#3295 (comment)) which they traced down to some bug in the coreclr. Maybe worth a look?

[stakx]

@mayerj, any progress with the repro? Otherwise, I'll close this issue in a few days' time. (You can always post a repro after that and I'll reopen the issue, but in case this is no longer of any importance or concern to you, there's no point in keeping this open & letting it go stale.)

[mayerj]

Not a lot of luck getting a reliable repro. I've opened a support ticket with Microsoft support to look at the code coverage angle.

[stakx]

@mayerj, I will close this issue to prevent it from going stale. Once you do have a repro (it doesn't have to be 100% reliable, I'm OK with running it a few times or a few copies of it in parallel), please post it here and we'll reopen!

[mayerj]

I know that has been closed for quite some time, but I wanted to circle back so it doesn't sit forever with no explanation. Microsoft confirmed that the code coverage engine used in vs2017/2019 had a bug that was causing incorrect code-gen.

[jnm2]

Just to follow up, the NUnit thread that @siprbaum linked had a reliable repro (after a lot of work): https://github.com/jnm2/NUnitHangRepro. This was the original bug report: dotnet/runtime#10986. It was fixed in .NET Framework in February's update: https://devblogs.microsoft.com/dotnet/net-framework-february-2020-security-and-quality-rollup/.

CLR

• There is a race condition in the portable PDB metadata provider cache that leaked providers and caused crashes in the diagnostic StackTrace API. To fix the race, detect the cause where the provider wasn’t being disposed and dispose it.

[stakx]

@jnm2 thanks a lot for following up on this! Nice to see this did get fixed.