Prig test run crashing (when a nested static, unstubbed method is called)

[andy250]

I have a problem with couple of my tests. I generally observed that prig has issues with static methods with optional arguments. Not always though - I tried to reproduce this on a side project but I could not. However in my tests (fairly large solution) there are a few which had optional arguments, and they crashed the whole test run. Refactoring to methods without optional arguments solved it... for some of the. There are few tests which crash even after optional args have been removed. When I am running the test in the console:
prig run -process "C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\CommonExtensions\Microsoft\TestWindow \vstest.console.exe" -arguments "PrigTests.dll"
the process crashes, I get popup "program stopped working" then I click the "debug" button and I can get this stack trace in VS:
https://www.screencast.com/t/jvesh3Yrx
This doesn't tell me much though. Anyone has a clue what might be wrong? I am willing to make further investigation and provide more details on this tomorrow.

[urasandesu]

Thank you for the reporting! But it seems a difficult problem...

Possibly, Prig was outputting some error log. By default, it is in the directory %ALLUSERSPROFILE%\chocolatey\lib\Prig\tools\log. If possible, could you share it to me?

[andy250]

Here it is, but I suspect these are not the errors I was referring to:

2017/01/26 10:39:12.283066,ERROR,0x00002648,11,0x00002ef8," Weaver.cpp(175): Throw in function long __stdcall CWeaverDetail::CWeaverImpl::InitializeCore(struct IUnknown *)
Dynamic exception type: class boost::exception_detail::clone_impl
std::exception::what: The package which has the source """"C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\CommonExtensions\Microsoft\IntelliTrace\14.0.0"""" is not found.
[struct Urasandesu::CppAnonym::tag_stack_trace *] = at ?save_object_data@?$oserializer@Vxml_woarchive@archive@boost@@VPath@filesystem@3@@detail@archive@boost@@UBEXAAVbasic_oarchive@234@PBX@Z in C:\ProgramData\chocolatey\lib\Prig\tools\x86\Urasandesu.Prig.dll
at ?save_object_data@?$oserializer@Vxml_woarchive@archive@boost@@VPath@filesystem@3@@detail@archive@boost@@UBEXAAVbasic_oarchive@234@PBX@Z in C:\ProgramData\chocolatey\lib\Prig\tools\x86\Urasandesu.Prig.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at IEE in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at IEE in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at SetRuntimeInfo in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at DllRegisterServerInternal in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at SetRuntimeInfo in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at _CorExeMain in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at _CorExeMain in C:\Windows\Microsoft.NET\Framework\v4.0.30319\mscoreei.dll
at _CorExeMain in C:\Windows\SYSTEM32\MSCOREE.DLL
at BaseThreadInitThunk in C:\Windows\SYSTEM32\KERNEL32.dll
at RtlSetCurrentTransaction in C:\Windows\SYSTEM32\ntdll.dll
at RtlSetCurrentTransaction in C:\Windows\SYSTEM32\ntdll.dll

","C:\Users\urasa\Prig\Swathe\Urasandesu.Swathe\Urasandesu/Swathe/Profiling/ICorProfilerCallbackImpl.h",262,"long __stdcall CWeaverDetail::CWeaverImpl::InitializeCore(struct IUnknown *)=>Weaver.cpp,115","if (regex_search(procPath, wregex(targetProcName)))=>Weaver.cpp,139"
2017/01/26 12:00:47.667896,ERROR,0x0000264c,11,0x00002724," Weaver.cpp(175): Throw in function long __stdcall CWeaverDetail::CWeaverImpl::InitializeCore(struct IUnknown *)
Dynamic exception type: class boost::exception_detail::clone_impl
std::exception::what: The package which has the source """"C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\CommonExtensions\Microsoft\IntelliTrace\14.0.0"""" is not found.
[struct Urasandesu::CppAnonym::tag_stack_trace *] = at ?save_object_data@?$oserializer@Vxml_woarchive@archive@boost@@VPath@filesystem@3@@detail@archive@boost@@UBEXAAVbasic_oarchive@234@PBX@Z in C:\ProgramData\chocolatey\lib\Prig\tools\x86\Urasandesu.Prig.dll
at ?save_object_data@?$oserializer@Vxml_woarchive@archive@boost@@VPath@filesystem@3@@detail@archive@boost@@UBEXAAVbasic_oarchive@234@PBX@Z in C:\ProgramData\chocolatey\lib\Prig\tools\x86\Urasandesu.Prig.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at IEE in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at IEE in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at SetRuntimeInfo in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at DllRegisterServerInternal in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at SetRuntimeInfo in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at _CorExeMain in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at _CorExeMain in C:\Windows\Microsoft.NET\Framework\v4.0.30319\mscoreei.dll
at _CorExeMain in C:\Windows\SYSTEM32\MSCOREE.DLL
at BaseThreadInitThunk in C:\Windows\SYSTEM32\KERNEL32.dll
at RtlSetCurrentTransaction in C:\Windows\SYSTEM32\ntdll.dll
at RtlSetCurrentTransaction in C:\Windows\SYSTEM32\ntdll.dll

