Join GitHub today
GitHub is home to over 50 million developers working together to host and review code, manage projects, and build software together.
Sign upPowerShell profiler #13673
PowerShell profiler #13673
Conversation
|
Looks good. I am not able to build it on Windows. Cleaned up and ran bootstrap script, but I still see |
|
@lzybkr I added a scriptblock rundown event per #13589 (comment)
Also I found how use ConditionalWeakTable. With it I get strange scriptblocks without sequence points. @nohwnd It is very strange. It seems your local fork is broken. At least you could do |
|
This looks pretty good, I especially like relying on the rundown event internally which means it should work well out of process as well. |
| [NonEvent] | ||
| internal void WriteRundownEvents() | ||
| { | ||
| foreach (var pair in CompiledScriptBlockData.GetCompiledScriptBlockTable()) |
lzybkr
Sep 23, 2020
Member
This isn't ideal as it may write out much more than necessary, but it may also miss some script blocks that are hit while profiling.
The ConditionalWeakTable does not prevent garbage collection, so if, e.g. we cleared the script block cache while profiling, scripts that had exited while profiling would be missing the rundown data.
iSazonov
Sep 24, 2020
Author
Collaborator
- Yes, it is not ideal. For the simple test I shared I see a size of the table is 86. In big application (Pester) it could be 500 or 1000 - it does not look so critical bad.
- I tried ConcurrentDictionary instead of ConditionalWeakTable. You can revert last commit and see the case. My idea was to register scriptblock in Compile() method so that we was independent from scriptblock cache. It is more predictable but we need to clean the buffer somehow.
- for ConcurrentDictionary case I cleaned up the buffer at EventSource disable time. It is not ideal too. It duplicates the scriptblock cache.
- for ConditionalWeakTable we could temporary stop to clean up the scriptblock cache until we disable EventSource.
lzybkr
Sep 24, 2020
Member
The profiler could take a snapshot of the script block cache when starting. This snapshot would hold references so it wouldn't matter if the script block cache was cleared.
Then, script block creation would also add to that snapshot.
This way, the memory is owned by the profiler and can be cleared when profiling is disabled allowing garbage collection to do it's thing.
iSazonov
Sep 25, 2020
Author
Collaborator
The snapshot does not help in a scenario with long live scriptblocks. Such scriptblocks could be tracked with ConditionalWeakTable. We could avoid ConditionalWeakTable if there is a way to identify running scripts.
lzybkr
Sep 25, 2020
Member
I think you could gather by breaking every runspace (I think the debugger can do this) and walking the stack of each runspace.
But I think it would be simpler to just take a snapshot of the scriptblock cache. IIRC, the only scriptblock that doesn't end up in the cache comes from the command line.
Regardless, ConditionalWeakTable is likely not what you want because you don't control keeping the data you need alive.
iSazonov
Sep 28, 2020
Author
Collaborator
Now I replace ConditionalWeakTable with ConcurrentDictionary, add an initialization from scriptblock cache, simplify the scriptblock cache ( we cached ScriptBlock but never use it directly - clone before use but Clone() method actually
copies a reference to CompiledScriptBlock so we can cache directly CompiledScriptBlock)ю
IISResetMe
Sep 28, 2020
Contributor
@lzybkr Do you have any ideas for how to track the "origin" or "root dispatcher" for the individual script blocks as described above? It would make it so much easier to consume the events in any tool/context.
iSazonov
Sep 29, 2020
•
Author
Collaborator
I added Runspace and parent scriptblock Ids in perf event. I am still not sure it works as expected - need a review.
Also I added a typed output and set Start Opcode on perf event - need to find how to issue Stop event.
Duration is now broken in common - we need to take into account Runspaces.
iSazonov
Sep 30, 2020
Author
Collaborator
I pulled some commits and it's ready for further discussion. The PR description has also been updated.
| var compiledScriptBlock = pair.Key; | ||
| ScriptBlockRundown(compiledScriptBlock.Id, compiledScriptBlock.Ast.Body.Extent.Text); | ||
|
|
||
| if (compiledScriptBlock.SequencePoints is null) |
lzybkr
Sep 23, 2020
Member
Based on my comment and the code it guards, I think the point was to avoid needing tests like this elsewhere.
iSazonov
Sep 24, 2020
Author
Collaborator
But I catch NRE here :-( Should we consider this as separate bug and open a tracking issue?
lzybkr
Sep 24, 2020
Member
I suppose it's not exactly a bug if it's not causing other issues now - so your call.
| { | ||
| var extent = compiledScriptBlockData.SequencePoints[profileDate.SequencePointPosition]; | ||
|
|
||
| PSObject result = new PSObject(); |
lzybkr
Sep 23, 2020
Member
This should be a real object as I'd expect we'll construct a ton of them.
iSazonov
Sep 25, 2020
Author
Collaborator
My thoughts about Measure-Script cmdlet is we could have some cases:
- with
-OutFileparameter write real objects to standard file like ewtx - with
-Rawswitch write real objects to the pipeline - by default write specific psobjects so that users can investigate simple scripts and to get nice formatted output on console (like @IISResetMe demo below #13673 (comment))
lzybkr
Sep 25, 2020
Member
You should always prefer a real object if you know the properties you'll need, especially if you might be writing out thousands of said objects.
|
@IISResetMe (who adapted my SDK sample into the module PSProfiler) might also want to take a look. |
|
What kind of support in PerfView are you looking for? |
|
The output format is slightly awkward, but beyond that I could definitely work with this:
Will take a closer look at the code tomorrow |
|
@brianrob - I think PowerShell maintainers and some module authors would appreciate hybrid PowerShell/C# call stacks from CPU sampling. This PR is generating minimal events (analogous to an IP but no stack) while profiling via an EventSource (using instrumentation in the generated code which is interpreted and lazily jit compiled). After turning off profiling, a rundown event provider is generating metadata to recover the source line and function details from the minimal events. @iSazonov may have other ideas how PowerShell users might use perfview or wpa. |
My thoughts is very simple. Since users will can able to collect PowerShell performance events out-of-process they need tools to analyze the data.
@lzybkr Could you please point me where we could issue a stop event for scriptblock/sequence point? @brianrob What do you think? Is it possible? Could you tell me how we should create events correctly for PerfView? |
|
Tried running this over a Pester test and it failed. Here is a mini repro: _scriptBlock is null when you hit the
|
|
@nohwnd for reference your original error was because the resource strings needed to be rebuilt. |
|
I just skimmed the PR to try and understand how things work. I would like to make sure I understand how things work, and then have a few questions. My understanding is that there is a desire to enable profiling in two ways:
There are a couple of pieces of functionality that I can see being implemented in PerfView. Of course, I'm open to feedback and other ideas as well:
For the computing resource based views, we'd need to understand a couple of things:
Right now, PerfView has functionality that does this for jitted code that is compiled on-the-fly by the .NET runtime. This is done by using rundown events to provide function memory ranges and symbols. There's mention of both interpreted and jitted code here. For interpreted code, we'd need events that would allow us to build the appropriate stack. You could imagine doing this with start/stop events that wrap the "scope" of each frame. This would work as long as collection started before the invocation. If it is started in the middle of an invocation, we'd see broken stacks, but these may still be valuable depending on how much movement up and down the stack there is. For jitted code, are we talking about using the .NET runtime's JIT, or something else? |
Yes.
Yes for 1. Currently we issue an event with number 1 as start event but without the "start" label. For 2. I am not sure we can utilize resource tracking because scripts are executed in runspaces (you can think that it is special thread) and there could be some parallel runspaces so we cannot directly know which runspace is consuming resources- we should track a long correlation sequence scriptblock-runspace-.Net thread. It looks too complex for me. Although it is possible... It is my answer on "For jitted code, are we talking about using the .NET runtime's JIT, or something else?" too - it would interesting to have the correlated views (script - JIT) but looks too complex for the first step PR. |
NRE is in "ProfilerEventSource.LogInstance.SequencePoint(_scriptBlock.Id, pos);" (in UpdatePositionNoBreak()) because "_scriptBlock" is null. I wonder why... It seems a "bug" mentioned above. |
|
@brianrob PowerShell does use the .NET jit via LINQ expression trees. PowerShell forked the DLR to use the interpreter which will jit compile code if it executes enough times. |
We catch NRE on "@()". It is parameter binding. This is evaluated out of current scripblock. There is created pseudo functioncontext with sequence points but without a reference to current scriptblock.
Since these code paths is complex, with static methods without scriptblock parameter it is a huge work to fix all them. |
|
I just tried it out with some real scripts and my module that summarizes the results and it works nicely. I am preparing a presentation about this for PWSH24. Is it reasonable to expect that this will be available in a month or two? (even if behind an experimental flag) |
|
@nohwnd Thanks! Do you ask about 7.1 or 7.2? I am sure we will get this in 7.2 Preview1 as experimental. |
|
7.2 is okay. I just wanted to know when roughly this will be ready to try, because I have only a version that works with PowerShell 5, by doing some "reflection" magic, but nothing for the PowerShell core versions. |
|
@nohwnd .Net 5.0 will be released in November. PowerShell 7.1 will be released in the time too. Then the holidays come. I'd expect 7.2 Preview1 in January unless MSFT team forked earlier. |
|
This pull request has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 15 days. It will be closed if no further activity occurs within 10 days of this comment. |

Formed in 2009, the Archive Team (not to be confused with the archive.org Archive-It Team) is a rogue archivist collective dedicated to saving copies of rapidly dying or deleted websites for the sake of history and digital heritage. The group is 100% composed of volunteers and interested parties, and has expanded into a large amount of related projects for saving online and digital history.

PR Summary
Simple demo:
PR Context
Based on Jason's approach lzybkr@d620bb4
Perf event (with minimal data) issues for every sequence point while measure runs
Perf events are implemented in ProfilerEventSource class
Perf event contains
Now perf events are issued for default parameter evaluations (and more).
Limitations:
Rundown event (with full meta data) issues for every sequence point after measure stops
Rundown event issues for every script block (not used in Measure-Script now)
Rundown event issues are implemented in ProfilerRundownEventSource class
Scriptblock cache was simplifed and now it caches
CompiledScriptBlock-snew ScriptBlock(CompiledScriptBlock)new ScriptBlock(CompiledScriptBlock)without extra cloning.To collect meta data we use
ConcurrentDictionaryCompiledScriptBlock.s_cachedScriptscacheTo initialize the cache at measure start we use CompiledScriptBlock cache and then register every script block at creation time.
This allow us to have meta data for every script block.
Exception (an edge case) - long running script blocks already removed from CompiledScriptBlock cache.
Measure-Script cmdlet is implemented for demo use
ProfileEventRecord is used for typed output
Duration is broken in common
For discussion
Since we have only start timestamps we haven't stop timestamp for last sequence point. Perhaps we need a script block stop event and maybe start event.
Here a question is should we think about measuring pipelines, parameter bindings.
Also can we be compatible with PerfView tool?
PR Checklist
.h,.cpp,.cs,.ps1and.psm1files have the correct copyright headerWIP:or[ WIP ]to the beginning of the title (theWIPbot will keep its status check atPendingwhile the prefix is present) and remove the prefix when the PR is ready.