Skip to content

Fail when the timing assertions get something they cannot measure - #3032

Merged
nohwnd merged 1 commit into
mainfrom
fix-timing-assertions-silent-pass
Sep 5, 2026
Merged

Fail when the timing assertions get something they cannot measure#3032
nohwnd merged 1 commit into
mainfrom
fix-timing-assertions-silent-pass

Conversation

@nohwnd

@nohwnd nohwnd commented Sep 5, 2026

Copy link
Copy Markdown
Member

Should-BeFasterThan and Should-BeSlowerThan handle [scriptblock] and [timespan], and both branches return. Anything else fell out of the bottom of the function, so the assertion returned having asserted nothing and the test passed:

Actual = [String]     -> SILENTLY PASSED
Actual = [Int32]      -> SILENTLY PASSED
Actual = [null]       -> SILENTLY PASSED
Actual = [Object[]]   -> SILENTLY PASSED

Now:

[String] -> Expected a [scriptblock] to measure or a [timespan] to compare, but got [string] 'a string'.
[Int32]  -> Expected a [scriptblock] to measure or a [timespan] to compare, but got [int] 42.
[null]   -> Expected a [scriptblock] to measure or a [timespan] to compare, but got [null] $null.

Why now

This is what has been making Should-BeFasterThan.Throws when scriptblock is slower than expected flake on Windows PS7. From the run on #3023:

[-] Should-BeFasterThan.Throws when scriptblock is slower than expected 3ms
Exception: Expected the script block {  $Actual | Should-BeFasterThan -Expected $Expected  }
           to fail in Pester assertion, but no assertion failure error was thrown!

The test's scriptblock is { Start-Sleep -Milliseconds 10 } and the whole test took 3ms. That is wall clock on the It, not a Stopwatch reading, so no clock or timer-resolution problem can explain it. The sleep never ran. & $Actual was never reached, which means $assert.Actual() returned something that is neither a scriptblock nor a timespan, and the function fell through the bottom and returned silently.

So it was never a timing flake. It looked like one because a scriptblock that is never run is indistinguishable from a scriptblock that ran impossibly fast, when nothing reports the difference.

This does not fix the underlying cause, we still do not know why Actual() returns the wrong thing there, and only on Windows PS7. It makes the next occurrence say what it actually got instead of looking like a stopwatch wobble, and it closes the silent-pass hole either way, which is worth doing on its own.

For the record, ruled out locally on macOS: Start-Sleep -Milliseconds 10 never under-ran in 3000 measurements (min 10.07ms), and the assertion did not flake once in 2000 iterations.

Verification

Should-BeFasterThan.Tests.ps1 20/20 and Should-BeSlowerThan.Tests.ps1 9/9, with a data-driven test on each covering a string, a number and $null. The scriptblock and timespan paths are unchanged.

🤖

Should-BeFasterThan and Should-BeSlowerThan handled [scriptblock] and [timespan],
and both branches return. Anything else fell out of the bottom of the function, so
the assertion returned having asserted nothing and the test passed. A string, a
number, $null and an array all passed silently.

That also made a CI flake unreadable. On Windows PS7 the test asserting that a 10ms
sleep is slower than 1ms failed with "no assertion failure error was thrown", and
the whole test took 3ms. The scriptblock was never run, which is why there was no
sleep and no failure, but nothing said so, and it looked like a scriptblock that ran
impossibly fast. The next time it happens the message names the type and value we
were actually handed.

🤖
@nohwnd
nohwnd enabled auto-merge (squash) September 5, 2026 09:12
@nohwnd
nohwnd merged commit 69dcffe into main Sep 5, 2026
12 checks passed
@nohwnd
nohwnd deleted the fix-timing-assertions-silent-pass branch September 5, 2026 09:19
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant