A method based on Ast visitors is more accurate, power and reliable. And more slow of cause. We could add some enhancements in PowerShell Engine to make it more faster - Why do we need to set breakpoints on every line? I hope we could avoid this.
A kind of sampling is alternative method that is proposed in the PR. I am not sure that it is so useful for Pester as first method. As for implementation it is more "powershelly" to enhance Trace-Command cmdlet to support files.

@iSazonov When you talk about AST being more accurate, powerful and reliable what are you comparing it to? The approach proposed in this PR gives us a way better baseline, and is able to profile any script without having to resort to AST. This is a huge limitation of PSProfiler / Measure-Script, you can analyze only a single scriptblock, and any referenced scripts are not instrumented. And you have to have an AST Visitor that understands every branch of your code and instruments it. This PR shows a way to do this without any of that.

As for Code Coverage, I am sure it will help Pester a lot. Some additional analysis will need to be done on the returned data to identify lines that can't be hit (e.g. empty line, return, else etc.), but that is pretty easy, we already have AST analyzer that does that, and imho we could write a simple regex that gets us 95% there. Or do you see some obvious gap that I am missing?

All in all, I am really excited about this change, and would love to get it in one form or another. 🙂

When you talk about AST being more accurate, powerful and reliable what are you comparing it to?

I was not too accurate - both options (AST visitors and sampling) have pros and cons.

I believe we don't want to add an profiler implementation in PowerShell Engine but we could enhance PowerShell Engine so that simplify third-party profiler implementations.

If PowerShell Debugger class is only source we can get an needed information from my suggestion is:

• add Hit struct (with better name, maybe PSTraceLineEvent)
• inject PSTraceSource in Debugger (can we use GetTracer() ?)
• with PSTraceSource write raw Hit structs to trace listeners
• enhance Trace-Command to turn on/off the feature
• third-party Profiler (and maybe PowerShell Editor Service) can read from a file or a socket the Hit structs, collect and process its.

Sounds good, except for the last point:

third-party Profiler (and maybe PowerShell Editor Service) can read from a file or a socket the Hit structs, collect and process its.

Could this be all done directly by just providing a callback of some sort, e.g. Action<PSTraceLineEvent>? Writing and reading the file with results, or communicating over sockets seems like unnecessary overhead.

Could this be all done directly by just providing a callback of some sort, e.g. Action? Writing and reading the file with results, or communicating over sockets seems like unnecessary overhead.

I have big doubts that the callback is applicable here. A common practice is to release events so that an external tool can collect and analyze them.
I guess you mean that the callback simplify a profile creation. This has negative effects on the engine.
Also, the callback will create an unpredictable delay, which just goes against the idea of ​​the profiler.

Added @PaulHigin for debugger expertise and @daxian-dbw for performance insights.

This seems like a really valuable addition. The questions in my mind are:

• What's the appropriate mechanism for this? The trace calls seem like a good one, but I don't know enough about the debugger to say whether they are the "right" one. Do they correspond to sequence points in a script?
• What shape should the APIs take, where should they be accessible from and in what states? Should they require privileges? What about optimisations/pessimisations due to debugging?
  • One thought that strikes me just based on the current prototype is that rather than being static, the API should probably be per-runspace or per-debugger
  • Is coupling this to the debugger an implementation detail or does it make sense to the end user?

One thought that strikes me just based on the current prototype is that rather than being static, the API should probably be per-runspace or per-debugger

Debugger class is created per ExecutionContext.

Is coupling this to the debugger an implementation detail or does it make sense to the end user?

Debugger class is already injected in execution process and if we could use this class it would greatly simplify the implementation.
Users will only see new parameter in Trace-Command like Trace-Command -TraceFile @(file1, file2, file3).

@PaulHigin @daxian-dbw Tagging you here one more time, in case you see some fundamental problems with this proposal. Thanks!

One more thought.

I have big doubts that the callback is applicable here. A common practice is to release events so that an external tool can collect and analyze them.

This is always a classic tradeoff. Do we allow arbitrary callbacks so we can reuse this later but which could become a doorway for all kinds of issues, or do we specialise the API? Or do we make the callbacks into asynchronous events?

