Skip to content

Increase decompiler test-suite CPU utilization via NUnit parallelism - #3940

Draft
christophwille wants to merge 17 commits into
masterfrom
decompiler-tests-parallelism
Draft

Increase decompiler test-suite CPU utilization via NUnit parallelism#3940
christophwille wants to merge 17 commits into
masterfrom
decompiler-tests-parallelism

Conversation

@christophwille

@christophwille christophwille commented Jul 30, 2026

Copy link
Copy Markdown
Member

A full ICSharpCode.Decompiler.Tests run kept a 24-logical-CPU machine at only ~46% average CPU. This PR makes the suite use the machine it runs on: fixtures run in parallel by default, the NUnit worker pool is oversubscribed to 2x logical CPUs, and the multi-minute tests are scheduled first. A companion doc describes the Windows Defender exclusions that would remove the remaining scan overhead (deliberately not automated).

Measured causes of the idle CPU

  1. ~30 fixture files had no Parallelizable attribute (TypeSystem, Output, Util, Metadata, ProjectDecompiler, ...) - NUnit runs unattributed fixtures one at a time on its non-parallel queue. Only the 12 matrix runners declared Parallelizable(ParallelScope.All).
  2. Worker count = ProcessorCount, but matrix tests spend most of their time blocked on child processes (csc/vbc/ilasm/msbuild/nunit-agent/TestRunner). Blocked workers leave cores idle.
  3. The critical path is a handful of 3-5 minute roundtrip tests (Random_TestCase_1, ExplicitConversions*, NRefactory_CSharp, ...) that started mid-run and straggled at the end.
  4. Windows Defender (MsMpEng.exe) ran at 1-4 cores continuously, scanning every compiled fixture and spawned process (out of scope for code changes; see doc/WindowsDefenderExclusions.md).

Options considered

For raising the worker count:

Option Verdict
Local .runsettings with NumberOfTestWorkers Rejected - a fixed number in a file, and an extra flag every run
Hard-coded [assembly: LevelOfParallelism(48)] Rejected - tuned to one machine; wrong everywhere else (e.g. 4-core CI runners)
Build-time computed attribute, always 2x logical CPUs Chosen - machine-independent policy, no number checked in

For the Defender overhead: apply exclusions vs. document them vs. skip. Machine-level AV configuration does not belong in the repo, so this PR only documents the exclusions (doc/WindowsDefenderExclusions.md).

How the oversubscription works

[assembly: LevelOfParallelism] only accepts a compile-time constant, so the csproj generates it during build:

<AssemblyAttribute Include="NUnit.Framework.LevelOfParallelism">
  <_Parameter1>$([MSBuild]::Multiply($([System.Environment]::ProcessorCount), 2))</_Parameter1>
  <_Parameter1_TypeName>System.Int32</_Parameter1_TypeName>
</AssemblyAttribute>
  • The AssemblyAttribute item is emitted into the SDK-generated AssemblyInfo.cs (obj/.../ICSharpCode.Decompiler.Tests.AssemblyInfo.cs); _Parameter1_TypeName makes MSBuild emit the value as an int rather than a string.
  • The value is 2x the logical CPU count of the machine building the tests - which is the machine running them, both locally and in CI. On the 24-thread dev box this generates LevelOfParallelism(48); on a 4-core CI runner it generates 8.
  • 2x is deliberate oversubscription: NUnit workers are dedicated threads, and most matrix tests block on child compiler/runner processes, so twice as many in-flight tests keeps cores busy without thrashing. The NUnit adapter honors the attribute unless a runsettings value overrides it (none does).
  • [assembly: Parallelizable(ParallelScope.Fixtures)] (in Properties/AssemblyInfo.cs) makes the previously-serial fixtures run concurrently with each other while tests within such a fixture stay sequential. Fixtures sharing process-global state can opt out with [NonParallelizable]; none currently needs to (DecompilerEventSourceTests was audited - its assertions already filter by payload marker).
  • [Order(1)]/[Order(2)] on RoundtripAssembly and CorrectnessTestRunner enqueue the multi-minute tests first.

Before / after (24 logical CPUs, ILSpy-tests checked out)

Baseline This PR
In-flight tests (from TRX start/end stamps) 24, flat 47-48, flat
Longest test start ~t+150s t=0
Wall time 8m16s (3966 tests) 8m11s-8m37s (4170 tests, two runs)
Average total CPU 45.8% 46.2%
Failures 0 0 (two consecutive green runs)

The test-count difference is unrelated new tests picked up by the rebuild. Concurrency verifiably doubled and scheduling is now optimal (every giant starts at t=0), yet wall time and CPU stayed flat - which proves the worker pool is no longer the constraint:

  • The suite is now bounded by its single longest test. Random_TestCase_1 runs 464s wall-to-wall (up from 314s mid-run at baseline - it slows under the doubled contention); total wall time is essentially that one test. More workers cannot help; they only add contention against the critical path.
  • The remaining idle CPU is Defender scan latency on thousands of process spawns and file writes (48 in-flight tests averaged ~0.23 cores each).

Round 2: sequential awaits inside the test infra

