search

Viladoman / CompileScore

Tools for profiling and visualizing C++ build times.
MIT License
460 stars 19 forks source link

[ERROR] Unknown output file extension provided #16

Closed jan-van-bergen closed 3 years ago

jan-van-bergen commented 3 years ago

Hi, I get the following error every time I run the profiler

[14:19:17] Calling ScoreDataExtractor with -msvc -start -d 1 -td 1
Starting MSVC recording...
Recording session started successfully!
Execution Time: 06ms
[14:19:17] Building...
[14:19:29] Calling ScoreDataExtractor with -msvc -stop -tp 100 -td 1 -d 1 -o C:\Git\Pathtracer\compileData.scor
[ERROR] Unknown output file extension provided. The MSVC generator only knows how to generate .scor or .etl files.
Execution Time: 00ms
[14:19:29] [ERROR] Score Data Extractor process failed with code 1. Please check the output pane for more information.
[14:20:45] Score generation completed!

I also get the error A recording is currently in progress on your system is preventing CompileScore from starting a new one.This can occur if you forgot to stop a CompileScore recording prior to running the start command, or if other processes have started ETW traces of their own.Please try running the CompileScore -stop command. every time I dont manually stop the profiler with tracelog -stop MSVC_BUILD_INSIGHTS_SESSION_COMPILE_SCORE

Viladoman commented 3 years ago

Thanks for sharing the issue! I have never seen this before, the actual output path looks solid and it has the correct extension.

It looks like the stop fails for some strange reason when parsing the output file. This makes the extractor never perform the real stop and leading to the second issue you are describing.

I will have a look when I have some free time.

visorz commented 3 years ago

After clean install of CompileScore in Microsoft Visual Studio Enterprise 2019 Version 16.9.2 I get this error:

[10:36:39] Calling ScoreDataExtractor with -msvc -start -d 1 -td 1
Starting MSVC recording...
Recording session started successfully!
Execution Time: 03ms
[10:36:39] Building...
[10:39:21] Calling ScoreDataExtractor with -msvc -stop -tp 100 -td 1 -d 1 -o C:\QDI\Revenue\Source\Features\4.0\[PBI-135122] Interactive FuG Switches\NG.Evaluations\compileData.scor
[ERROR] Unknown output file extension provided. The MSVC generator only knows how to generate .scor or .etl files.
Execution Time: 00ms
[10:39:21] [ERROR] Score Data Extractor process failed with code 1. Please check the output pane for more information.
[10:39:59] Score generation completed!

Another C++ solution works fine:

[11:06:16] Calling ScoreDataExtractor with -msvc -stop -tp 100 -td 1 -d 1 -o C:\Code\Playground\CPPPropertyWithAssignment\compileData.scor
Stopping MSVC recording and Generating Score...
Writing to file C:\Code\Playground\CPPPropertyWithAssignment\compileData.scor
Done!

Difference between solutions are:

Viladoman commented 3 years ago

Sorry for the late reply. Last weeks have been busy on my end.

Looks like something is wrong with the std::filesystem extension() function. As you said, that dot in the path might be messing with it. It still won't explain why @jan-van-bergen 's path is also failing. I think I will replace that code for my own path extension checker.

Regarding the 'Build and Profile' for the whole solution, I want to add also something to build and profile a single project and a single file.

Viladoman commented 3 years ago

Sorry for the late reply. I finally had time to dedicate to this. I fixed some issues with the output path in the Data Extractor:

I hope this helps with the situation. Please let me know if the issue is still present after version 1.5.7.

Thanks for the feedback! It is really appreciated.

NPatch commented 2 years ago

Having the same issue with 2022.

[21:28:11] Calling ScoreDataExtractor with -msvc -start -d 1 -td 1
Starting MSVC recording...
[ERROR] Failed to start recording.
[ERROR] A recording is currently in progress on your system is preventing CompileScore from starting a new one.This can occur if you forgot to stop a CompileScore recording prior to running the start command, or if other processes have started ETW traces of their own.Please try running the CompileScore -stop command.
You can use the 'tracelog -l' command from an elevated command prompt to list all ongoing tracing sessions on your system.Your currently ongoing CompileScore recording will show up as MSVC_BUILD_INSIGHTS_SESSION_COMPILE_SCORE.If no MSVC_BUILD_INSIGHTS_SESSION_COMPILE_SCORE is found, it could mean a kernel ETW trace is currently being collected.This trace will show up as 'NT Kernel Logger' in your tracelog output, and will also prevent you from starting a new trace.You can stop the 'NT Kernel Logger' session by running 'xperf -stop' from an elevated command prompt.
Execution Time: 01ms
[21:28:11] [ERROR] Score Data Extractor failed to start the recording session with code 1. The current build data won't be captured. Please check the output pane for more information.
[21:28:15] Building...
[21:28:15] Calling ScoreDataExtractor with -msvc -stop -tp 100 -td 1 -d 1 -o C:\Users\<user>\Documents\Dev\<project>\compileData.scor
Stopping MSVC recording and Generating Score...
[ERROR] Failed to stop the recording.
[ERROR] ERROR CODE: 20
Execution Time: 00ms
[21:28:15] [ERROR] Score Data Extractor process failed with code 1. Please check the output pane for more information.
[21:28:19] Score generation completed!
NPatch commented 2 years ago

...It needed an elevated VS. Why tho?

Viladoman commented 2 years ago

It looks like it is complaining that multiple recordings are happening.

The MSVC build insights uses the OS event system and are global on the machine, so you don't want to trigger multiple builds while profiling as it will pollute the results with data from other projects. you can try using the 'tracelog -l' command from an elevated command prompt to see if there the tracing session is dangling and kill it if needed.

As a side note it might be nice to have a button to force kill zombie tracing sessions, or at least make the start kill the previous one if existing. Sadly that's not the default behavior provided by the MS SDK atm. But I could try to detect it and force a stop before a start if needed.

I discovered It is not mandatory to use an elevated VS to use the Build Insights SDK ( even thou MS documentation requires it ), that's why I could integrate it properly within VS without problems. Inspecting the tracelogs on your machine might need elevated privileges.

NPatch commented 2 years ago

Tried running tracelog or CompileScore -stop, but they aren't recognized. Also tried from a devenv console, same issue with CompileScore, apart from tracelog -l having no result. Just now tried running tracelog -l in a devenv console from an elevated VS and I'm getting many results. One of them is Microsoft-Windows-Rdp-Graphics-RdpIdd-Trace and another is Microsoft-VisualStudio-Telemetry-PerfWatson2-29336. There are others but I don't recognize any other potential deal breakers, unless we want no .etls in progress whatsoever.

PS: Not sure if it affects anything, but I also see an Avg-IDP logger. Avg tends to be a thorn on one's side when you least expect it, so I'm mentioning it.

PS2: You could ask more info from Bruce Dawson. He might know how to tackle this.

NPatch commented 2 years ago

OTOH, it makes no sense if this error is only there when you run VS without elevated rights, yet it does not happen when you do, if running ETW's are the issue. Shouldn't that affect elevated VS as well? Seeing as ETW captures are not part of VS process, so that closing VS, fixes the issue.