For a trace API, I don't think it needs to be synchronous (i.e. it can simply emit events with timestamps to subscriber threads). In turn that makes the API a bit more cohesive; it's not for arbitrary callbacks, but for trace events saying when and where code was hit. The only problem with not being synchronous is that a subscriber needs a way to know that a session has ended.

Another possible problem with it being async is that there are well known complications that can tend to happen for any PS-focused tooling that might want to make use of such an API. That could perhaps be alleviated by packing it into an in-box cmdlet, though.

For a trace API, I don't think it needs to be synchronous

We use standard trace API and it already injected in all PowerShell code base. Writing one more event will not worsen anything. (If this is really a problem then we will have to rewrite all the tracing code which looks unnecessary.)

I tried implementing it via the TraceSource, and it is pretty annoying.

• I am tracing in OnSequencePointHit and I need to enable debugging for Trace-Command to trace anything in my source.
• Using the file listener I get terrible performance. For run of all pester tests the resulting log is 65MB and reading that takes couple of seconds. This is mainly because I can't filter the internal Pester calls, and exposing api to provide only the files to be traced does not fit well with the Trace-Command existing api.
• It would be nice to have inMemoryListener but I would have to implement it.
• All of this would give me a relatively simple way of collecting the trace in memory.

But here is another proposal, that does the same thing without most of the loose ends:

• Add TraceVariable parameter to Set-PSDebug, this will be variable to be used as output of the trace collection.
• If the variable does not exist we will create it on Set-PSDebug -Trace 1 -TraceVariable "trace".
• If the variable exist and has value of IList, use it.
• otherwise check the type of the value and throw.

This has great performance, the data are immediately available. And it requires minimal changes. The Api is also pretty natural to use, and don't require you to implement any c# code if you want to consume it (unlike using an event, where the handler could not be powershell action, because that would cause stack overflow):

Set-PSDebug -Trace 1 -TraceVariable "trace"
<Run your code> 
Set-PSDebug -Off

<Fiddle with the $trace as you like. >

I played with it a bit and if the line struct looks like this, it seems to consume little memory, and have no noticable perf impact on the execution. I've run some Pester tests 10 times in a row and they still run for the same amount of time, and ran fast:

    public struct PSTraceLine
    {
        public IScriptExtent Extent { get; set; }

        public long Timestamp { get; set; }
    }

Additionally, by being able to provide the IList instance ourselves, we can implement minimal filtering directly in the collection if we wish.

What do you think?

Code for that is here master...nohwnd:pwsh-profiler-take2

I tried implementing it via the TraceSource, and it is pretty annoying.

• I am tracing in OnSequencePointHit and I need to enable debugging for Trace-Command to trace anything in my source.

Why is it worse than Set-PSDebug -Trace 1 / Set-PSDebug -Off.

Also, for better UX we could implement Enable-Profiler/Disable-Profiler/Set-Profiler.

• Using the file listener I get terrible performance. For run of all pester tests the resulting log is 65MB and reading that takes couple of seconds. This is mainly because I can't filter the internal Pester calls, and exposing api to provide only the files to be traced does not fit well with the Trace-Command existing api.
• It would be nice to have inMemoryListener but I would have to implement it.

It is easy to implement such inMemoryListener. Also alternative scenarios could prefer a file output. The output should be binary (like EWT does) for performance. (If we converted timestamps to strings or Datetime we would lost performance over 100x or more.)
As for filtering, I'd expect Pester enable the profiler before a file run and disable after the file finished.

• All of this would give me a relatively simple way of collecting the trace in memory.

But here is another proposal, that does the same thing without most of the loose ends:

• Add TraceVariable parameter to Set-PSDebug, this will be variable to be used as output of the trace collection.

As I already said it is not right place for the profile feature. It is better to use *-Trace cmdlets or create new *-Profile cmdlets.

• If the variable does not exist we will create it on Set-PSDebug -Trace 1 -TraceVariable "trace".
• If the variable exist and has value of IList, use it.
• otherwise check the type of the value and throw.

If we want to have a profiler feature in Engine it must works for both scripts and binaries too. I'd expect users will want to implement alternative profilers (in different IDEs).

This has great performance, the data are immediately available. And it requires minimal changes. The Api is also pretty natural to use, and don't require you to implement any c# code if you want to consume it (unlike using an event, where the handler could not be powershell action, because that would cause stack overflow):

Set-PSDebug -Trace 1 -TraceVariable "trace"
<Run your code> 
Set-PSDebug -Off

