2.0.1
Big rename
Duration is SelfDuration, and Duration has new meaning
In 1.0.0 Duration shown the amount of time a command took by itself but did not count the time it took to execute all the code it called. This is now called SelfDuration
, and Duration
is now how long the command took to return. To show that on example:
function a () {
# sleep for 1 second
Start-Sleep 1
}
a
Function a
takes 1 second to return from (Duration), but by itself takes <1ms (SelfDuration). Internally it calls Start-Sleep
which also has Duration of 1 second because it takes 1 second to return from it. It calls into .NET which Profiler does not see, so the SelfDuration is also 1 second.
When improving performance Duration shows you which bigger parts of your code are slow, and SelfDuration which exact commands are slow. E.g. function Get-User is slow, because it internally calls 200 other commands which are each quite fast by themselves, but the time adds up because there are 200 of them.
Feature is now called Flag
-Feature is now called -Flag. Seems like a more to the point name.
See what is slow in the in a command
There is now ReturnIndex on every command, you can use that to see what happened during the command execution. See demo3 for full example:
# oooh call to function 'c' is slow
$slowLine = $trace.Top50 | Where-Object text -eq 'c'
$slowLine | Format-Table
# it was called just once (hit), and by itself (SelfDuration) takes < 1ms, but the code it calls
# takes over 200 ms (Duration), let's see what happens in the meantime
$hit = $slowLine.Hits[0]
$trace.Events[$hit.Index..$hit.ReturnIndex] | Format-Table
# and if that is too many calls, let's see the top 50 from that that themselves take the most
$trace.Events[$hit.Index..$hit.ReturnIndex] |
Sort-Object -Descending SelfDuration |
Select-Object -First 50 |
Format-Table