","C:\Users\urasa\Prig\Swathe\Urasandesu.Swathe\Urasandesu/Swathe/Profiling/ICorProfilerCallbackImpl.h",262,"long __stdcall CWeaverDetail::CWeaverImpl::InitializeCore(struct IUnknown *)=>Weaver.cpp,115","if (regex_search(procPath, wregex(targetProcName)))=>Weaver.cpp,139"
2017/01/26 12:58:18.243092,ERROR,0x00002d2c,11,0x00001318," Weaver.cpp(175): Throw in function long __stdcall CWeaverDetail::CWeaverImpl::InitializeCore(struct IUnknown *)
Dynamic exception type: class boost::exception_detail::clone_impl
std::exception::what: The package which has the source """"C:\Program Files (x86)\Microsoft Visual Studio 14.0\Common7\IDE\CommonExtensions\Microsoft\IntelliTrace\14.0.0"""" is not found.
[struct Urasandesu::CppAnonym::tag_stack_trace *] = at ?save_object_data@?$oserializer@Vxml_woarchive@archive@boost@@VPath@filesystem@3@@detail@archive@boost@@UBEXAAVbasic_oarchive@234@PBX@Z in C:\ProgramData\chocolatey\lib\Prig\tools\x86\Urasandesu.Prig.dll
at ?save_object_data@?$oserializer@Vxml_woarchive@archive@boost@@VPath@filesystem@3@@detail@archive@boost@@UBEXAAVbasic_oarchive@234@PBX@Z in C:\ProgramData\chocolatey\lib\Prig\tools\x86\Urasandesu.Prig.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at GetHistoryFileDirectory in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at IEE in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at IEE in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at SetRuntimeInfo in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at DllRegisterServerInternal in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at SetRuntimeInfo in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at _CorExeMain in C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
at _CorExeMain in C:\Windows\Microsoft.NET\Framework\v4.0.30319\mscoreei.dll
at _CorExeMain in C:\Windows\SYSTEM32\MSCOREE.DLL
at BaseThreadInitThunk in C:\Windows\SYSTEM32\KERNEL32.dll
at RtlSetCurrentTransaction in C:\Windows\SYSTEM32\ntdll.dll
at RtlSetCurrentTransaction in C:\Windows\SYSTEM32\ntdll.dll

","C:\Users\urasa\Prig\Swathe\Urasandesu.Swathe\Urasandesu/Swathe/Profiling/ICorProfilerCallbackImpl.h",262,"long __stdcall CWeaverDetail::CWeaverImpl::InitializeCore(struct IUnknown *)=>Weaver.cpp,115","if (regex_search(procPath, wregex(targetProcName)))=>Weaver.cpp,139"

[andy250]

I also managed to get a brief error message in visual studio when the test process crashes: it says that the heap is damaged.

[andy250]

I have made some further investigation and the error is not caused by optional arguments. My code is set up as follows:

public void DoSomething(.....) {
....
StaticClass.StaticMethod(.....);
}

public static void StaticMethod(....) {
....
string result = AnotherStaticClass.AnotherStaticMethod("some string input");
}

The test calls DoSomething and stubs the StaticMethod with a simple delegate. As soon as I comment out the line var result = AnotherStaticClass.AnotherStaticMethod(...); and recompile prig assemblies the test starts to work. I cannot share my exact code and I am unable to reproduce this behavior on a side project unfortunately. It is strange that the crash occurrs when calling stubbed method, only if that method originally contained a call to another static method (which happens to be also avialble for stubbing).

Might there be some problem with how the classes/methods are named, or how many args they have or with naming of those args? I should also mention that AnotherStaticMethod is also added in prig settings file (so I can stub this one, and I actually do that in some other tests, which work just fine).

[urasandesu]

Here it is, but I suspect these are not the errors I was referring to:

The latest error log that is recorded at 2017/01/26 12:58:18.243092 is probably caused by that prig install command was not executed correctly, but umm... What is "IntelliTrace"? I little investigated about that, it seems the feature Visual Studio 2015 Enterprise Edition or more only has. Could you disable it?