<Fiddle with the $trace as you like. >

I played with it a bit and if the line struct looks like this, it seems to consume little memory, and have no noticable perf impact on the execution. I've run some Pester tests 10 times in a row and they still run for the same amount of time, and ran fast:

    public struct PSTraceLine
    {
        public IScriptExtent Extent { get; set; }

        public long Timestamp { get; set; }
    }

It is right to have Timestamp as binary but we still lost performance on coping Extent. We could issue events for file start and file end, between them events could contain Timestamp and Line number as binaries.

Additionally, by being able to provide the IList instance ourselves, we can implement minimal filtering directly in the collection if we wish.

What do you think?

I dunno. I mean, I get that we do already have tracing cmdlets, but they trace events moreso than just lines of a script. I'm of the opinion that since the debugger is build from the beginning to be more cognizant of how a script is structured moreso than the engine is structured, it's a better place to put things here.

As I already said it is not right place for the profile feature. It is better to use *-Trace cmdlets or create new *-Profile cmdlets.

I don't get this. The cmdlet already has -Trace parameter, it combines Debugging with Trace, which is exactly what I do. I just write to a collection instead of writing it to debug stream. I don't do any profiling in the code, I just write a Trace.

Profiling would be additional functionality provided by external module that would consume the data. This would be just a very simple way to get the data. They are not very useful by themselves, but it allows me to keep the change to PowerShell minimal.

Why is it worse than Set-PSDebug -Trace 1 / Set-PSDebug -Off.

Also, for better UX we could implement Enable-Profiler/Disable-Profiler/Set-Profiler.

Trace-Command does not enable debugging by default. I have to enable tracing of my trace event, and then somehow enable debugging, but not by Set-PSDEbug -trace 1, because that writes to Debug stream. And then I need to run the code.

It is easy to implement such inMemoryListener. Also alternative scenarios could prefer a file output. The output should be binary (like EWT does) for performance. (If we converted timestamps to strings or Datetime we would lost performance over 100x or more.)

Yes, maybe, but why bother with adding another trace listener? We would also need to make it work for all the possible traces, because the current api of Trace-Command is not suited well for using different tracers with different sources of events.

As for filtering, I'd expect Pester enable the profiler before a file run and disable after the file finished.

Yes but it would enable it before running the tests file, because we don't control how users import their dependencies. So we need a way to tell the profiler which files we are interested in, otherwise it captures everything from everywhere. Putting a lot of noise in the trace, and storing unnecessary data.

If we want to have a profiler feature in Engine it must works for both scripts and binaries too. I'd expect users will want to implement alternative profilers (in different IDEs).

By binaries you mean binary modules? That would require a totally different approach and I and the current tracing that writes to Debug does not do that either. Profiling your own "C#" code is not hard, you have VS and all the awesome tooling at your disposal. I don't see why we should complicated it with this.

I also don't understand how implementing different profilers depends on being able to trace binary code. And I doubt there will be more that a handful of profilers, there is only so much you can do with the trace.

It is right to have Timestamp as binary but we still lost performance on coping Extent. We could issue events for file start and file end, between them events could contain Timestamp and Line number as binaries.

Is it not just copying the struct that has a reference to IScriptExtent that already exists? I don't see any impact on the execution time, and it also is running in debug mode, so we expect some perf degradation to be there.

Having an event for start and end of file is further complicating the problem.

Yes, maybe, but why bother with adding another trace listener? We would also need to make it work for all the possible traces, because the current api of Trace-Command is not suited well for using different tracers with different sources of events.

It is huge work to refactor all trace code. But it is not block additions which we can implement in right way.

By binaries you mean binary modules?

No, I mean hosting applications. I think about a profiler in VS Code/PES.

You are trying to find minimal and fastest solution for Pester (and maybe script scenarios (calling Profiler from script)) but I am sure that PowerShell engine must expose more power API so that users can profile scripts from scripts but also create other kinds of profilers and analyzers.

It is huge work to refactor all trace code. But it is not block additions which we can implement in right way.

Why are you forcing me to implement this in the most complicated way then? Trace-Command does not enable debugging, and I need debugging. Trace-Command does not have in memory trace and I need in memory tracer.

On the other hand Set-PSDebug enables debugging, and already has -Trace parameter, I just want a way to write the data to a different stream that I can consume, not just to Debug.