A second pass hunted for places where the infra itself awaits independent work sequentially (await a; await b; where a Task.WhenAll or an earlier start genuinely overlaps):

  • Tester.Initialize now runs everything concurrently. It gates every test via the [SetUpFixture], and serialized nine NuGet toolset fetches plus two self-contained TestRunner builds. The fetches extract into disjoint directories and the builds depend on no fetched toolset, so all of it is now started eagerly and awaited once (registration dictionaries got a lock). Only the two Windows RID builds stay sequential with each other - they share the TestRunner project's obj/, and their implicit restores would race on project.assets.json. Biggest effect on a cold machine/CI, where the downloads dominated. Verified with 3 consecutive cold-cache runs (toolset dirs deleted each time), all green.
  • The original and decompiled executables run concurrently. RunAndCompareOutput awaited the two runs back to back; they are independent processes with separately buffered output. Plain Task.WhenAll (no error aggregation) keeps NUnit's Ignore semantics, and exit codes are still asserted in the original order, so failure output is unchanged (verified by sabotaging one path and checking the message).
  • The original executable starts before the decompile. In the correctness runners (RunCS/RunVB/RunIL) and the RunWithOutput roundtrips, the original binary is complete after the first compile, and the decompile/recompile stages only read it - the new Tester.StartRun hands the in-flight run into the comparison. For mcs configurations the .exe.config write moved ahead of the run start (the runtime reads it at process launch); the mcs matrix stays green. In roundtrips the pristine exe now overlaps the multi-minute whole-project decompile; the submodule-missing guard runs before the early start so those tests still report Ignored.
  • FindMSBuild is cached (Lazy<Task<string>>): the parallel roundtrip fixture spawned one vswhere.exe per test for a process-invariant answer.
  • The roundtrip testAction became Func<string, Task> along the way, removing GetAwaiter().GetResult() blocking on NUnit worker threads.

