Tracing with /level3 results in FAILURE_MERGE_TRACES

[Khaled-Ah]

When trying to analyze a project of our solution with vcperf /level3 it's not possible to successfully stop the tracing session. I've also tried to use /nocpusampling together with /stopnoanalyze but the error still occurs. The Sprout example from the blog works fine.

vcperf /start /level3 MySessionName

Microsoft (R) Visual C++ (R) Performance Analyzer 1.3.20031402
Starting tracing session MySessionName...
Tracing session started successfully!

vcperf /stop /templates MySessionName outputFile.etl

Microsoft (R) Visual C++ (R) Performance Analyzer 1.3.20031402
Stopping and analyzing tracing session MySessionName...
Dropped MSVC events: 0
Dropped MSVC buffers: 0
Dropped system events: 0
Dropped system buffers: 0
Failed to stop trace.
ERROR CODE: FAILURE_MERGE_TRACES

[kevcadieux]

How long is the build you are tracing, and how much space do you have available on your drives? Traces for long builds are larger. This error could mean there isn't enough space on your system drive (normally the C: drive) as vcperf tries to save the temporary non-analyzed trace in a temp directory.

[Khaled-Ah]

The build of the single project takes ~ 2:30 min. I have 220GB of free space on my disk.
Smaller projects that needed only 20 sec to build worked fine.
Our whole solution currently takes 25 minutes to build. Is there a way to specify the temp directory?

[kevcadieux]

You can override the temporary directory by setting the TMP or TEMP environment variable in the same console where you invoke vcperf. I would suggest using a directory on that 220 GB drive.

[kevcadieux]

Were you able to successfully stop your trace?

[Khaled-Ah]

Hi,

I've just set the TEMP folder to a drive that has ~770GB. The generated etl-files reached ~3GB. However it still fails with the same error message. I guess it doesn't seem to be a problem with the file size.

[sandercox]

Having the same issue here.
Freedisk space is 30gb, /stopnoanalyze output file is only 429mb and then I get a FAILURE_MERGE_TRACES.

Project is only a few jobs all parallel 1 job takes the entire time and takes roughly 2 minutes to compile on a i9 7980XE. Trying to figure out where all the time is going, parsing the input files is only part of the time spent but most of it is the rest of my C1DLL bar so was hoping /level3 would provide some insights :-(

[sandercox]

Also tried to stop from Visual Studio (debugger) that throws an Access Violation

msvcrt.dll!00007ffd244744c4()
KernelTraceControl.dll!Microsoft::Windows::Performance::CCvDDCache::CCvDD::CCvDD(class std::basic_string<unsigned short,struct std::char_traits<unsigned short>,class std::allocator<unsigned short>,class _STL70> const &,class std::basic_string<unsigned short,struct std::char_traits<unsigned short>,class std::allocator<unsigned short>,class _STL70> const &,unsigned long,union _CVDD const *,unsigned long const *,struct CODEVIEW_INFORMATION_1 const *,unsigned long,unsigned long,unsigned long,struct EMBEDDED_PDB_INFORMATION const *,bool)
KernelTraceControl.dll!Microsoft::Windows::Performance::CCvDDCache::Add(unsigned short const *,unsigned long,unsigned long,union _CVDD const *,unsigned long const *,struct CODEVIEW_INFORMATION_1 const *,unsigned long,unsigned long,struct EMBEDDED_PDB_INFORMATION *,bool,unsigned short const *,bool *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CImageIdEventTraceExtender::AddImageIdEvents(unsigned long,struct _EVENT_TRACE *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CImageIdEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CEventMetadataEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CPerfTrackMetadataEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CWinSATEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CEventTraceExtenderBase::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CNGenEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CElfImageEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CVolumeMappingEventTraceExtender::OnBeforeEvent(struct _EVENT_TRACE *,unsigned long,void const *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CEventTraceRelogger::ETW_EventCallback_OtherEvents(struct _EVENT_TRACE *,void *)
sechost.dll!00007ffd24d7b144()
sechost.dll!00007ffd24d5076f()
sechost.dll!00007ffd24d3b889()
KernelTraceControl.dll!Microsoft::Windows::Performance::CEventTraceRelogger::HrProcessTrace(class Microsoft::Windows::Performance::CEtwTraceHandleGroup &,struct _FILETIME *,struct _FILETIME *)
KernelTraceControl.dll!Microsoft::Windows::Performance::CEventTraceRelogger::InternalProcessTraces(void)
KernelTraceControl.dll!Microsoft::Windows::Performance::CEventTraceRelogger::ProcessTraces(void)
KernelTraceControl.dll!MergeEtlExWithErrorContext�()
KernelTraceControl.dll!CreateMergedTraceFile�()
CppBuildInsights.dll!00007ffcecb669b7()
CppBuildInsights.dll!00007ffcecb62e1d()
vcperf.exe!Microsoft::Cpp::BuildInsights::StopTracingSession(const wchar_t * sessionName, const wchar_t * outputLogFile, Microsoft::Cpp::BuildInsights::TRACING_SESSION_STATISTICS_TAG * statistics) Line 3421
	at C:\develop\sander\vcperf\packages\Microsoft.Cpp.BuildInsights.1.1.0\build\native\inc\CppBuildInsights.hpp(3421)
vcperf.exe!vcperf::DoStopNoAnalyze(const std::wstring & sessionName, const std::filesystem::path & outputFile) Line 322
	at C:\develop\sander\vcperf\src\Commands.cpp(322)
vcperf.exe!wmain(int argc, wchar_t * * argv) Line 279
	at C:\develop\sander\vcperf\src\main.cpp(279)
vcperf.exe!invoke_main() Line 91
	at d:\agent\_work\59\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl(91)
vcperf.exe!__scrt_common_main_seh() Line 288
	at d:\agent\_work\59\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl(288)
vcperf.exe!__scrt_common_main() Line 331
	at d:\agent\_work\59\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl(331)
vcperf.exe!wmainCRTStartup(void * __formal) Line 17
	at d:\agent\_work\59\s\src\vctools\crt\vcstartup\src\startup\exe_wmain.cpp(17)
kernel32.dll!00007ffd24de7034()
ntdll.dll!00007ffd259dd241()

I can provide pdb & dump file of vcperf that caused this - if helpful.

[kevcadieux]

Thanks for the information. Does this only happen with /level3? Does it happen every time or just occasionally? Yes if you could provide a dump file it could be useful. Opening an issue on Developer Community might be better for submitting a dump file.

[stgatilov]

The same problem happens to me on a custom build of vcperf (freshly merged with this repo's master).
I have hundreds of GB on both drives, and I build only one project, which takes 10 minutes.
I also have Dropped MSVC events: 7, although I suppose it is not critical.

I tried to build the same project again, and got the same exact error.
I tried to build some other projects: did not see the error there.
Tried to build with /level2 instead of /level3: the problem went away too.

UPDATE: Tried to downgrade CppBuildInsights to 1.1.0 which I used previously. Got the same error, but now with 168910 dropped MSVC events.

[mihaisebea]

hi @kevcadieux
first of all, thank you for all this great work, has been a real lifetime saver
second we are seeing a similar issue only with /level3
etl trace uploaded here - https://developercommunity.visualstudio.com/t/vcperf-fails-to-stop-trace-for-C-fail/10731427?sort=newest
tried debugging it but seems cpp_insights dll returns RESULT_CODE_FAILURE_STOP_MSVC_TRACE without any other error or exception :(
I assume the code for this dll is not available for debugging ?
Cheers!