Huge performance drop when using `--collect:"XPlat Code Coverage"` in `dotnet test` (.NET 6) #1192

eduherminio · 2021-07-09T23:53:39Z

I have an NUnit test project with a dependency on coverlet.collector v3.0.3 which becomes unusable when dotnet test is invoked with --collect:"XPlat Code Coverage".

Repro steps:

git clone https://github.com/lynx-chess/Lynx
git checkout 8dd27e9cb2863c6e538638b4482154270ca00525

dotnet test .\tests\Lynx.NUnit.Test\ -c Release --filter "Mate_in_2" # 1s
dotnet test .\tests\Lynx.NUnit.Test\ -c Release --filter "Mate_in_2" --collect:"XPlat Code Coverage" # 47s

dotnet test .\tests\Lynx.NUnit.Test\ -c Release --filter "TestCategory=LongRunning"  # < 4 min
dotnet test .\tests\Lynx.NUnit.Test\ -c Release --filter "TestCategory=LongRunning" --collect:"XPlat Code Coverage"  # Never ending

See also some GH Actions runs (see long-running tests -> Run long-running tests):

Run 1: With coverlet.collector and with --collect:"XPlat Code Coverage" - Manually cancelled after 45 min 🔴
Run 2: With coverlet.collector and without --collect:"XPlat Code Coverage" - ~2.5 min ✔️
Run 3: Without coverlet.collector and without --collect:"XPlat Code Coverage" - ~2.5 min ✔️(the failure in the next step of the job is unrelated)

Versions;

6.0.100-preview.5.21302.13

  <PropertyGroup>
    <TargetFramework>net6.0</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="NUnit" Version="3.13.2" />
    <PackageReference Include="NUnit3TestAdapter" Version="4.0.0" />
    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="16.10.0" />
    <PackageReference Include="coverlet.collector" Version="3.0.3">
      <IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
      <PrivateAssets>all</PrivateAssets>
    </PackageReference>
  </ItemGroup>

The text was updated successfully, but these errors were encountered:

MarcoRossignoli · 2021-07-20T09:54:39Z

I didn't investigate yet but sometimes is "rare but expected", if your tests/code has got a lot of loop can happen. We're injecting some code for every sequence point and this can affect jitter optimization(inlining etc...).
We have a pair of issue open for this problem
#511
#804

And we have some possible solution but the change is unfortunately huge at the moment:
#307

The main issue is that current strategy of coverlet instrumentation is based on sequence point and not on code block so we're sometimes "instrumenting too much".

That said we should take a dump and check if it's related to that or injecting code lead to some latent bug somewhere(infinite loop for some wrong synchronization).

MarcoRossignoli · 2021-07-20T09:58:34Z

@eduherminio have you tried with different runtime version is it the same with 5.0?

eduherminio · 2021-07-20T11:03:09Z

I just did with an older version of the codebase using:

Both .NET 5 and .NET 6 SDKs
Project targeting .NET 5

Similar results for the tests mentioned in the description: 2s -> ~1m 30s.

And yes. this project heavily relies on loops @MarcoRossignoli 😄

I'll monitor those issues as well, hopefully you can find a solution soon 💪🏼💪🏼
Meanwhile, I'll have to avoid collecting coverage for that set of tests.

MarcoRossignoli · 2021-07-20T11:42:24Z

Are you testing in debug or release?

eduherminio · 2021-07-20T11:54:22Z

Originally Release, but I see similar results in Debug: 7s -> ~1min 40s

joshsten · 2021-11-10T23:09:57Z

We are seeing this too on .NET 5. Drop in performance from 30 seconds to over 5 minutes in our case.

MarcoRossignoli · 2021-11-11T10:48:42Z

To be sure that issue is what I expect someone should take a dump of process and check if threads are for most of the time inside RecordHit or RecordSingleHit

In that case for now we don't have a solution 😞

Coverlet instrumentation relies heavily on sequence points and not "blocks" so for every sequence point it emits a "hit records" that despite inlined(is a update indexed array location with +1) can lead to perf issue or maybe to some missing optimization due to "more code to run".
I have one idea of replacing completely the sequence points engine with a "block engine" but it's very huge work.

winterlimelight · 2022-06-02T22:34:38Z

(edit) I withdraw my original comment. I had a misconfiguration which meant the Migrations were being included in the coverage. Once the appropriate exclude filters were actually applying then run time has dropped to normal levels. (https://github.com/coverlet-coverage/coverlet/blob/master/Documentation/VSTestIntegration.md)

zhchg6666 · 2023-02-13T09:03:48Z

Hi @MarcoRossignoli , thanks for your job.
I like this tool, and it already helped me about showing coverage report in azure devops. I still have two questions, please give me some help.

We already have a fix plan for issue or not for vstest driver?
Is this issue also appear in msbulid driver?

jakubch1 · 2023-02-13T10:56:53Z

@eduherminio I was able to get code coverage using Microsoft.CodeCoverage package:

D:\repros\Lynx [main ≡ +0 ~1 -0 !]> dotnet test .\tests\Lynx.Test\ -c Release --filter "TestCategory=LongRunning" --collect:"Code Coverage"
  Determining projects to restore...
  Restored D:\repros\Lynx\tests\Lynx.Test\Lynx.Test.csproj (in 12.6 sec).
  1 of 2 projects are up-to-date for restore.
C:\Program Files\dotnet\sdk\8.0.100-alpha.1.23068.2\Sdks\Microsoft.NET.Sdk\targets\Microsoft.NET.RuntimeIdentifierInference.targets(287,5): message NETSDK1057: You are using a preview version
of .NET. See: https://aka.ms/dotnet-support-policy [D:\repros\Lynx\tests\Lynx.Test\Lynx.Test.csproj]
  Lynx -> D:\repros\Lynx\src\Lynx\bin\Release\net7.0\Lynx.dll
  Lynx.Test -> D:\repros\Lynx\tests\Lynx.Test\bin\Release\net7.0\Lynx.Test.dll
Test run for D:\repros\Lynx\tests\Lynx.Test\bin\Release\net7.0\Lynx.Test.dll (.NETCoreApp,Version=v7.0)
Microsoft (R) Test Execution Command Line Tool Version 17.6.0-preview-20230117-02 (x64)
Copyright (c) Microsoft Corporation.  All rights reserved.

Starting test execution, please wait...
A total of 1 test files matched the specified pattern.

Passed!  - Failed:     0, Passed:    55, Skipped:     0, Total:    55, Duration: 21 m 5 s - Lynx.Test.dll (net7.0)

Attachments:
  D:\repros\Lynx\tests\Lynx.Test\TestResults\f2187645-1e3a-4361-b120-56a09f4d6b89\UseThisAccount_JACHOCHO-5820_2023-02-13.11_16_42.coverage

I've upgraded Microsoft.CodeCoverage to latest Preview version. Still huge perf drop is there but at least tests are finishing.

D:\repros\Lynx [main ≡ +0 ~1 -0 !]> git diff
diff --git a/tests/Lynx.Test/Lynx.Test.csproj b/tests/Lynx.Test/Lynx.Test.csproj
index f04e533..6151b2e 100644
--- a/tests/Lynx.Test/Lynx.Test.csproj
+++ b/tests/Lynx.Test/Lynx.Test.csproj
@@ -8,7 +8,7 @@
     <PackageReference Include="Moq" Version="4.18.4" />
     <PackageReference Include="NUnit" Version="3.13.3" />
     <PackageReference Include="NUnit3TestAdapter" Version="4.3.1" />
-    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.4.1" />
+    <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.5.0-preview-20221221-03" />
     <PackageReference Include="coverlet.collector" Version="3.2.0">
       <IncludeAssets>runtime; build; native; contentfiles; analyzers; buildtransitive</IncludeAssets>
       <PrivateAssets>all</PrivateAssets>

You can also use --collect "Code Coverage;Format=cobertura" if you need cobertura format. Here dotnet/roslyn-analyzers#6211 (comment) you can find some performance comparison between coverlet and Microsoft.CodeCoverage.

eduherminio · 2023-02-13T11:10:33Z

That's definitely a step forward, thanks @jakubch1!

MarcoRossignoli · 2023-02-13T11:12:42Z

We already have a fix plan for issue or not for vstest driver?

At the moment we have not plan to change the engine of coverlet. The main issue I suppose is the fact that coverlet is based on sequence points(so we're inserting more probes than needed for coverage analysis) and we're inserting "hit calls method" in the code(doesn't inline well, for instance in debug).

The update needed to change the two points above is not trivial.

Is this issue also appear in msbulid driver?

Yep coverlet is sharing the same engine for all drivers(.NET tool, msbuild, vstest collector).

anandjaisy · 2023-03-03T03:44:51Z

Is there any work around for this?

MarcoRossignoli · 2023-03-03T09:26:46Z

Is there any work around for this?

As said in the message above at the moment we don't have "workaround". We don't plan at the moment to change how the engine is working, is someone of you want to try something feel free to open a PR I'll be happy to review/help/suggest.

nietras · 2024-06-09T18:57:28Z

Hit the same issue here with at test taking a very very long time to run with --collect:"XPlat Code Coverage" on .NET 8. Guess only option is to switch coverage library.

Bertk · 2024-07-22T08:28:57Z

Please use latest coverage.collector V6.0.2 package and check whether the performance improved.

eduherminio · 2024-07-22T15:12:15Z

There have been clear improvements vs when I opened this issue.
However, an important performance hit can still be observed in my specific scenario.

See perft-tests jobs the in the following test runs:

No collectioon: 3-5 min long test runs (https://github.com/lynx-chess/Lynx/actions/runs/10032966652/job/27725432000)
Microsoft.CodeCoverage: Windows and Linux ~1:30h, MacOS 3:45h (https://github.com/lynx-chess/Lynx/actions/runs/10038049076/job/27739163988)
coverlet: Windows and Linux ~2h, MacOS 20min (!) (https://github.com/lynx-chess/Lynx/actions/runs/10037715443/job/27738104303)

I just realized that the results Jakub reported in February last year were not against the commit id I posted in the description, and therefore can't be compared with the repro because of test categories changes.

MarcoRossignoli · 2024-07-22T15:45:06Z

@eduherminio you could try SingleHit = true if you don't need to account how many time you pass thought the lines for coverlet.

eduherminio · 2024-07-22T16:44:30Z

you could try SingleHit = true if you don't need to account how many time you pass thought the lines for coverlet.

Thanks I just tried that and it cut the time to ~30min!

eduherminio · 2024-07-22T17:22:18Z

To be clear, on my end the performance hit is no longer a blocker, so this issue can be closed unless you choose to use it to track further improvements.

Quick summary with some rough numbers:

--filter "Mate_in_2":

No coverage: ~1s
2021: ~50s
Now: ~2s

--filter "TestCategory=LongRunning":

No coverage: 1-3min
2021: >45min (cancelled)
2023 using Microsoft.CodeCoverage: ~20 min
Now: 1.5-3.5min

--filter "TestCategory=Perft" (I don't actually need code coverage for these ones):

No coverage: 5-6min
2021: never ending
Now using Microsoft.CodeCoverage: Windows and Linux ~1:30h, MacOS 3:45h
Now using coverlet: Windows and Linux ~2h, MacOS 20min
Now using coverlet and SingleHit: ~20-30min

xPaw · 2024-07-27T16:57:01Z

Yeah I was just trying to setup coverlet in a xunit project and also ran into coverage taking a long time to generate (I didn't wait for it to finish, but without it the tests run in seconds).

Bertk · 2024-09-17T12:28:34Z

Please use coverage.collector V6.0.3-preview.10.g7c8c6fae27 package from nightly build and send your feedback. Thanks.
This should also improve performance.

hughbidone · 2025-01-09T21:39:10Z

Please use coverage.collector V6.0.3-preview.10.g7c8c6fae27 package from nightly build and send your feedback. Thanks. This should also improve performance.

For our case this nightly build has improved a lot
Before: ~30mins (6.0.2)
After: ~8mins (6.0.3-preview.10.g7c8c6fae27)

Thanks!

NB: Is it possible to know when this version will be ready for production?

Edit: Same improvement also can be seen with 6.0.3 stable

Bertk · 2025-01-10T08:58:40Z

Coverlet V6.0.3 is published on nuget.org.

daveMueller added the untriaged To be investigated label Jul 10, 2021

MarcoRossignoli added tenet-performance Performance related issue Known Issue It's a know issue labels Jul 20, 2021

Bertk added Solved The issue is solved and can be closed and removed untriaged To be investigated Known Issue It's a know issue labels Jul 23, 2024

Bertk mentioned this issue Aug 31, 2024

Coverage causes hangs #511

Closed

Bertk closed this as completed Jan 10, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Huge performance drop when using `--collect:"XPlat Code Coverage"` in `dotnet test` (.NET 6) #1192

Huge performance drop when using `--collect:"XPlat Code Coverage"` in `dotnet test` (.NET 6) #1192

eduherminio commented Jul 9, 2021 •

edited

Loading

MarcoRossignoli commented Jul 20, 2021 •

edited

Loading

MarcoRossignoli commented Jul 20, 2021

eduherminio commented Jul 20, 2021 •

edited

Loading

MarcoRossignoli commented Jul 20, 2021 •

edited

Loading

eduherminio commented Jul 20, 2021

joshsten commented Nov 10, 2021

MarcoRossignoli commented Nov 11, 2021

winterlimelight commented Jun 2, 2022 •

edited

Loading

zhchg6666 commented Feb 13, 2023 •

edited

Loading

jakubch1 commented Feb 13, 2023

eduherminio commented Feb 13, 2023

MarcoRossignoli commented Feb 13, 2023 •

edited

Loading

anandjaisy commented Mar 3, 2023

MarcoRossignoli commented Mar 3, 2023

nietras commented Jun 9, 2024

Bertk commented Jul 22, 2024

eduherminio commented Jul 22, 2024

MarcoRossignoli commented Jul 22, 2024

eduherminio commented Jul 22, 2024

eduherminio commented Jul 22, 2024

xPaw commented Jul 27, 2024

Bertk commented Sep 17, 2024 •

edited

Loading

hughbidone commented Jan 9, 2025 •

edited

Loading

Bertk commented Jan 10, 2025

Huge performance drop when using --collect:"XPlat Code Coverage" in dotnet test (.NET 6) #1192

Huge performance drop when using --collect:"XPlat Code Coverage" in dotnet test (.NET 6) #1192

Comments

eduherminio commented Jul 9, 2021 • edited Loading

MarcoRossignoli commented Jul 20, 2021 • edited Loading

MarcoRossignoli commented Jul 20, 2021

eduherminio commented Jul 20, 2021 • edited Loading

MarcoRossignoli commented Jul 20, 2021 • edited Loading

eduherminio commented Jul 20, 2021

joshsten commented Nov 10, 2021

MarcoRossignoli commented Nov 11, 2021

winterlimelight commented Jun 2, 2022 • edited Loading

zhchg6666 commented Feb 13, 2023 • edited Loading

jakubch1 commented Feb 13, 2023

eduherminio commented Feb 13, 2023

MarcoRossignoli commented Feb 13, 2023 • edited Loading

anandjaisy commented Mar 3, 2023

MarcoRossignoli commented Mar 3, 2023

nietras commented Jun 9, 2024

Bertk commented Jul 22, 2024

eduherminio commented Jul 22, 2024

MarcoRossignoli commented Jul 22, 2024

eduherminio commented Jul 22, 2024

eduherminio commented Jul 22, 2024

xPaw commented Jul 27, 2024

Bertk commented Sep 17, 2024 • edited Loading

hughbidone commented Jan 9, 2025 • edited Loading

Bertk commented Jan 10, 2025

Huge performance drop when using `--collect:"XPlat Code Coverage"` in `dotnet test` (.NET 6) #1192

Huge performance drop when using `--collect:"XPlat Code Coverage"` in `dotnet test` (.NET 6) #1192

eduherminio commented Jul 9, 2021 •

edited

Loading

MarcoRossignoli commented Jul 20, 2021 •

edited

Loading

eduherminio commented Jul 20, 2021 •

edited

Loading

MarcoRossignoli commented Jul 20, 2021 •

edited

Loading

winterlimelight commented Jun 2, 2022 •

edited

Loading

zhchg6666 commented Feb 13, 2023 •

edited

Loading

MarcoRossignoli commented Feb 13, 2023 •

edited

Loading

Bertk commented Sep 17, 2024 •

edited

Loading

hughbidone commented Jan 9, 2025 •

edited

Loading