[urasandesu]

I have made some further investigation and the error is not caused by optional arguments. My code is set up as follows:

Thank you for your deep investigation!

In the past, the complex issue around a parameter that is caused by the order of referenced assembly existed. You might be able to reproduce on a side project if you make it having plurality class libraries.

[andy250]

There is one more thing I noticed: when I run the test from VS Test Explorer it works. When it is executed from ReSharper test runner, or from command line ("prig run ...") - then it crashes.

[urasandesu]

I don't have ReSharper license, so I'm investigating command line side. However, vstest.console.exe works correctly in my environment against some simple samples 😥

Now, I have requested ReSharper Ultimate Free Open Source License to JetBrains to investigate this issue. I will contact you if there is progress.

[andy250]

Thanks for your support. Today I did even more investigation and it seems that the cause of the error is even different than I thought. I even can't isolate the problematic line of code now. What I'm doing is commenting/changing code within the method that is being stubbed in the test, recompiling prig assemblies and re-runing the test. There is some randomness around it, and in the end it seems that the optional parameters have something to do with the issue - when removing/changing calls to such methods I am able to make the test run or make it fail, but it doesn't seem to be consistent (or I can't see the clue).

I also tried on a side project as well, by copying quite a lot of code from my original project but without success. In the new project the test passes.

[ngjermundshaug]

I tried to run one of @andy250 's tests (we're co-workers) - and it also failed on my local PC.

When analyzing the .dmp file in DebugDiag2 - it seems it is also related to Serialization in Boost.

Exception Information

NTDLL!RTLREPORTCRITICALFAILURE+89In vstest.executionengine.x86.exe.21552.dmp the assembly instruction at ntdll!RtlReportCriticalFailure+89 in C:\Windows\System32\ntdll.dll from Microsoft Corporation has caused a corrupted heap exception (0xC0000374) when trying to perform an unknown operation on memory location 0x09b1b500 on thread 21

Thread 21 - System ID 6168

This thread is not fully resolved and may or may not be a problem. Further analysis of these threads may be required.

.NET Call Stack

[[PrestubMethodFrame] (.{error})] www.dll!Unknown 

Full Call Stack

ntdll!NtWaitForMultipleObjects+c 
ntdll!WerpWaitForCrashReporting+63 
ntdll!RtlReportExceptionHelper+2c7 
ntdll!RtlReportException+6a 
ntdll!RtlReportCriticalFailure+ad 
ntdll!RtlpReportHeapFailure+32 
ntdll!RtlpLogHeapFailure+9f 
ntdll!RtlFreeHeap+ac 
msvcr120!free+1a 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+a7024 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+a72ee 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+13038b 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+12fd67 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+130266 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+12fa41 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+12f4e5 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+129826 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+f8c0d 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+aa0b6 
Urasandesu_Prig!InstanceGettersTryRemove+1d1b 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+51765 
Urasandesu_Prig!boost::archive::detail::oserializer<boost::archive::xml_woarchive,boost::filesystem::path>::save_object_data+4f0fb 
clr!EEToProfInterfaceImpl::JITCompilationStarted+5d 
clr!MethodDesc::MakeJitWorker+2fe

[urasandesu]

@ngjermundshaug, it is strange... In the stack trace, boost::archive::xml_woarchive is appeared. This class is only used when executing prig install, prig update and prig uninstall command in Prig. Normally, these command is executed only once at the first time in each environment.

Are you wrapping prig run by any scripts? If it is true, would you share it to me?

[andy250]

Basically when running from within VS "prig run" is wrapped by either ReSharper test runner or VSTest runner (which we donb't have access to). When running from command line there is no additional wrapping.

Today I can observe a bit different behavior (which is weird, to say the least):

1. pring run -process "vstest.console.exe" -arguments "PrigTests.sll /Tests:CrashingTestName" --> test runs but the stubs are not working (original implementation is called) - which is different than it was yesterday/last week. How is this even possible?
2. ReSharper test runner from within VS --> test crashes. ReSharper uses vstest.executionengine.x86.exe internally. The error originates in C:\Windows\SYSTEM32\ntdll.dll.

[urasandesu]

OK, I have understood that there are no any wrapper scripts. Ummmmm...

[ngjermundshaug]

Restarted PC, Opened VS, Recompiled, Ran test with VS Test Runner ==> It crashed.
So it's definitely not related to installing/uninstalling PRIG in the VS Menu.