microsoft / vcperf

A build analysis tool for the MSVC toolchain.
MIT License
296 stars 35 forks source link

Tracing with /level3 results in FAILURE_MERGE_TRACES #15

Open Khaled-Ah opened 4 years ago

Khaled-Ah commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

Were you able to successfully stop your trace?

Khaled-Ah commented 4 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 2 years ago

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 commented 2 months ago

hi @kevcadieux first of all, thank you for all this great work, has been a real ~life~time 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!