Full suite after the changes: 4170 tests, 0 failures, 20 skipped (environment-gated), wall in the same band as before - expected, since Random_TestCase_1 spends 98.6% of its 480s inside a single WholeProjectDecompiler.DecompileProject call (measured from the harness's Decompiled X in N stamps), which none of this touches. The wins are cold-start setup, the correctness fixture (864 cases), and removed serial slack off the critical path.

Follow-up ideas (non-Defender)

  • Split the generated monoliths in ILSpy-tests. Random_TestCase_1 and the ExplicitConversions* variants are single generated executables from Random Tests/TestCaseGenerator in the ILSpy-tests submodule. Splitting each into several smaller assemblies (or emitting the conversions matrix as N partitions) would turn one 460s pipeline into parallelizable chunks - the only way to push wall time meaningfully below ~8 minutes.
  • The per-file decompile phase is already parallel (WholeProjectDecompiler.MaxDegreeOfParallelism = ProcessorCount), so the giants' serial cost is in their single-assembly csc rebuild and execute/compare phases, which only splitting addresses.
  • Scheduling slack, ~66s. From the TRX timeline: Random_TestCase_1 starts ~27s into the run despite Order(1) (setup + fixture-construction order), and ~44s of unordered fast tests drain after it finishes. Recovering that head/tail is worth more than any remaining in-process await.
  • The Linux/macOS CI job runs its four test assemblies strictly serially (build-ilspy.yml, separate dotnet test --project steps), while the Windows job's --solution form runs them concurrently. Running them in parallel cuts roughly 40% of that job's test time; needs a solution filter without ILSpy.Tests.Windows (which must not run off-Windows) or backgrounded steps.
  • ILSpy.Tests extracts zero parallelism by construction (one Avalonia dispatcher via AvaloniaTestIsolationLevel.PerAssembly plus the static MEF container; PerTest was tried and reverted). Only process-level sharding of fixtures helps; measured fixture durations bin-pack to ~185s slowest shard at 4 shards. Separate effort.

🤖 Generated with Claude Code

@christophwille

Copy link
Copy Markdown
Member Author

Verification: do the NUnit parallelism attributes actually work under Microsoft.Testing.Platform?

The attributes are consumed by NUnit itself, not by the host platform, so MTP vs. VSTest makes no difference - but here is the full verified chain rather than an appeal to documentation.

1. The attributes are physically in the compiled assembly

Reading the PE metadata of the built ICSharpCode.Decompiler.Tests.dll (System.Reflection.Metadata, no runtime load) shows both assembly-level custom attributes with the expected arguments:

Attribute Blob Decoded
NUnit.Framework.LevelOfParallelismAttribute 01 00 30 00 00 00 int32 0x30 = 48 (2x24 logical CPUs of the build machine)
NUnit.Framework.ParallelizableAttribute 01 00 00 02 00 00 0x200 = ParallelScope.Fixtures

2. NUnit 4.6.1 honors the attribute unless the adapter passes an override

Decompiling nunit.framework.dll (with this repo's ilspycmd), NUnitTestAssemblyRunner.GetLevelOfParallelism is:

private int GetLevelOfParallelism(ITest loadedTest)
{
    if (!Settings.TryGetValue("NumberOfTestWorkers", out object value))
        return loadedTest.Properties.TryGet("LevelOfParallelism", DefaultLevelOfParallelism);
    return ConvertSetting<int>(value);
}

The assembly attribute populates the LevelOfParallelism property on the loaded test assembly; the result feeds new ParallelWorkItemDispatcher(48). The parallelism engine is entirely NUnit's in-process dispatcher - MTP (via Microsoft.Testing.Extensions.VSTestBridge) just hosts the adapter and adds nothing to this path.

3. NUnit3TestAdapter 6.2.0 does not inject NumberOfTestWorkers in our invocation

Decompiling NUnit3.TestAdapter.dll:

  • AdapterSettings: NumberOfTestWorkers = GetInnerTextAsInt(xmlNode, "NumberOfTestWorkers", -1) - defaults to -1 when no runsettings node exists.
  • NUnitTestAdapter.CreateTestPackage: the setting is only written into the test package when >= 0, so with the default -1 the framework falls through to the assembly attribute.
  • The only paths that force it to 0 (serial): debugger attached (without AllowParallelWithDebugger), DisableParallelization in runsettings, or CollectDataForEachTestSeparately / Live Unit Testing in-proc collectors. None applies to a plain --report-trx run with no --settings.

4. Empirical proof from the TRX timelines

Reconstructing concurrency from per-test startTime/endTime stamps:

  • Overall in-flight tests: 24, flat (baseline) vs. 47-48, flat (this PR) for the entire run.
  • The ~30 fixtures that previously had no Parallelizable attribute (718 tests in the comparison set): 0 cross-fixture overlapping executions in the baseline run - perfectly serial, as predicted - vs. 4596 overlapping execution pairs across 206 distinct fixture pairs with this PR.

Caveat

The attribute is a default, not a mandate: --settings with NumberOfTestWorkers, DisableParallelization, CollectDataForEachTestSeparately, or running under a debugger overrides or disables it. That matches the adapter's long-standing behavior under VSTest as well.

🤖 Generated with Claude Code

@christophwille

Copy link
Copy Markdown
Member Author

Round 3: Random_TestCase_1 is not a scheduling problem, it is a quadratic DEBUG assertion

The PR notes above concluded that the suite is bounded by one test and that the only remaining lever was "split the generated monoliths in ILSpy-tests". That follow-up was investigated by measuring rather than by splitting, and the conclusion changed: the fixture is fine, the decompiler had a quadratic [Conditional("DEBUG")] check. Fixing it is 8.35x on that fixture and 4-20% on every other assembly, and it removes the need to touch the submodule at all.

All numbers below: macOS, Apple Silicon, 10 logical CPUs, .NET 11 preview SDK, ilspycmd -p -lv CSharp8_0 against the ILSpy-tests fixtures, median of 3, machine otherwise idle. ilspycmd -p is the right proxy because this PR already established the roundtrip test is 98.6% DecompileProject.

1. The critical path is a single method, not a single test

Fixture Size Decompile (Debug) .cs files Lines Shape
TestCase-1.exe 177 KB 22.7 s (102% CPU) 10 9,529 1 real file
ImplicitConversions.exe 203 KB 4.0 s 10 27,712 1 real file, ~220 methods
ImplicitConversions_32.exe 42 KB 1.2 s 10 5,552 1 real file
ExplicitConversions_32.exe 2.1 MB 8.4 s 40 279,416 ~30 fat files, parallelizes
ExplicitConversions.exe 6.3 MB 21.0 s 40 821,186 ~30 fat files, parallelizes

TestCase-1.exe decompiles to one type in one file, and that type's 101 methods are 100 five-line stubs (M0..M99) plus Main, which spans lines 6..8,966 - 8,961 lines in one body. Confirmed directly:

ilspycmd -m "M:TestCases.Main"                       -> 22.2 s   (8,963 lines)
ilspycmd -m "M:TestCases.M0(System.IntPtr,System.Boolean)" -> 0.32 s (incl. ~0.3 s startup)

So 100% of the cost is one method body. Neither the NUnit worker count, nor WholeProjectDecompiler's file-level Parallel.ForEach, nor any per-member parallelism can touch it. The cause is visible in the generator (ILSpy-tests/Random Tests/TestCaseGenerator/Program.cs): GenerateRandomOps loops 100 times and each iteration calls EmitSampledCallsInMain(), which appends up to 10 try/catch regions to the same Main - about 1,000 exception handlers in one body.

2. It is DEBUG-only, and it is one specific check

The same decompile in Release is 2.0 s - an 11x Debug/Release gap, where every other fixture only gains 1.4-2.5x. Gating each CheckInvariant call site behind a separate environment variable and rebuilding isolates it exactly:

Configuration TestCase-1
baseline 23.68 s
AST check off (CSharpDecompiler.RunTransforms) 22.60 s
whole-function check off (ILFunction.RunTransforms) 23.01 s
block check off (Block.RunTransforms) 2.78 s

Instrumenting that one call site with a stopwatch:

Fixture block checks time in checks of total
TestCase-1.exe 21,133 19.48 s 22.37 s (87%)
ImplicitConversions.exe 66,129 0.57 s 4.11 s (14%)

ImplicitConversions runs three times as many checks for 1/34th of the cost: per-check cost is 107x higher in TestCase-1. CheckInvariant is O(size of the block), and the block transforms (ConditionDetection, StatementTransform, ...) merge statements into ever larger blocks, so re-checking after each transform is quadratic in the body size. Block sizes at RunTransforms entry are tiny in both fixtures (max 397 nodes) - the blow-up happens as the transforms merge the 1,000 try/catch groups inside a single call.

3. Three fixes raced (Debug, median of 3, seconds)

  • V1 - count the block's nodes with an early-exit budget, skip the check when oversized.
  • V1b - keep the check but truncate the walk after N nodes (thread-static budget in ILInstruction.CheckInvariant).
  • V2 - drop the per-transform block check entirely.
assembly baseline V1 count+skip V1b budgeted V2 drop
TestCase-1.exe 22.97 3.08 4.13 2.75
ImplicitConversions.exe 4.27 4.31 4.23 3.67
ImplicitConversions_32.exe 1.24 1.24 1.22 1.09
ExplicitConversions.exe 21.01 22.18 21.40 17.48
ExplicitConversions_32.exe 8.36 8.65 8.43 7.33
Mono.Cecil.dll 1.25 1.20 1.22 1.20
ICSharpCode.NRefactory.CSharp.dll 12.52 12.12 12.58 11.84
ICSharpCode.Decompiler.dll 8.59 8.80 8.32 7.95

V2 dominates on every single assembly: 8.35x on the critical path and 4-20% faster everywhere else. The other two are strictly worse:

  • V1 pays an extra traversal (count, then check) on every normal block - consistently ~4% slower than baseline on ordinary assemblies.
  • V1b truncates the recursion in the base CheckInvariant, but the derived overrides still run after base.CheckInvariant returns, and Block.CheckInvariant's HasFlag(EndPointUnreachable) loop forces flag computation over the whole subtree anyway - so most of the cost survives.

4. Head-to-head against the "split the monoliths" idea

To quantify what the submodule change would have bought, a synthetic fixture with the same shape (1,000 try/catch call groups over conversion-heavy leaf methods) was generated with the groups distributed over K methods, total IL constant:

methods (K) baseline with V2
1 22.12 2.32
2 11.95 1.99
5 5.86 1.93
10 3.81 1.97
25 2.74 1.87
100 2.20 1.98

Halving the per-method body size halves the time - the quadratic, confirmed - with a floor around 2.0 s. Splitting needs K >= 25 to approach a floor that V2 reaches at K = 1.

Split the fixture Fix the decompiler (V2)
Effect on TestCase-1 ~8x at K=25, needs regeneration 8.35x
Effect on other assemblies none 4-20% faster
Blast radius second repo (ILSpy-tests) + PR, fixture churn, new [Test] methods, N x msbuild/run/compare per roundtrip one deleted line
Generality that one fixture every large method, for every ILSpy user (a DEBUG build of the UI hangs on such a method for 20 s today)
Coverage change none loses attribution of a corruption to an individual block transform

5. The change

One line removed in ICSharpCode.Decompiler/IL/Instructions/Block.cs, plus a <remarks> block so nobody re-adds it:

 				context.StepStartGroup(transform.GetType().Name);
 				transform.Run(this, context);
-				this.CheckInvariant(ILPhase.Normal);
 				context.StepEndGroup();

What is given up: attribution of a tree corruption to the individual block transform. What still verifies the tree: the block on entry to RunTransforms, every transformed statement inside StatementTransform (StatementTransform.cs:142), and the whole function after every top-level IL transform in ILFunction.RunTransforms. A corrupting block transform is therefore still caught in the same run, attributed to BlockILTransform instead of e.g. ConditionDetection. Note this is a pure DEBUG concern - CheckInvariant is [Conditional("DEBUG")], so Release behaviour and Release timings are untouched.

Verification

  • Decompiled output byte-identical before/after for TestCase-1.exe, ExplicitConversions.exe, Mono.Cecil.dll, ICSharpCode.NRefactory.CSharp.dll and ICSharpCode.Decompiler.dll (recursive diff of the full -p project output).
  • dotnet test --solution ILSpy.XPlat.slnf --report-trx (Debug, macOS): 3343 tests, 0 failed, 216 skipped (environment-gated: Mono/vbc, Windows-only roundtrips).

6. Open item: Windows timing run needed

Everything above is decompile-time on macOS. The roundtrip fixture is [Platform("Win")], so the suite-level effect - the number this PR actually cares about - has not been measured. Projecting this PR's own figures (Random_TestCase_1 = 464 s wall, 98.6% in DecompileProject) gives roughly 464 s -> ~60 s, which should stop the suite being bounded by that test. That projection needs confirming on the 24-thread Windows box.

Instructions for the Windows run

Goal: measure the suite-level wall-time effect of commit 42cdf006a ("Stop verifying the whole block after every block transform") on branch decompiler-tests-parallelism, in the Debug configuration, on a machine that can run the [Platform("Win")] roundtrip tests.

Prerequisites

  1. git submodule update --init ILSpy-tests - without it, every roundtrip test reports Ignored and the run measures nothing. Confirm ILSpy-tests\Random Tests\TestCases\TestCase-1.exe exists.
  2. Apply the Windows Defender exclusions from doc/WindowsDefenderExclusions.md (or note in the results that they were not applied - it is worth several percent and the PR's earlier numbers were taken without them).
  3. Close other load; the numbers being compared differ by minutes, but the machine must be in the same state for both runs.

Measure (Debug configuration - this is the only one affected)

# BEFORE
git checkout 22bd532bc          # parent of the fix
.\restore.ps1
.\build.ps1 -Configuration Debug --no-restore
Measure-Command { dotnet test --project ICSharpCode.Decompiler.Tests\ICSharpCode.Decompiler.Tests.csproj --report-trx }

# AFTER
git checkout 42cdf006a          # the fix
.\build.ps1 -Configuration Debug --no-restore
Measure-Command { dotnet test --project ICSharpCode.Decompiler.Tests\ICSharpCode.Decompiler.Tests.csproj --report-trx }

Use restore.ps1 / build.ps1 rather than bare dotnet commands - a bare restore prunes every packages.lock.json and shows up as a spurious diff.

Report, per run

  1. Total wall time of the dotnet test invocation, and the tests-passed/failed/skipped counts.
  2. Per-test durations from the TRX (startTime/endTime on each UnitTestResult), specifically for Random_TestCase_1, ExplicitConversions*, NRefactory_CSharp, Cecil_net45, NewtonsoftJson_net45. Expected: Random_TestCase_1 drops from ~464 s to roughly 60 s; the other roundtrips should improve a few percent.
  3. Which test is the new longest, and its duration - the point of the change is that Random_TestCase_1 stops being the critical path, so name whatever takes over.
  4. Average total CPU utilization across the run, for comparison against the 45.8% / 46.2% recorded earlier in this PR.
  5. Confirm 0 failures. The DEBUG invariant assertions are what this change touches, so a new Debug.Assert failure anywhere in the decompiler tests is the signal that matters.

Optional cross-check (fast, isolates the decompile from msbuild/run/compare):

.\build.ps1 -Configuration Debug --no-restore
Measure-Command { .\ICSharpCode.ILSpyCmd\bin\Debug\net10.0\ilspycmd.exe -p -lv CSharp8_0 -o $env:TEMP\tc1 "ILSpy-tests\Random Tests\TestCases\TestCase-1.exe" }

Expect roughly an 8x difference between 22bd532bc and 42cdf006a. If that ratio reproduces but the suite wall time does not improve proportionally, then the roundtrip test's remaining cost is the msbuild rebuild / execute / compare phases, and that is the next thing to attack.

Assisted-by: Claude:claude-opus-5[1m]:Claude Code

@christophwille

Copy link
Copy Markdown
Member Author

Windows timing run for 42cdf00 (item 6)

Machine: Windows 11, 24 logical CPUs, .NET 11 preview SDK, Debug configuration, ILSpy-tests at 4ccc3f0. Each commit was measured twice (interleaved: before, after, after, before) because the first pair disagreed with the projection by more than the run-to-run noise. Windows Defender exclusion state could not be verified (Get-MpPreference needs admin); Acronis TrueImageMonitor real-time protection was running. All four runs were taken in the same machine state, otherwise idle. Command per run: restore.ps1 (once), build.ps1 -Configuration Debug --no-restore, Measure-Command { dotnet test --project ICSharpCode.Decompiler.Tests\ICSharpCode.Decompiler.Tests.csproj --report-trx }; CPU sampled every 4 s from \Processor(_Total)\% Processor Time during the dotnet test window only.

1. Suite level

run commit wall passed / failed / skipped avg CPU longest test
before #1 22bd532bc 526.6 s 4150 / 0 / 20 43.0% ExplicitConversions_With_NativeInts 505.1 s
before #2 22bd532bc 544.4 s 4150 / 0 / 20 40.2% Random_TestCase_1 539.3 s
after #1 42cdf006a 578.5 s 4150 / 0 / 20 40.3% NRefactory_CSharp 507.7 s
after #2 42cdf006a 493.6 s 4150 / 0 / 20 40.9% ExplicitConversions 486.2 s

Suite wall time is unchanged within noise (mean 535.5 s before, 536.1 s after; spread +-45 s). 0 failures in all four runs, no new Debug.Assert anywhere. CPU 40-43%, slightly below the 45.8% / 46.2% recorded earlier.

2. Per-test durations (TRX startTime..endTime, seconds)

test before #1 before #2 after #1 after #2
Random_TestCase_1 482.3 539.3 204.0 118.5
ExplicitConversions 504.5 481.9 486.9 486.2
ExplicitConversions_With_NativeInts 505.1 451.1 485.3 483.7
ExplicitConversions_32 384.2 384.7 421.4 383.4
ExplicitConversions_32_With_NativeInts 303.8 372.9 371.7 258.0
NRefactory_CSharp 410.3 451.0 507.7 365.8
NewtonsoftJson_net45 178.3 220.3 241.5 232.7
Cecil_net45 60.9 90.7 112.1 133.8

The Decompiled X in N s line each roundtrip writes to stdout (captured in the TRX) isolates the decompile phase inside the suite:

in-suite decompile before #1 before #2 after #1 after #2
TestCase-1.exe 473.3 536.3 190.4 104.0
ExplicitConversions.exe (x2) 480.6 / 482.1 430.2 / 458.4 451.2 / 459.0 470.7 / 474.1
ICSharpCode.NRefactory.CSharp.dll 342.7 396.2 445.6 316.4
Mono.Cecil.dll 12.9 33.3 70.2 76.1

So Random_TestCase_1 is ~95% decompile in-suite (non-decompile remainder ~14 s), and the fix cuts it 2.5-4.5x. The other roundtrips move by tens of seconds in both directions between identical runs (Cecil 13-76 s, NRefactory 316-446 s) - that is scheduling noise, not the change.

3. New critical path

ExplicitConversions / ExplicitConversions_With_NativeInts at ~485 s each, stable across all four runs (451-505 s), essentially all in the decompile phase (430-482 s). Before the fix they were already neck-and-neck with Random_TestCase_1 on this box (482/539 vs 505/482 s), which is why removing ~350 s from Random_TestCase_1 bought no wall time: the suite is max(long roundtrips) + tail, and the max barely moved.

4. Cross-check: standalone ilspycmd -p -lv CSharp8_0 (Debug, 3 runs each)

before (22bd532bc) after (42cdf006a)
TestCase-1.exe 35.7 / 33.0 / 33.0 s, and 40.9 / 36.3 / 36.4 s 6.2 / 5.7 / 6.3 s, and 5.2 / 5.2 / 5.1 s
ExplicitConversions.exe 20.2 s (not measured)

~6x on TestCase-1 standalone (a bit less than the 8x on macOS; the Windows before-number is ~1.5x slower than the macOS one, the after-number ~2x).

5. The actual finding: in-suite decompiles run 20-25x slower than standalone

  • ExplicitConversions.exe: 20 s standalone, 430-482 s inside the suite.
  • TestCase-1.exe (after): 5-6 s standalone, 104-190 s inside the suite.

at 40% average CPU on 24 threads. That is not compute, it is contention: 48 NUnit workers (LevelOfParallelism = 2x logical CPUs) each running WholeProjectDecompiler's Parallel.ForEach on the shared thread pool (starvation - hill-climbing adds pool threads at ~1-2/s while dozens of Parallel.ForEach callers block), plus workstation GC (default; no ServerGarbageCollection in the test project) with dozens of allocation-heavy threads. Which of the two dominates needs one measurement each (DOTNET_gcServer=1; ThreadPool.SetMinThreads / capping the roundtrip fixture's parallelism), but either way this is the lever for the suite: the ~485 s critical path is a 20 s decompile being starved, so the msbuild/run/compare phases (~14 s on Random_TestCase_1) are not the next thing to attack.

Bottom line for the commit itself: it does what it says (6x standalone, 2.5-4.5x in-suite on TestCase-1, byte-identical output already verified on macOS, 0 failures in 4 Debug runs of the full suite on Windows) and it should stay - but the projected "464 s -> ~60 s" suite gain does not materialize on the 24-thread box, because the suite was never bounded by that single test alone.

Assisted-by: Claude:claude-fable-5:Claude Code

@christophwille

Copy link
Copy Markdown
Member Author

Round 4: the suite was spending 63% of its wall time in GC pauses - server GC halves the run

Two commits pushed:

  • ba4997fc0 reverts 42cdf006a ("Stop verifying the whole block after every block transform"). The Windows run in the previous comment showed it buys nothing at suite level - the suite is bounded by ExplicitConversions* at ~485 s with or without it - and the per-transform block check is worth keeping for attribution of a tree corruption to the individual block transform.
  • 9a981abb1 sets <ServerGarbageCollection>true</ServerGarbageCollection> on ICSharpCode.Decompiler.Tests. Everything below is the measurement behind that.

All numbers: the same 24-thread Windows 11 box, .NET 11 preview SDK, Debug, ILSpy-tests at 4ccc3f0, same driver as the previous comment (restore.ps1 once, build.ps1 -Configuration Debug --no-restore, Measure-Command { dotnet test --project ICSharpCode.Decompiler.Tests\ICSharpCode.Decompiler.Tests.csproj --report-trx }, \Processor(_Total)\% Processor Time sampled every 4 s during the dotnet test window only). Both GC runs are on ba4997fc0, i.e. identical decompiler code; the only difference is the GC mode. GC counters come from a temporary [OneTimeTearDown] that wrote GC.CollectionCount, GC.GetTotalPauseDuration() and GC.GetTotalAllocatedBytes() to a file at the end of the run (not committed).

1. Why the previous round's finding pointed here

The last comment established that the roundtrip decompiles run 20-25x slower inside the suite than standalone (ExplicitConversions.exe: 20 s under ilspycmd, 430-482 s in the suite; TestCase-1.exe after the block-check removal: 5-6 s vs 104-190 s), at only ~40% average CPU on 24 threads. A single-threaded method body that takes 6 s alone and 190 s in the suite while the machine is 60% idle is not compute-bound; something is stopping the world. The test project ran with the default workstation GC while NUnit runs LevelOfParallelism = 2x logical CPUs = 48 workers, each roundtrip additionally fanning out through WholeProjectDecompiler's Parallel.ForEach. Under workstation GC every gen0/gen1 collection any of those threads triggers suspends the entire process.

2. Suite level: workstation vs server GC (same code, one run each)

workstation GC (default) server GC (9a981abb1) change
suite wall time 486.7 s 268.5 s 1.81x faster
average CPU utilization 44.4% 84.3%
passed / failed / skipped 4150 / 0 / 20 4150 / 0 / 20
gen0 / gen1 / gen2 collections 24,846 / 6,280 / 92 978 / 427 / 107 25x / 15x fewer
total GC pause (GC.GetTotalPauseDuration) 306.4 s (63% of wall) 12.4 s (5% of wall) 25x less
total allocated 190.2 GB 126.1 GB
total processor time of the test host 2618 s 2626 s same work, less waiting
longest test Random_TestCase_1 407.9 s NewtonsoftJson_net45 211.4 s

The processor-time row is the key one: the test host burned the same ~2620 CPU-seconds either way, but under workstation GC it spent 306 s with every thread suspended, so those CPU-seconds were spread over 487 s of wall at 44% utilization. Server GC removes the suspension and the same work packs into 268 s at 84%. (The lower allocation total under server GC is the usual effect of per-heap allocation contexts and fewer promotions; it is not a code difference.)

The difference is far outside the run-to-run noise: the four workstation-GC runs in the previous comment plus this one span 486.7-578.5 s; the server-GC run is 268.5 s.

3. Per-test durations (TRX startTime..endTime, seconds)

test workstation GC server GC ratio
Random_TestCase_1 407.9 142.9 2.9x
ExplicitConversions 390.3 129.5 3.0x
ExplicitConversions_With_NativeInts 386.0 149.9 2.6x
NRefactory_CSharp 351.6 164.0 2.1x
ExplicitConversions_32_With_NativeInts 241.4 95.7 2.5x
ExplicitConversions_32 202.9 96.3 2.1x
NewtonsoftJson_net45 181.2 211.4 0.9x
ICSharpCode_Decompiler 180.1 87.6 2.1x
ImplicitConversions 125.3 59.1 2.1x
Cecil_net45 88.5 128.9 0.7x
UseNestedDirectoriesForNamespacesFalseWorks 261.7 (not in top 12)

NewtonsoftJson_net45 and Cecil_net45 did not improve; they now sit at the front of the queue and their duration is dominated by MSBuild rebuild + running the original NUnit suites (external processes, unaffected by the host GC) plus whatever else was scheduled around them - both moved by tens of seconds between identical runs before, too.

4. Decompile phase only (the Decompiled X in N s line each roundtrip prints; two entries = the plain and _With_NativeInts variants)

in-suite decompile workstation GC server GC standalone ilspycmd -p (Debug)
ExplicitConversions.exe 353.4 / 366.0 102.1 / 125.4 20.2
TestCase-1.exe 401.8 133.0 33-36
ICSharpCode.NRefactory.CSharp.dll 312.2 86.0
ExplicitConversions_32.exe 172.7 / 234.0 59.1 / 59.7
ICSharpCode.Decompiler.dll 163.8 52.4
ImplicitConversions.exe 118.8 39.0
Newtonsoft.Json.dll 51.9 / 83.0 29.3 / 31.8
Mono.Cecil.dll 24.3 10.0
ImplicitConversions_32.exe 14.0 6.7

Every decompile phase drops 2-4x. What remains between the server-GC in-suite numbers and standalone (ExplicitConversions 102-125 s vs 20 s) is now real CPU contention at 84% utilization - the fixtures decompiling in parallel with each other and with the ~4,000 other tests - not a stopped world.

5. For comparison: the block-check removal that was reverted

From the previous comment, 42cdf006a (workstation GC) vs its parent, two runs each:

before (22bd532bc) after (42cdf006a)
suite wall 526.6 / 544.4 s 578.5 / 493.6 s
Random_TestCase_1 482.3 / 539.3 s 204.0 / 118.5 s
ExplicitConversions 504.5 / 481.9 s 486.9 / 486.2 s
standalone ilspycmd TestCase-1 33-36 s 5-6 s

It made the one method 6x faster in isolation and did nothing to the suite; server GC does nothing to any single method in isolation and takes 45% off the suite. The block check is back in.

6. Caveats / next

  • One server-GC run so far. Given the size of the effect and the pause counters I did not repeat it, but the numbers should be re-taken on the CI runners: server GC creates one heap per core and on a 2-4 core runner behaves much closer to workstation GC, so the CI gain will be smaller than 1.8x. If CI memory becomes a concern, GCHeapCount / GCConserveMemory are the knobs; nothing was needed on the 24-thread box (peak working set was not measured, though).
  • With GC pauses gone the suite is CPU-bound at 84%, and the longest tests are now 130-210 s external-process-heavy roundtrips (NewtonsoftJson_net45, NRefactory_CSharp). Further wall-time reduction means either less total CPU work per fixture or ordering the long roundtrips first; nothing more to gain from GC or worker-count tuning.

Assisted-by: Claude:claude-fable-5:Claude Code

A full ICSharpCode.Decompiler.Tests run kept a 24-logical-CPU machine at
only ~46% average CPU: unattributed fixtures ran one at a time on NUnit's
non-parallel queue, the default one-worker-per-CPU pool sat blocked on
child compiler/runner processes, and the multi-minute roundtrip and
correctness tests straggled at the end of the run. Fixtures now run in
parallel by default, the worker count is generated at build time as 2x
the building machine's logical CPUs (LevelOfParallelism only accepts a
constant, and a checked-in number would be wrong on every other machine),
and the two heavyweight fixtures are ordered first so the longest tests
start immediately. In-flight tests measured 47-48 instead of 24; the
suite is now bounded by its single longest test rather than by scheduling.

Assisted-by: Claude:claude-fable-5:Claude Code
While the decompiler test suite runs, Defender's scan engine was measured
using 1-4 CPU cores continuously and adds scan latency to every spawned
compiler/runner process. Machine-level AV configuration does not belong in
the repo, so document the folders worth excluding, the tradeoff, and the
commands instead of automating the change.

Assisted-by: Claude:claude-fable-5:Claude Code
Tester.Initialize is about to issue the toolset Fetch calls concurrently;
each Fetch ends by registering its install path in a plain Dictionary,
which is not safe for concurrent writers. Lookups need no lock: they only
happen after Initialize has awaited all registrations.

Assisted-by: Claude:claude-fable-5:Claude Code
The setup fixture gates every test in the suite, and on a cold machine it
serialized nine NuGet fetches plus two self-contained TestRunner builds.
The fetches extract into disjoint directories and the builds depend on no
fetched toolset, so everything now runs concurrently and is awaited once.
Only the two Windows RID builds stay sequential with each other: they
share the TestRunner project's obj/ directory, and their implicit
restores would race on project.assets.json.

Assisted-by: Claude:claude-fable-5:Claude Code
Every roundtrip test spawned its own vswhere.exe to answer a question
that is invariant for the lifetime of the process. Lazy<Task<string>>
with ExecutionAndPublication guarantees a single spawn even when the
parallel roundtrip fixture hits the lookup from several tests at once.

Assisted-by: Claude:claude-fable-5:Claude Code
RunAndCompareOutput awaited the two runs back to back, but they are
independent processes with separately buffered output. The new StartRun
helper also lets callers begin the original run even earlier and hand
the in-flight task to the comparison; it pre-observes the task fault so
a run abandoned after an upstream failure cannot surface as an
UnobservedTaskException. Plain WhenAll (no error aggregation) keeps
NUnit Ignore semantics when both runs raise IgnoreException, and the
exit codes are still asserted in the original order, so failure output
is unchanged.

Assisted-by: Claude:claude-fable-5:Claude Code
The original binary is complete once the first compile (or ilasm)
finishes, and the decompile/recompile stages only read it, so its
execution now overlaps them instead of waiting at the very end of the
pipeline. For mcs configurations the .exe.config write moves ahead of
the run start - the runtime reads it at process launch - while the
compiler-option mutation stays after the decompile, which must see the
original options.

Assisted-by: Claude:claude-fable-5:Claude Code
The RunWithTest/RunWithOutput lambdas blocked an NUnit worker thread
with GetAwaiter().GetResult() on inherently async work. Passing a
Func<string, Task> lets RunInternal await the action, and enables
handing an already-running execution into the comparison.

Assisted-by: Claude:claude-fable-5:Claude Code
In RunWithOutput roundtrip tests the reference executable from the
ILSpy-tests checkout ran only after the whole-project decompile and the
MSBuild rebuild had finished, although nothing in that pipeline writes
to the input directory. Its execution now starts first and overlaps the
multi-minute decompile. The submodule-missing guard moves ahead of the
early start so those tests still report Ignored, not a faulted launch.

Assisted-by: Claude:claude-fable-5:Claude Code
CheckInvariant is O(size of the block), and the block transforms merge statements
into ever larger blocks, so checking after each one is quadratic in the body size.
Normal code never notices, but a method whose statements all land in a single block
does: decompiling ILSpy-tests' TestCase-1.exe (one 8,961-line Main) spent 19.5s of
22.4s inside 21,133 of these checks. That is what made Random_TestCase_1 the test
suite's critical path in the Debug configuration -- the same decompile takes 2.0s in
Release, where the check is compiled out.

Dropping it is 8.3x on that fixture and 4-20% on ordinary assemblies, with output
byte-identical. Two alternatives were measured and rejected: skipping the check only
for oversized blocks costs an extra counting walk (7.3x, but ~4% slower elsewhere),
and truncating the walk with a node budget still lets the derived overrides force
flag computation (5.5x). The tree is still verified on entry, per statement inside
StatementTransform, and per whole function in ILFunction.RunTransforms, so a
corrupting transform is still caught in the same run -- only the attribution to an
individual block transform is given up.

Assisted-by: Claude:claude-opus-5[1m]:Claude Code
This reverts commit 42cdf00.

Measured on a 24-thread Windows box (two Debug runs each way), the
removed check makes no difference to the decompiler test suite's wall
time: the suite is bounded by the ExplicitConversions roundtrips at
~485 s both before and after, and in-suite decompiles run 20-25x
slower than standalone at ~40% CPU, so the cost is contention, not
this invariant check. The per-transform block check attributes a
tree corruption to the individual block transform, which is worth
keeping.

Assisted-by: Claude:claude-fable-5:Claude Code
The suite keeps 2x logical CPUs NUnit workers busy with allocation-heavy
decompiles (190 GB allocated per run), so under workstation GC every
gen0/gen1 collection any worker triggers suspends the whole process.
Measured on a 24-thread Windows box (Debug): 24,846 gen0 / 6,280 gen1
collections and 306 s of total GC pause in a 487 s run, at 44% average
CPU. With server GC the same run takes 268 s, 978 gen0 / 427 gen1, 12 s
of pause, 84% CPU; the in-suite whole-project decompiles drop 3-4x
(ExplicitConversions 353-366 s -> 102-125 s, NRefactory 312 s -> 86 s).
Standalone ilspycmd timings are unaffected, which is what pointed at
contention inside the test process rather than decompiler cost.

Assisted-by: Claude:claude-fable-5:Claude Code
@christophwille
christophwille force-pushed the decompiler-tests-parallelism branch from 9a981ab to 7ee67a6 Compare August 15, 2026 13:11
The Windows job runs every test host of the solution concurrently on a
4-core runner. Since ICSharpCode.Decompiler.Tests switched to server GC,
3 of 6 Windows jobs failed in ILSpy.Tests.Windows: the NetFramework
process-module walks that took seconds on master stalled for 5-15
minutes (long enough to outlive the fixture's PowerShell host and the
explorer's 60 s budget), and the decompiler suite itself finished no
faster than under workstation GC on that runner (Debug 21m33 vs 21m35,
Release 12m53 vs 13m31). Server GC stays on for machines the suite has
to itself; the Linux/macOS jobs run the projects one at a time.

Assisted-by: Claude:claude-fable-5:Claude Code
The PowerShell host used to sleep for a fixed 300 s, so any run in which
the process walks got slow (as happened on a starved CI runner) lost the
host mid-fixture and failed the remaining tests for the wrong reason.
Waiting on the test host's PID makes the fixture independent of wall
clock and also guarantees the host disappears with the test host even
if the teardown never runs.

Assisted-by: Claude:claude-fable-5:Claude Code
The scan reads the module list of every process on the machine, a few
hundred cross-process calls each, one process after the other. On the
4-core CI runner that walk takes 20-30 s while the decompiler suite is
running and, with the parallel suite keeping the box busier, exceeded
the 60 s budget of the process-explorer tests in ILSpy.Tests and
ILSpy.Tests.Windows. Inspecting the processes concurrently bounds the
walk by the slowest process instead of the sum, the same reason the
CoreCLR half already queries its runtimes concurrently.

Assisted-by: Claude:claude-fable-5:Claude Code
…ws CI tests

Diagnostic only, to be reverted: a background pwsh sampler logs free
memory, pagefile use, paging and disk-read latency counters, the largest
working sets, and its own timed per-process module walk (naming any
process that takes over a second) every 20 s while the test step runs.
The log is uploaded with the trx files.

Assisted-by: Claude:claude-fable-5:Claude Code
The sampler was a one-off to find out why process-module walks stall on
the Windows runner; it did its job. The answer was memory: ILSpy.Tests
grows to ~15 GB over its run and pages the box out, so every module
read hard-faults - a disk-bound problem that inspecting processes
concurrently could not and did not shorten. That leak is fixed
separately (#4012); the scan goes back to its original form.

Assisted-by: Claude:claude-fable-5:Claude Code
@christophwille

Copy link
Copy Markdown
Member Author

Status of the CI failures on this branch, and which commits were actually needed

The Windows job failures here (NetFrameworkProcessesTests in ILSpy.Tests.Windows, ProcessExplorerTests in ILSpy.Tests) turned out to be victims, not the fault: ILSpy.Tests retains ~13 MB per test and grows to ~15 GB over its run, which pages out the 16 GB runner, and the process-module walks those tests perform then hard-fault through every idle process (4 s idle vs. 100-400 s measured under load, 13-16 min when server GC added memory on top). That leak exists on master and is fixed in #4012; the Windows jobs of this branch will keep flaking until that lands (or is rebased in). Master's own Release job already spent 20-31 s in those tests, so the branch only tipped an existing edge.

With that established, the commits added while chasing this:

  • 7ee67a62b Use server GC - not part of the fix; on the 4-core runner it bought no suite time (Debug 21m33 -> 21m35, Release 12m53 -> 13m31) and its extra memory made the paging worse (0/6 Windows jobs failed before it, 3/6 with it). Its justification is the local 24-thread measurement only.
  • 4cccd1974 Workstation GC on the Windows CI test step - kept as a safety valve while the leak is unfixed. Once Stop ILSpy.Tests from retaining every test's app graph (15 GB -> 0.7 GB) #4012 is in, worth one CI run without it: with ILSpy.Tests at ~0.7 GB the box has room, and it may turn out unnecessary.
  • 2853a8b08 Fixture host waits on the test host PID - cheap hardening (no 300 s wall clock to outrun, no orphaned powershell.exe); optional.
  • b592b6164 Concurrent .NET Framework scan - unnecessary: the walk is disk-bound, so parallelising it did nothing (the next run still failed at 73 s). Reverted in 64b7b5b2a together with the temporary diagnostics sampler.

Two self-consistent minimal sets: keep server GC + 4cccd1974 (current state), or drop both. Either way #4012 is the fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant