Add self percent
nohwnd opened this issue · 8 comments
I find myself looking at percent mainly to get a validation that the profiling finishes fine (when seeing 99.99 percent or thereabouts).
But would find is useful to have SelfPercent which would show how useful reducing the given line would be. e.g. this single line is 10% of the whole duration. SelfPercents should add to 100% obviusly.
Wouldn't that already be shown as ex. a 10.00 Percent line further down in the top 50?
the percent would be correct only if the command would have the same selfduration as duration. I will play around a bit more and see if I really need it. But first tests and xplat support.
the percent would be correct only if the command would have the same selfduration as duration.
By using Top50SelfDuration, you'd put those events at the top which basically makes the Percent-value of those lines "SelfPercent" - at least for the first standout lines which is probably the ones you care about.
PS /workspaces/Profiler> $trace.StopwatchDuration.TotalSeconds
12.0144386
PS /workspaces/Profiler> $trace.Top50SelfDuration | ft
Percent HitCount Duration Average SelfDuration SelfAverage Name Line Text
------- -------- -------- ------- ------------ ----------- ---- ---- ----
49.953 3 00:00:06.0012573 00:00:02.0004191 00:00:06.0012573 00:00:02.0004191 t.ps1 5 Start-Sleep 2
24.981 3 00:00:03.0011301 00:00:01.0003767 00:00:03.0011301 00:00:01.0003767 t.ps1 4 Start-Sleep 1
24.975 1 00:00:03.0004253 00:00:03.0004253 00:00:03.0004253 00:00:03.0004253 t.ps1 12 Start-Sleep -Seconds 3
100 3 00:00:12.0137053 00:00:04.0045684 00:00:00.0088057 00:00:00.0029352 scriptblock 1 & ./demo-scripts/t.ps1
74.947 3 00:00:09.0038643 00:00:03.0012881 00:00:00.0007326 00:00:00.0002442 t.ps1 10 & $sb1
74.939 3 00:00:09.0029713 00:00:03.0009904 00:00:00.0004278 00:00:00.0001426 t.ps1 7 . $sb2
74.951 4 00:00:09.0044382 00:00:02.2511096 00:00:00.0003648 00:00:00.0000912 t.ps1 9 1..3 | % { …
0.002 3 00:00:00.0002091 00:00:00.0000697 00:00:00.0002091 00:00:00.0000697 t.ps1 11 }
0.001 3 00:00:00.0001133 00:00:00.0000378 00:00:00.0001133 00:00:00.0000378 t.ps1 6 }
0.001 6 00:00:00.0000836 00:00:00.0000139 00:00:00.0000836 00:00:00.0000139 t.ps1 2 $sb2 = {…
0.001 3 00:00:00.0000713 00:00:00.0000238 00:00:00.0000713 00:00:00.0000238 t.ps1 8 }
0 4 00:00:00.0000585 00:00:00.0000146 00:00:00.0000585 00:00:00.0000146 t.ps1 1 $sb1 = {…
0 3 00:00:00.0000259 00:00:00.0000086 00:00:00.0000259 00:00:00.0000086 t.ps1 3 $test = "hello"
Still, I guess it wouldn't hurt to have a SelfPercent between Average and SelfDuration to make it very clear for all events. It does start to use quite a bit of space though. Might have to format the time output to
Yeah it is wide. I am reluctant to format the times, because that needs a base unit, but most use cases will be dealing with seconds to minute ranges I think. We can also search the list to get the longest item and use that as base unit. But it still should clearly tell the user what the time unit is.
Yeah it is wide.
One option could be to create different views. Unfortunately auto-selecting view is not possible without creating custom classes for each "Top50"-array etc.
PS /workspaces/Profiler> $t.AllLines
Percent HitCount Duration Average SelfDuration SelfAverage Name Line Text
------- -------- -------- ------- ------------ ----------- ---- ---- ----
100.000 % 3 00:00:00.0152117 00:00:00.0050706 00:00:00.0083692 00:00:00.0027897 719f57af-e27a-482f-b8c0-06af95645c9b 1 & ./demo-scripts/ThrowingScript.ps1
44.982 % 1 00:00:00.0068425 00:00:00.0068425 00:00:00.0002777 00:00:00.0002777 ThrowingScript.ps1 15 c
43.119 % 1 00:00:00.0065592 00:00:00.0065592 00:00:00.0001680 00:00:00.0001680 ThrowingScript.ps1 11 b
0.037 % 1 00:00:00.0000056 00:00:00.0000056 00:00:00.0000056 00:00:00.0000056 ThrowingScript.ps1 10 {
41.468 % 1 00:00:00.0063080 00:00:00.0063080 00:00:00.0002103 00:00:00.0002103 ThrowingScript.ps1 7 a
0.032 % 1 00:00:00.0000048 00:00:00.0000048 00:00:00.0000048 00:00:00.0000048 ThrowingScript.ps1 6 {
39.956 % 1 00:00:00.0060780 00:00:00.0060780 00:00:00.0060780 00:00:00.0060780 ThrowingScript.ps1 3 throw "aaa"
0.130 % 1 00:00:00.0000197 00:00:00.0000197 00:00:00.0000197 00:00:00.0000197 ThrowingScript.ps1 2 {
0.515 % 1 00:00:00.0000784 00:00:00.0000784 00:00:00.0000784 00:00:00.0000784 ThrowingScript.ps1 18 "failed"
PS /workspaces/Profiler> $t.AllLines | Format-Table -View SelfTimings
Percent HitCount SelfPercent SelfDuration SelfAverage Name Line Text
------- -------- ----------- ------------ ----------- ---- ---- ----
100.000 % 3 0.123 % 00:00:00.0083692 00:00:00.0027897 719f57af-e27a-482f-b8c0-06af95645c9b 1 & ./demo-scripts/ThrowingScript.ps1
44.982 % 1 0.123 % 00:00:00.0002777 00:00:00.0002777 ThrowingScript.ps1 15 c
43.119 % 1 0.123 % 00:00:00.0001680 00:00:00.0001680 ThrowingScript.ps1 11 b
0.037 % 1 0.123 % 00:00:00.0000056 00:00:00.0000056 ThrowingScript.ps1 10 {
41.468 % 1 0.123 % 00:00:00.0002103 00:00:00.0002103 ThrowingScript.ps1 7 a
0.032 % 1 0.123 % 00:00:00.0000048 00:00:00.0000048 ThrowingScript.ps1 6 {
39.956 % 1 0.123 % 00:00:00.0060780 00:00:00.0060780 ThrowingScript.ps1 3 throw "aaa"
0.130 % 1 0.123 % 00:00:00.0000197 00:00:00.0000197 ThrowingScript.ps1 2 {
0.515 % 1 0.123 % 00:00:00.0000784 00:00:00.0000784 ThrowingScript.ps1 18 "failed"
PS /workspaces/Profiler> $t.AllLines | Format-Table -View nonexisting
Format-Table: The view name nonexisting cannot be found. Specify one of the following Table views and try again: Default, SelfTimings.
I think we can drop the Average columns. Have you ever used them? I did at the start, but nowadays I never do.
Yup.