You are trying to find minimal and fastest solution for Pester (and maybe script scenarios (calling Profiler from script)) but I am sure that PowerShell engine must expose more power API so that users can profile scripts from scripts but also create other kinds of profilers and analyzers.

You are mostly right, I am trying to find a minimal solution so I can finally profile my scripts, without jumping through so many hoops. All I ask for is being able to write the trace in a way that I can consume it, instead of being written into Debug stream. That is it. You are trying to make this into an effort to allow profilers to be written in any IDE, but do you have any asks for it?

If someone wants to integrate this into VSCode they can call the same cmdlets as I do, or they can download the module that we will write around this, and use it. Or replicate that code in their language of choice. Look at Pester, it is also an external module and it integrates with VSCode.

I am slowly giving up here. So how about the events that @rjmholt mentioned, is there an example of such event already in the engine, and where would I surface it?

Here is it implemented with event, much like CommandNotFoundAction.

master...nohwnd:pwsh-trace-with-sync-event

I make sure to not invoke the action when already in the action. This way you can hook it up from PowerShell, by simply providing a scriptblock. You can also debug the provided scriptblock. With my basic example there is again no significant perf degradation even if running powershell scriptblock as the callback.

I don't think that making it async is worth it, because it is obvious that the more work you do in the callback the slower the code will be, and it would be difficult to leverage that in powershell. In C# we can simply push the data into a queue and process it on another thread, if we need. But seeing that even using scriptblock callback causes no visible perf degradation it probably won't be needed.

The naming and location could be improved. Do you have any suggestions?

Why are you forcing me to implement this in the most complicated way then?

I cannot force you. :-) Since we intend to make a new public API, we need to weigh all the options.

but do you have any asks for it?

It was always a big gap in PowerShell. We can find in Internet some Profiles implemented on tracing. Also MSFT team have an interest #7857 (comment)

Here is it implemented with event

If we consider only "in-session" profiling this looks like overhead and previous prototype is more good for the scenario where you directly collect full info in a list.

It seems @daxian-dbw is busy maybe @lzybkr will share some thoughts.

I honestly never considered Set-PSDebug, possibly because I was never a fan of the cmdlet, but I do see it is a viable approach for some scenarios.

I do prefer an EventSource (or ETW for Windows) based approach. I actually started this approach a long time back here.

A huge benefit to ETW is the ability to enable a trace from outside the process. It's more work to produce useful reports, but it's useful when you need to profile:

• an already running script that you don't want to restart
• hosted PowerShell processes that may not expose Set-PSDebug

That said, in-process is important too, and EventSource supports that. I don't think EventSource is a huge effort to support in-process, but my WIP is incomplete because my approach introduces some extra complexity to support ETW/out-of-process reporting.

The basic idea is to, while measuring, add as little impact as possible, collecting minimal information (collecting a GUID + sequence number while tracing) - then post process. In-process is a bit easier as the data structures are still in memory, ETW would require additional events to enable mapping the GUID+sequence number back to something meaningful. These events would be written after stopping the trace, similar to the .Net rundown events.

@lzybkr Many thanks! We could continue this work if @daxian-dbw hadn't intercepted it already. Have you a time to mentor?

@iSazonov - I could mentor if someone wants to pick up my approach.

@lzybkr Thanks! Now I'm working with your code and I was able to get the first results. Now I'm stuck on "rundown events". because there we need to send an array of SequencePoint-s and I do not still find how implement this.

@iSazonov - You would have 2 event sources: ProfilerEventSource and RundownEventSource. The sequence for an external profiler would be:

1. Enable ProfilerEventSource
2. Disable ProfilerEventSource
3. Enable RundownEventSource
4. Disable RundownEventSource

I was thinking the RundownEventSource would generate:

• 1 event per ScriptBlock with a payload of:
  • Guid (for mapping events from the ProfilerEventSource
  • ScriptBlock text
• 1 event per sequence point with a payload of:
  • Guid
  • Id
  • Extent

This way, a tool need not depend on PowerShell at all and could generate a nice report.

@lzybkr Thanks! I did not see your last comment and already pulled #13673. You can play with working prototype and feedback.

@nohwnd Please look #13673 and feedback.

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.

This is superseded by #13673, thanks @iSazonov for doing all the work!