Skip to content

Slow instrumentation for a large project #777

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
katiekloss opened this issue Mar 24, 2020 · 14 comments
Closed

Slow instrumentation for a large project #777

katiekloss opened this issue Mar 24, 2020 · 14 comments
Labels
stale tenet-performance Performance related issue

Comments

@katiekloss
Copy link

katiekloss commented Mar 24, 2020

I'm setting up coverage for a project with about 1.2 million lines of VB.NET code, which compiles to a 24 MB assembly and 48 MB PDB in debug mode. It takes the global tool (version 1.7.0) about 75 minutes to instrument the assembly, which is understandable but not ideal for our build process.

Are there any options I can try to improve instrumentation performance, or is this to be expected from trying to instrument that much IL?

@MarcoRossignoli
Copy link
Collaborator

MarcoRossignoli commented Mar 25, 2020

It takes the global tool (version 1.7.0) about 75 minutes to instrument the assembly

How you can get this numbers?Have you ran /clp:PerformanceSummary?
Are you talking about instrumentation phase or all tests run?

@MarcoRossignoli MarcoRossignoli added the tenet-performance Performance related issue label Mar 25, 2020
@katiekloss
Copy link
Author

katiekloss commented Mar 25, 2020

How you can get this numbers?

I used --verbosity detailed and checked in periodically to see when it logged that the assembly was instrumented.

Have you ran /clp:PerformanceSummary?

Is that an MSBuild flag? I'm using the NUnit test runner as the coverlet target, not dotnet test.

Are you talking about instrumentation phase or all tests run?

Just instrumentation phase. The actual tests only take a few seconds longer to run with coverage, surprisingly enough.

@MarcoRossignoli
Copy link
Collaborator

MarcoRossignoli commented Mar 25, 2020

Is that an MSBuild flag? I'm using the NUnit test runner as the coverlet target, not dotnet test.

Can you use it and > out.txt you'll get msbuild tasks stats and timing from here we can understand how coverlet tasks consume times.

Just instrumentation phase. The actual tests only take a few seconds longer to run with coverage, surprisingly enough.

Yes it's strange we had issues with log test runtime due to instumentation of loops and consequent more code to run, but never had issue with instrumentation phase.

@katiekloss
Copy link
Author

katiekloss commented Mar 25, 2020

Here it is: out.txt

It looks like there was an exception while generating the coverage report, but it does show that the run took 98 minutes and only 25 seconds were spent running the tests.

@MarcoRossignoli
Copy link
Collaborator

MarcoRossignoli commented Mar 28, 2020

Thank's for artifact, I'll take a look asap.
Can you attach your command line?

@MarcoRossignoli MarcoRossignoli added the needs more info More details are needed label Mar 28, 2020
@MarcoRossignoli
Copy link
Collaborator

MarcoRossignoli commented Mar 29, 2020

@katiekloss one question, in your sample do you get output report file?Because on you output I see an exception very similar to #775 that I'm investingation, also I cannot see coverlet expected tasks. Can you run a sample wiht msbuild command so we can see real timing of tasks?

dotnet test /p:CollectCoverage=true /clp:PerformanceSummary > out.txt

out.txt

Here as you can see I found tasks https://github.com/tonerdo/coverlet/blob/master/src/coverlet.msbuild.tasks/coverlet.msbuild.targets InstrumentModules GenerateCoverageResult that are coverlet tasks for instrumentation and report generation

image

@katiekloss
Copy link
Author

Using the MSBuild package instead of the collector, I do get coverage results. The performance summary is attached; it appears that instrumentation and results take 110 minutes and 30 seconds, respectively.

@MarcoRossignoli
Copy link
Collaborator

MarcoRossignoli commented Apr 3, 2020

Ok now we've task numbers

    30292 ms  GenerateCoverageResult                     1 calls
    6609911 ms  InstrumentModules                          1 calls

First time we have this kind of issue, I mean a very slow instrumentation time, we had in past issue with slow test run due to instrumentation and with SingleHit flag things went well.
To undestand what happen we should profile and understand where time is spent(cpu?GC?alg?).
At the moment we don't have that measure, I'll keep this issue open untile we'll find time to tackle perf issues(we have only 1 more perf issue in the repo at the moment https://github.com/tonerdo/coverlet/issues?q=is%3Aissue+is%3Aopen+performance+label%3Atenet-performance).
Honestly perf is a "tenet" in my mind but until now we kept focus on bug/features.
We have two main point to tackle, profile and understand where time is spent and parallelize instrumentation.

At the moment the only way to lowering time is exclude assemblies, I know it's not a solution but at the moment I don't have nothing more that that 😞, I apologize.

Thank you very much for help on investigation!

cc: @tonerdo @petli

@Alexander-Bartosh
Copy link

For me Instrumentation of a relatively small Orleans Project takes a few minutes and consumes 1 CPU
It looks like it is related to the fact that there is generated code in the assembly:
https://dotnet.github.io/orleans/docs/grains/code_generation.html

@Alexander-Bartosh
Copy link

Alexander-Bartosh commented Jun 15, 2021

For me the slowness was solved by excluding generated code:
--collect "XPlat Code coverage" -- DataCollectionRunSettings.DataCollectors.DataCollector.Configuration.ExcludeByAttribute=GeneratedCodeAttribute

Is there any reason why code with GeneratedCodeAttribute is not excluded by default from code coverage ?

@kwaazaar
Copy link

@Alexander-Bartosh Did you have to do anything special to get code coverage on Orleans to work? In my case (self hosted silo using generic host) the grains are reporting to have 0% coverage, while for other classes in the project (outside of the Orleans-stuff) are reported as being covered.

@Alexander-Bartosh
Copy link

@kwaazaar nothing special:

dotnet test /testprojectpath/ /p:Configuration=Debug --no-build --results-directory /tmp/resutls --logger trx --collect "XPlat Code coverage" -- DataCollectionRunSettings.DataCollectors.DataCollector.Configuration.ExcludeByAttribute=GeneratedCodeAttribute

I do collect test coverage from Integration tests

Copy link

github-actions bot commented Jul 7, 2024

This issue is stale because it has been open for 3 months with no activity.

@github-actions github-actions bot added the stale label Jul 7, 2024
@Bertk
Copy link
Collaborator

Bertk commented Sep 19, 2024

This issue was created for global tool V1.7.0 and is meanwhile outdated. The actual version is 6.0.2.

@Bertk Bertk closed this as completed Sep 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
stale tenet-performance Performance related issue
Projects
None yet
Development

No branches or pull requests

5 participants