test run duration degredation when upgrading from 8.8.74 to 8.8.165?

[kimpenhaus]

hey @SteveGilham

I hope this doesn't come across as unqualified, but I wanted to share my observations and would like to get your feedback.

Today, Renovate gave us a PR for the version upgrade from 8.8.74 to 8.8.165. When running our PR pipeline, I noticed that the test duration has increased significantly.

Normal run duration of the unit-test step was around 4~6 minutes:

After upgrading to the latest version, this step increased to over 13 minutes:

I re-ran the whole pipeline to ensure it wasn't an issue caused by machine load or something similar - the result was nearly the same:

I'm not sure what additional information I can provide, but I would appreciate any feedback and am happy to provide it.

Thanks,
Marcus

[SteveGilham]

Thank you for the report, unwelcome though the news is.

Of the two significant changes in this release, the recorder rewrite would be the more pervasive, and the more likely culprit. I had hoped it would make little impact, and perhaps more performant by eschewing the extra allocations required with immutable data structures - the AltCover self-tests having shown no noticeable change.

One easy way to find out, if you could be so good as to oblige - here is a build taken from the point immediately before the recorder rewrite began, but after the Cobertura fix. If you could give this a try, that should give a definitive answer as to where the problem lies

nupkgs.zip

If it is the recorder, then I can scrap that change, put out a new release now, and then get an alternative strategy ready for net9.0 in November.

[kimpenhaus]

Good Morning @SteveGilham,

I needed to switch from the azure pipeline to my local machine to run the tests with the version you gave me.

I tried to leave the machine doing its stuff with no interaction - so that the results are more or less comparable.

I then changed the version to:

• 8.8.74
• 8.8.90-pre-gdeef884004
• 8.8.165

I did alsways a dotnet restore and a dotnet build -c Release --force

and then started with the command:

dotnet test Solution.sln --logger trx --results-directory ./_temp --nologo --no-build --configuration Release /p:CopyLocalLockFileAssemblies=true /p:AltCover=true /p:AltCoverFailFast=true /p:AltCoverAssemblyFilter='^(?!Some\.Namespace).*$|^(Some\.Namespace.*?\.Test.*)$' /p:AltCoverAttributeFilter=ExcludeFromCodeCoverage /p:AltCoverCobertura=coverage.cobertura.xml

the results were as follows:

As you can see there - unfortunately - no difference between 8.8.90-pre-gdeef884004 and 8.8.165. So it might be the cobertura fix kickin in - not sure if that is optimizable at all or the state we have to live with

Hope that helps - if you need further information or any other testings - just let me know. I am happy to help with that.

m.

[SteveGilham]

Thank you for that. Not the result I had hoped for.

Could you confirm that you are actually opting to generate Cobertura output (via /p:AltCoverCobertura=... or equivalent), as that change would only affect the reformatting part of the process. The only other differences will be in the versions of third-party libraries used, which will be a tedious thing to track down.

[kimpenhaus]

hope I understood you correctly as I am not a native speaker (guess you figured this already 😄)

yes we are having /p:AltCoverCobertura=coverage.cobertura.xml as parameter (see the long dotnet test Solution.sln (at the end))

[SteveGilham]

My apologies, I had missed the command line, having simply focused on the elapsed time.

Now I know where to look. Thank you!

[kimpenhaus]

Good morning @SteveGilham,

today I gave it another shot with additionally setting the /p:AltCoverSingle=true flag - I thought I try to see if that makes any difference - unfortunately it does not

I thought you might be interested in that as well - if there are other things you might think might improve perf or is worth to try just let me know.

👋🏼

[SteveGilham]

The change in behaviour is to do with processing the file names, which depends on the purely static number and distribution of classes amongst them, not the visits actually made. Examining the changes I made, I can see several possible sources of inefficiency, so at the moment I'm setting up a proper performance test so I can measure how effective any mitigations are.

…

On Thu, 25 Jul 2024 at 08:07, Marcus Kimpenhaus ***@***.***> wrote: Good morning @SteveGilham <https://github.com/SteveGilham>, today I gave it another shot with also setting the /p:AltCoverSingle=true flag - I thought I try to see if that makes any difference - unfortunately it does not grafik.png (view on web) <https://github.com/user-attachments/assets/02e30cf1-7568-4e0a-bd12-311d5725926e> I thought you might be interested in that as well - if there are other things you might think might improve perf or is worth to try just let me know. 👋🏼 — Reply to this email directly, view it on GitHub <#227 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ABY5P5SYCKP2TMG6BHRUA23ZOCP3XAVCNFSM6AAAAABLKK47K2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDENBZGYYTAMJZGQ> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[SteveGilham]

A proper soak test showed that the bottleneck was indeed where I though it would be, and also verified that there were no more hotspots after the fix I made, which brought performance back to where it had been. Here's an interim build for your use -

nupkgs.zip

[kimpenhaus]

Oh that is awesome 🙏 over the weekend I am off with the family but as soon as i will be back home again, I'll run some tests. Thanks for fixing it that fast!

[SteveGilham]

It's also in new release v8.8.173

[kimpenhaus]

hey @SteveGilham,

I can confirm that the test run speed is as good as it was before :) thanks for fixing it that quickly and for allt he time you spent in this project!

m.