Skip to content

Commit 4b29eda

Browse files
authored
Measure AfterAll and AfterEach as UserDuration (#2313)
1 parent d6516ef commit 4b29eda

File tree

3 files changed

+61
-6
lines changed

3 files changed

+61
-6
lines changed

src/Pester.Runtime.ps1

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1486,6 +1486,7 @@ function Invoke-ScriptBlock {
14861486
finally {
14871487
if ($null -ne $______parameters.Teardown -and $______parameters.Teardown.Length -gt 0) {
14881488
if ($______parameters.EnableWriteDebug) { &$______parameters.WriteDebug "Running inner teardowns" }
1489+
if ($______parameters.MoveBetweenScopes) { & $______parameters.SwitchTimerUserCode }
14891490
foreach ($______current in $______parameters.Teardown) {
14901491
try {
14911492
if ($______parameters.EnableWriteDebug) { &$______parameters.WriteDebug "Running inner teardown { $______current }" }
@@ -1516,6 +1517,7 @@ function Invoke-ScriptBlock {
15161517

15171518
if ($null -ne $______parameters.OuterTeardown -and $______parameters.OuterTeardown.Length -gt 0) {
15181519
if ($______parameters.EnableWriteDebug) { &$______parameters.WriteDebug "Running outer teardowns" }
1520+
if ($______parameters.MoveBetweenScopes) { & $______parameters.SwitchTimerUserCode }
15191521
foreach ($______current in $______parameters.OuterTeardown) {
15201522
try {
15211523
if ($______parameters.EnableWriteDebug) { &$______parameters.WriteDebug "Running outer teardown { $______current }" }
@@ -1556,6 +1558,13 @@ function Invoke-ScriptBlock {
15561558
}
15571559
}
15581560

1561+
$switchTimerUserCode = if ($MoveBetweenScopes) {
1562+
{
1563+
$state.UserCodeStopWatch.Start()
1564+
$state.FrameworkStopWatch.Stop()
1565+
}
1566+
}
1567+
15591568
#$break = $true
15601569
$err = $null
15611570
try {
@@ -1573,6 +1582,8 @@ function Invoke-ScriptBlock {
15731582
WriteDebug = $writeDebug
15741583
Configuration = $Configuration
15751584
NoNewScope = $NoNewScope
1585+
MoveBetweenScopes = $MoveBetweenScopes
1586+
SwitchTimerUserCode = $switchTimerUserCode
15761587
}
15771588

15781589
# here we are moving into the user scope if the provided

test.ps1

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -62,8 +62,8 @@ Get-Module Pester | Remove-Module
6262

6363
if (-not $SkipPTests) {
6464
$result = @(Get-ChildItem $PSScriptRoot/tst/*.ts.ps1 -Recurse |
65-
foreach {
66-
$r = & $_.FullName -PassThru -NoBuild:$NoBuild
65+
ForEach-Object {
66+
$r = & $_.FullName -PassThru -NoBuild:$true
6767
if ($r.Failed -gt 0) {
6868
[PSCustomObject]@{
6969
FullName = $_.FullName

tst/Pester.Runtime.ts.ps1

Lines changed: 48 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -2234,8 +2234,6 @@ i -PassThru:$PassThru {
22342234

22352235

22362236
t "total time is roughly the same as time measured externally (measured on a second test)" {
2237-
# this is the same as above, if I add one time setups then the framework time should grow
2238-
# but not the user code time
22392237
$container = @{
22402238
Test = $null
22412239
Block = $null
@@ -2298,8 +2296,6 @@ i -PassThru:$PassThru {
22982296
}
22992297

23002298
t "total time is roughly the same as time measured externally (on many tests)" {
2301-
# this is the same as above, if I add one time setups then the framework time should grow
2302-
# but not the user code time
23032299
$container = @{
23042300
Test = $null
23052301
Block = $null
@@ -2357,6 +2353,54 @@ i -PassThru:$PassThru {
23572353

23582354
# TODO: revisit the difference on many tests, it is still missing some parts of the common discovery processing I guess (replicates on 10k tests)
23592355
}
2356+
2357+
t "OneTimeTestSetup and OneTimeTestTeardown is measured as user code in block" {
2358+
$actual = Invoke-Test -SessionState $ExecutionContext.SessionState -BlockContainer (
2359+
New-BlockContainerObject -ScriptBlock {
2360+
New-Block -Name 'b1' {
2361+
New-OneTimeTestSetup {
2362+
Start-Sleep -Milliseconds 50
2363+
}
2364+
New-OneTimeTestTeardown {
2365+
Start-Sleep -Milliseconds 50
2366+
}
2367+
New-Test 't1' {
2368+
$true
2369+
}
2370+
}
2371+
}
2372+
)
2373+
2374+
$actual.UserDuration.TotalMilliseconds -ge 100 | Verify-True
2375+
$actual.Blocks[0].UserDuration.TotalMilliseconds -ge 100 | Verify-True
2376+
$actual.Blocks[0].OwnDuration.TotalMilliseconds -ge 100 | Verify-True
2377+
# test should not include time spent in block setup/teardown
2378+
$actual.Blocks[0].Tests[0].UserDuration.TotalMilliseconds -lt 100 | Verify-True
2379+
}
2380+
2381+
t "EachTestSetup and EachTestTeardown is measured as user code in test" {
2382+
$actual = Invoke-Test -SessionState $ExecutionContext.SessionState -BlockContainer (
2383+
New-BlockContainerObject -ScriptBlock {
2384+
New-Block -Name 'b1' {
2385+
New-EachTestSetup {
2386+
Start-Sleep -Milliseconds 50
2387+
}
2388+
New-EachTestTeardown {
2389+
Start-Sleep -Milliseconds 50
2390+
}
2391+
New-Test 't1' {
2392+
$true
2393+
}
2394+
}
2395+
}
2396+
)
2397+
2398+
$actual.UserDuration.TotalMilliseconds -ge 100 | Verify-True
2399+
$actual.Blocks[0].UserDuration.TotalMilliseconds -ge 100 | Verify-True
2400+
# block is not responsible for setup/teardown per test.
2401+
$actual.Blocks[0].OwnDuration.TotalMilliseconds -lt 100 | Verify-True
2402+
$actual.Blocks[0].Tests[0].UserDuration.TotalMilliseconds -ge 100 | Verify-True
2403+
}
23602404
}
23612405

23622406
b "Setup and Teardown on root block" {

0 commit comments

Comments
 (0)