coverlet icon indicating copy to clipboard operation
coverlet copied to clipboard

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

Open eduherminio opened this issue 2 years ago β€’ 15 comments

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>

eduherminio avatar Jul 09 '21 23:07 eduherminio

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 https://github.com/coverlet-coverage/coverlet/issues/511 https://github.com/coverlet-coverage/coverlet/issues/804

And we have some possible solution but the change is unfortunately huge at the moment: https://github.com/coverlet-coverage/coverlet/issues/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 avatar Jul 20 '21 09:07 MarcoRossignoli

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

MarcoRossignoli avatar Jul 20 '21 09:07 MarcoRossignoli

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.

eduherminio avatar Jul 20 '21 11:07 eduherminio

Are you testing in debug or release?

MarcoRossignoli avatar Jul 20 '21 11:07 MarcoRossignoli

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

eduherminio avatar Jul 20 '21 11:07 eduherminio

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

joshsten avatar Nov 10 '21 23:11 joshsten

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.

MarcoRossignoli avatar Nov 11 '21 10:11 MarcoRossignoli

(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)

winterlimelight avatar Jun 02 '22 22:06 winterlimelight

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?

zhchg6666 avatar Feb 13 '23 09:02 zhchg6666

@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 https://github.com/dotnet/roslyn-analyzers/pull/6211#issuecomment-1409894782 you can find some performance comparison between coverlet and Microsoft.CodeCoverage.

jakubch1 avatar Feb 13 '23 10:02 jakubch1

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

eduherminio avatar Feb 13 '23 11:02 eduherminio

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).

MarcoRossignoli avatar Feb 13 '23 11:02 MarcoRossignoli

Is there any work around for this?

anandjaisy avatar Mar 03 '23 03:03 anandjaisy

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.

MarcoRossignoli avatar Mar 03 '23 09:03 MarcoRossignoli