From ade6b5488a9673a03a2d82cd97975cda089edf85 Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 22 Sep 2020 21:30:36 +0500 Subject: [PATCH 01/25] PowerShell profiler --- .../engine/InitialSessionState.cs | 1 + .../interpreter/PowerShellInstructions.cs | 13 +- .../engine/parser/Compiler.cs | 49 ++- .../engine/runtime/CompiledScriptBlock.cs | 34 +- .../engine/runtime/Profiler.cs | 391 ++++++++++++++++++ 5 files changed, 457 insertions(+), 31 deletions(-) create mode 100644 src/System.Management.Automation/engine/runtime/Profiler.cs diff --git a/src/System.Management.Automation/engine/InitialSessionState.cs b/src/System.Management.Automation/engine/InitialSessionState.cs index bfae1b3e6b4..950397fc301 100644 --- a/src/System.Management.Automation/engine/InitialSessionState.cs +++ b/src/System.Management.Automation/engine/InitialSessionState.cs @@ -5269,6 +5269,7 @@ private static void InitializeCoreCmdletsAndProviders( { "Import-Module", new SessionStateCmdletEntry("Import-Module", typeof(ImportModuleCommand), helpFile) }, { "Invoke-Command", new SessionStateCmdletEntry("Invoke-Command", typeof(InvokeCommandCommand), helpFile) }, { "Invoke-History", new SessionStateCmdletEntry("Invoke-History", typeof(InvokeHistoryCommand), helpFile) }, + { "Measure-Script", new SessionStateCmdletEntry("Measure-Script", typeof(MeasureScriptCommand), helpFile) }, { "New-Module", new SessionStateCmdletEntry("New-Module", typeof(NewModuleCommand), helpFile) }, { "New-ModuleManifest", new SessionStateCmdletEntry("New-ModuleManifest", typeof(NewModuleManifestCommand), helpFile) }, { "New-PSRoleCapabilityFile", new SessionStateCmdletEntry("New-PSRoleCapabilityFile", typeof(NewPSRoleCapabilityFileCommand), helpFile) }, diff --git a/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs b/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs index 5592af6f526..f186b129955 100644 --- a/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs +++ b/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs @@ -29,17 +29,14 @@ private UpdatePositionInstruction(bool checkBreakpoints, int sequencePoint) public override int Run(InterpretedFrame frame) { var functionContext = frame.FunctionContext; - var context = frame.ExecutionContext; - - functionContext._currentSequencePointIndex = _sequencePoint; if (_checkBreakpoints) { - if (context._debuggingMode > 0) - { - context.Debugger.OnSequencePointHit(functionContext); - } + functionContext.UpdatePosition(_sequencePoint); + } + else + { + functionContext.UpdatePositionNoBreak(_sequencePoint); } - return +1; } diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index 68bb523427b..62e5d9c8d69 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -241,6 +241,12 @@ internal static class CachedReflectionInfo internal static readonly MethodInfo FunctionContext_PushTrapHandlers = typeof(FunctionContext).GetMethod(nameof(FunctionContext.PushTrapHandlers), InstanceFlags); + internal static readonly MethodInfo FunctionContext_UpdatePosition = + typeof(FunctionContext).GetMethod(nameof(FunctionContext.UpdatePosition), InstanceFlags); + + internal static readonly MethodInfo FunctionContext_UpdatePositionNoBreak = + typeof(FunctionContext).GetMethod(nameof(FunctionContext.UpdatePositionNoBreak), InstanceFlags); + internal static readonly MethodInfo FunctionOps_DefineFunction = typeof(FunctionOps).GetMethod(nameof(FunctionOps.DefineFunction), StaticFlags); @@ -802,6 +808,25 @@ internal void PopTrapHandlers() { _traps.RemoveAt(_traps.Count - 1); } + + internal void UpdatePositionNoBreak(int pos) + { + _currentSequencePointIndex = pos; + + if (ProfilerEventSource.LogInstance.IsEnabled()) + { + ProfilerEventSource.LogInstance.SequencePoint(_scriptBlock.Id, pos); + } + } + + internal void UpdatePosition(int pos) + { + UpdatePositionNoBreak(pos); + if (_executionContext._debuggingMode > 0) + { + _executionContext.Debugger.OnSequencePointHit(this); + } + } } internal class Compiler : ICustomAstVisitor2 @@ -7055,26 +7080,10 @@ public override Expression Reduce() exprs.Add(Expression.DebugInfo(_debugSymbolDocument, _extent.StartLineNumber, _extent.StartColumnNumber, _extent.EndLineNumber, _extent.EndColumnNumber)); } - exprs.Add( - Expression.Assign( - Expression.Field(Compiler.s_functionContext, CachedReflectionInfo.FunctionContext__currentSequencePointIndex), - ExpressionCache.Constant(_sequencePoint))); - - if (_checkBreakpoints) - { - exprs.Add( - Expression.IfThen( - Expression.GreaterThan( - Expression.Field(Compiler.s_executionContextParameter, CachedReflectionInfo.ExecutionContext_DebuggingMode), - ExpressionCache.Constant(0)), - Expression.Call( - Expression.Field(Compiler.s_executionContextParameter, CachedReflectionInfo.ExecutionContext_Debugger), - CachedReflectionInfo.Debugger_OnSequencePointHit, - Compiler.s_functionContext))); - } - - exprs.Add(ExpressionCache.Empty); - + var method = _checkBreakpoints + ? CachedReflectionInfo.FunctionContext_UpdatePosition + : CachedReflectionInfo.FunctionContext_UpdatePositionNoBreak; + exprs.Add(Expression.Call(Compiler.s_functionContext, method, ExpressionCache.Constant(_sequencePoint))); return Expression.Block(exprs); } diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index 79881796cad..8b5d3d7024a 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -39,18 +39,41 @@ internal enum ScriptBlockClauseToInvoke internal class CompiledScriptBlockData { + private readonly static ConcurrentDictionary s_IdToScriptBlock + = new ConcurrentDictionary(); + + internal static void ResetIdToScriptBlock() + { + s_IdToScriptBlock.Clear(); + } + + internal static bool TryGetCompiledScriptBlockData(Guid key, /* [MaybeNullWhen(false)] */ out CompiledScriptBlockData value) + { + return s_IdToScriptBlock.TryGetValue(key, out value); + } + + internal static ConcurrentDictionary GetCompiledScriptBlockData() + { + return s_IdToScriptBlock; + } + + internal void RegisterCompiledScriptBlockData() + { + s_IdToScriptBlock.TryAdd(this.Id, this); + } + internal CompiledScriptBlockData(IParameterMetadataProvider ast, bool isFilter) { _ast = ast; - this.IsFilter = isFilter; - this.Id = Guid.NewGuid(); + IsFilter = isFilter; + Id = Guid.NewGuid(); } internal CompiledScriptBlockData(string scriptText, bool isProductCode) { _isProductCode = isProductCode; _scriptText = scriptText; - this.Id = Guid.NewGuid(); + Id = Guid.NewGuid(); } internal bool Compile(bool optimized) @@ -78,6 +101,11 @@ internal bool Compile(bool optimized) CompileOptimized(); } + if (ProfilerEventSource.LogInstance.IsEnabled()) + { + RegisterCompiledScriptBlockData(); + } + return optimized; } diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs new file mode 100644 index 00000000000..21ee16b9c49 --- /dev/null +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -0,0 +1,391 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +#nullable enable + +using System.Collections.Generic; +using System.Diagnostics.Tracing; +using System.Management.Automation.Internal; + +namespace System.Management.Automation +{ + /// + /// This class is a source of performance events for script block profiling. + /// Guid is {092ae15a-d5fb-5d8d-9ffd-68891d24c5f6}. + /// + [EventSource(Name = "Microsoft-PowerShell-Profiler")] + internal class ProfilerEventSource : EventSource + { + internal static ProfilerEventSource LogInstance = new ProfilerEventSource(); + + [Event(1)] + public void SequencePoint(Guid ScriptBlockId, int SequencePointPosition) + { + // We could use: + // WriteEvent(eventId: 1, ScriptBlockId, SequencePointPosition); + // but we care about performance. + if (IsEnabled()) + { + unsafe + { + EventData* eventPayload = stackalloc EventData[2]; + + eventPayload[0] = new EventData + { + Size = sizeof(Guid), + DataPointer = ((IntPtr)(&ScriptBlockId)) + }; + eventPayload[1] = new EventData + { + Size = sizeof(int), + DataPointer = ((IntPtr)(&SequencePointPosition)) + }; + + WriteEventCore(eventId: 1, eventDataCount: 2, eventPayload); + } + } + } + + protected override void OnEventCommand(EventCommandEventArgs command) + { + base.OnEventCommand(command); + + if (command.Command == EventCommand.Disable) + { + // At the end of the profile session, we send all the metadata. + ProfilerRundownEventSource.LogInstance.WriteRundownEvents(); + } + } + } + + /// + /// This class is a source of rundown (meta data) events for script block profiling. + /// Guid is {f348266e-dde6-5590-4bc9-10e1e2b6fe16}. + /// + [EventSource(Name = "Microsoft-PowerShell-Profiler-Rundown")] + internal class ProfilerRundownEventSource : EventSource + { + internal static ProfilerRundownEventSource LogInstance = new ProfilerRundownEventSource(); + + [Event(2)] + public void SequencePointRundown( + Guid ScriptBlockId, + int SequencePointCount, + int SequencePoint, + string File, + int StartLineNumber, + int StartColumnNumber, + int EndLineNumber, + int EndColumnNumber, + string Text, + int StartOffset, + int EndOffset) + { + // It is not performance critical so we use the standard method overload. + WriteEvent( + eventId: 2, + ScriptBlockId, + SequencePointCount, + SequencePoint, + File, + StartLineNumber, + StartColumnNumber, + EndLineNumber, + EndColumnNumber, + Text, + StartOffset, + EndOffset); + } + + [NonEvent] + internal void WriteRundownEvents() + { + foreach (var csb in CompiledScriptBlockData.GetCompiledScriptBlockData().Values) + { + for (var position = 0; position < csb.SequencePoints.Length; position++) + { + var sequencePoint = csb.SequencePoints[position]; + + SequencePointRundown( + csb.Id, + csb.SequencePoints.Length, + position, + sequencePoint.File, + sequencePoint.StartLineNumber, + sequencePoint.StartColumnNumber, + sequencePoint.EndLineNumber, + sequencePoint.EndColumnNumber, + sequencePoint.Text, + sequencePoint.StartOffset, + sequencePoint.EndOffset); + } + } + } + + protected override void OnEventCommand(EventCommandEventArgs command) + { + base.OnEventCommand(command); + + if (command.Command == EventCommand.Enable) + { + CompiledScriptBlockData.ResetIdToScriptBlock(); + } + } + + protected override void Dispose(bool disposing) + { + CompiledScriptBlockData.ResetIdToScriptBlock(); + base.Dispose(disposing); + } + } + + /// + /// Represents a span of text in a script. + /// + internal struct ScriptExtentEventData + { + /// + /// The filename the extent includes, or null if the extent is not included in any file. + /// + public string File; + + /// + /// The line number at the beginning of the extent, with the value 1 being the first line. + /// + public int StartLineNumber; + + /// + /// The column number at the beginning of the extent, with the value 1 being the first column. + /// + public int StartColumnNumber; + + /// + /// The line number at the end of the extent, with the value 1 being the first line. + /// + public int EndLineNumber; + + /// + /// The column number at the end of the extent, with the value 1 being the first column. + /// + public int EndColumnNumber; + + /// + /// The script text that the extent includes. + /// + public string Text; + + /// + /// The starting offset of the extent. + /// + public int StartOffset; + + /// + /// The ending offset of the extent. + /// + public int EndOffset; + } + + /// + /// This class is PowerShell script block profiler. + /// + internal class InternalProfiler : EventListener + { + /// + /// Represents a SequencePoint profile event data. + /// The event is raised at every sequence point start. + /// The event must be as small as possible for performance. + /// + internal struct SequencePointProfileEventData + { + /// + /// Start time of the SequencePoint. + /// + public DateTime Timestamp; + + /// + /// Unique identifer of the script block. + /// + public Guid ScriptId; + + /// + /// SequencePoint index number/position of the script block. + /// + public int SequencePointPosition; + } + + /// + /// Represents a SequencePoint rundown profile event data. + /// The rundown event contains a meta data about script block sequence points. + /// The rundown event is raised once for every script block sequence point + /// at profile session end. + /// + internal struct CompiledScriptBlockRundownProfileEventData + { + /// + /// Timestamp of first rundown profile event for the script block. + /// + public DateTime Timestamp; + + /// + /// Unique identifer of the script block. + /// + public Guid ScriptId; + + /// + /// Sequence points of the script block. + /// + public ScriptExtentEventData[] SequencePoints; + } + + // Buffer to collect a performance event data. + internal List SequencePointProfileEvents = new List(5000); + + // Buffer to collect a script block meta data. + internal Dictionary CompiledScriptBlockMetaData = new Dictionary(5000); + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + var payload = eventData.Payload; + if (payload is null) + { + // there is a bug in our custom EventSource. + throw new ArgumentNullException(nameof(payload)); + } + + switch (eventData.EventId) + { + case 1: + SequencePointProfileEvents.Add(new SequencePointProfileEventData + { + Timestamp = eventData.TimeStamp, + ScriptId = (Guid)payload[0]!, + SequencePointPosition = (int)payload[1]! + }); + break; + case 2: + ScriptExtentEventData sequencePoint; + var scriptId = (Guid)payload[0]!; + var sequencePointCount = (int)payload[1]!; + var pos = (int)payload[2]!; + sequencePoint.File = (string)payload[3]!; + sequencePoint.StartLineNumber = (int)payload[4]!; + sequencePoint.StartColumnNumber = (int)payload[5]!; + sequencePoint.EndLineNumber = (int)payload[6]!; + sequencePoint.EndColumnNumber = (int)payload[7]!; + sequencePoint.Text = (string)payload[8]!; + sequencePoint.StartOffset = (int)payload[9]!; + sequencePoint.EndOffset = (int)payload[10]!; + + if (CompiledScriptBlockMetaData.TryGetValue(scriptId, out var sbe)) + { + sbe.SequencePoints[pos] = sequencePoint; + } + else + { + sbe = new CompiledScriptBlockRundownProfileEventData() + { + Timestamp = eventData.TimeStamp, + ScriptId = scriptId, + SequencePoints = new ScriptExtentEventData[sequencePointCount] + }; + + sbe.SequencePoints[pos] = sequencePoint; + + CompiledScriptBlockMetaData.TryAdd(sbe.ScriptId, sbe); + } + break; + } + } + + /// + /// Start the profiler. + /// + public void EnableEvents() + { + EnableEvents(ProfilerRundownEventSource.LogInstance, EventLevel.LogAlways); + EnableEvents(ProfilerEventSource.LogInstance, EventLevel.LogAlways); + } + + /// + /// Stop the profiler. + /// + public void DisableEvents() + { + DisableEvents(ProfilerEventSource.LogInstance); + DisableEvents(ProfilerRundownEventSource.LogInstance); + } + } + + /// + /// The cmdlet profiles a script block. + /// + [Cmdlet(VerbsDiagnostic.Measure, "Script", RemotingCapability = RemotingCapability.None)] + public class MeasureScriptCommand : PSCmdlet + { + /// + /// A script block to profile. + /// + [Parameter(Position = 0, Mandatory = true)] + public ScriptBlock ScriptBlock { get; set; } = null!; + + /// + /// Process a profile data. + /// + protected override void EndProcessing() + { + using (var profiler = new InternalProfiler()) + { + try + { + profiler.EnableEvents(); + + ScriptBlock.InvokeWithPipe( + useLocalScope: false, + errorHandlingBehavior: ScriptBlock.ErrorHandlingBehavior.WriteToCurrentErrorPipe, + dollarUnder: null, + input: Array.Empty(), + scriptThis: AutomationNull.Value, + outputPipe: new Pipe { NullPipe = true }, + invocationInfo: null); + } + finally + { + profiler.DisableEvents(); + } + + var events = profiler.SequencePointProfileEvents; + if (events.Count == 0) + { + return; + } + + var metaData = profiler.CompiledScriptBlockMetaData; + + // We have only start timestamp for sequence point. + // To evaluate a duration of the sequence point + // we take a start timestamp from next sequence point + // that is actually a stop timestamp for the previous sequence point. + // For last sequence point we have not next timestamp + // so we add a copy of the last sequence point as a workaround. + events.Add(events[events.Count - 1]); + + for (var i = 0; i < events.Count - 1; i++) + { + var profileDate = events[i]; + if (metaData.TryGetValue(profileDate.ScriptId, out var compiledScriptBlockData)) + { + var extent = compiledScriptBlockData.SequencePoints[profileDate.SequencePointPosition]; + + PSObject result = new PSObject(); + result.Properties.Add(new PSNoteProperty("TimeStamp", profileDate.Timestamp.TimeOfDay)); + result.Properties.Add(new PSNoteProperty("Duration", events[i + 1].Timestamp - profileDate.Timestamp)); + result.Properties.Add(new PSNoteProperty("ExtentText", extent.Text)); + result.Properties.Add(new PSNoteProperty("Extent", extent)); + + WriteObject(result); + } + } + } + } + } +} From cabadd5a163cb8861b13e0178c1e33c55fd272ed Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 22 Sep 2020 22:15:39 +0500 Subject: [PATCH 02/25] Fix CodeFactor issues --- .../engine/interpreter/PowerShellInstructions.cs | 1 + .../engine/runtime/CompiledScriptBlock.cs | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs b/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs index f186b129955..9f251d7a9ff 100644 --- a/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs +++ b/src/System.Management.Automation/engine/interpreter/PowerShellInstructions.cs @@ -37,6 +37,7 @@ public override int Run(InterpretedFrame frame) { functionContext.UpdatePositionNoBreak(_sequencePoint); } + return +1; } diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index 8b5d3d7024a..fa19add7761 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -39,7 +39,7 @@ internal enum ScriptBlockClauseToInvoke internal class CompiledScriptBlockData { - private readonly static ConcurrentDictionary s_IdToScriptBlock + private static readonly ConcurrentDictionary s_IdToScriptBlock = new ConcurrentDictionary(); internal static void ResetIdToScriptBlock() From 49e48f8de9e7115963f12350ca29ab7160edbb0f Mon Sep 17 00:00:00 2001 From: Ilya Date: Wed, 23 Sep 2020 11:58:41 +0500 Subject: [PATCH 03/25] Add scriptblock rundown event --- .../engine/runtime/Profiler.cs | 21 ++++++++++++++++++- 1 file changed, 20 insertions(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 21ee16b9c49..5d55d86ce6a 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -68,6 +68,18 @@ internal class ProfilerRundownEventSource : EventSource internal static ProfilerRundownEventSource LogInstance = new ProfilerRundownEventSource(); [Event(2)] + public void ScriptBlockRundown( + Guid ScriptBlockId, + string ScriptBlockText) + { + // It is not performance critical so we use the standard method overload. + WriteEvent( + eventId: 2, + ScriptBlockId, + ScriptBlockText); + } + + [Event(3)] public void SequencePointRundown( Guid ScriptBlockId, int SequencePointCount, @@ -83,7 +95,7 @@ public void SequencePointRundown( { // It is not performance critical so we use the standard method overload. WriteEvent( - eventId: 2, + eventId: 3, ScriptBlockId, SequencePointCount, SequencePoint, @@ -102,6 +114,8 @@ internal void WriteRundownEvents() { foreach (var csb in CompiledScriptBlockData.GetCompiledScriptBlockData().Values) { + ScriptBlockRundown(csb.Id, csb.Ast.Body.Extent.Text); + for (var position = 0; position < csb.SequencePoints.Length; position++) { var sequencePoint = csb.SequencePoints[position]; @@ -255,6 +269,7 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) switch (eventData.EventId) { case 1: + // Performance event SequencePointProfileEvents.Add(new SequencePointProfileEventData { Timestamp = eventData.TimeStamp, @@ -263,6 +278,10 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) }); break; case 2: + // Scriptblock rundown event + break; + case 3: + // SequencePoint rundown event ScriptExtentEventData sequencePoint; var scriptId = (Guid)payload[0]!; var sequencePointCount = (int)payload[1]!; From 84b4629d1836239a9ab120d26b9c14edae091af4 Mon Sep 17 00:00:00 2001 From: Ilya Date: Wed, 23 Sep 2020 18:40:52 +0500 Subject: [PATCH 04/25] Use ConditionalWeakTable --- .../engine/runtime/CompiledScriptBlock.cs | 31 +++------------- .../engine/runtime/Profiler.cs | 36 ++++++++----------- 2 files changed, 19 insertions(+), 48 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index fa19add7761..ad8efde5e71 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -39,34 +39,17 @@ internal enum ScriptBlockClauseToInvoke internal class CompiledScriptBlockData { - private static readonly ConcurrentDictionary s_IdToScriptBlock - = new ConcurrentDictionary(); + private static readonly ConditionalWeakTable s_LiveScriptBlockTable + = new ConditionalWeakTable(); - internal static void ResetIdToScriptBlock() - { - s_IdToScriptBlock.Clear(); - } - - internal static bool TryGetCompiledScriptBlockData(Guid key, /* [MaybeNullWhen(false)] */ out CompiledScriptBlockData value) - { - return s_IdToScriptBlock.TryGetValue(key, out value); - } - - internal static ConcurrentDictionary GetCompiledScriptBlockData() - { - return s_IdToScriptBlock; - } - - internal void RegisterCompiledScriptBlockData() - { - s_IdToScriptBlock.TryAdd(this.Id, this); - } + internal static ConditionalWeakTable GetCompiledScriptBlockTable() => s_LiveScriptBlockTable; internal CompiledScriptBlockData(IParameterMetadataProvider ast, bool isFilter) { _ast = ast; IsFilter = isFilter; Id = Guid.NewGuid(); + s_LiveScriptBlockTable.Add(this, this); } internal CompiledScriptBlockData(string scriptText, bool isProductCode) @@ -74,6 +57,7 @@ internal CompiledScriptBlockData(string scriptText, bool isProductCode) _isProductCode = isProductCode; _scriptText = scriptText; Id = Guid.NewGuid(); + s_LiveScriptBlockTable.Add(this, this); } internal bool Compile(bool optimized) @@ -101,11 +85,6 @@ internal bool Compile(bool optimized) CompileOptimized(); } - if (ProfilerEventSource.LogInstance.IsEnabled()) - { - RegisterCompiledScriptBlockData(); - } - return optimized; } diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 5d55d86ce6a..69fb73490c0 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -112,17 +112,25 @@ public void SequencePointRundown( [NonEvent] internal void WriteRundownEvents() { - foreach (var csb in CompiledScriptBlockData.GetCompiledScriptBlockData().Values) + foreach (var pair in CompiledScriptBlockData.GetCompiledScriptBlockTable()) { - ScriptBlockRundown(csb.Id, csb.Ast.Body.Extent.Text); + var compiledScriptBlock = pair.Key; + ScriptBlockRundown(compiledScriptBlock.Id, compiledScriptBlock.Ast.Body.Extent.Text); - for (var position = 0; position < csb.SequencePoints.Length; position++) + if (compiledScriptBlock.SequencePoints is null) { - var sequencePoint = csb.SequencePoints[position]; + // Why do we get script blocks without sequence points? + // See a comment in Compiler.cs line 2035. + continue; + } + + for (var position = 0; position < compiledScriptBlock.SequencePoints.Length; position++) + { + var sequencePoint = compiledScriptBlock.SequencePoints[position]; SequencePointRundown( - csb.Id, - csb.SequencePoints.Length, + compiledScriptBlock.Id, + compiledScriptBlock.SequencePoints.Length, position, sequencePoint.File, sequencePoint.StartLineNumber, @@ -135,22 +143,6 @@ internal void WriteRundownEvents() } } } - - protected override void OnEventCommand(EventCommandEventArgs command) - { - base.OnEventCommand(command); - - if (command.Command == EventCommand.Enable) - { - CompiledScriptBlockData.ResetIdToScriptBlock(); - } - } - - protected override void Dispose(bool disposing) - { - CompiledScriptBlockData.ResetIdToScriptBlock(); - base.Dispose(disposing); - } } /// From f93bd8fa36d969680d3d3ce8cb24f7f833b4eb08 Mon Sep 17 00:00:00 2001 From: Ilya Date: Mon, 28 Sep 2020 11:02:58 +0500 Subject: [PATCH 05/25] Revert "Use ConditionalWeakTable" This reverts commit 9a22f66b6e712ac12a0b645f26da090803071d1b. --- .../engine/runtime/CompiledScriptBlock.cs | 31 +++++++++++++--- .../engine/runtime/Profiler.cs | 36 +++++++++++-------- 2 files changed, 48 insertions(+), 19 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index ad8efde5e71..fa19add7761 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -39,17 +39,34 @@ internal enum ScriptBlockClauseToInvoke internal class CompiledScriptBlockData { - private static readonly ConditionalWeakTable s_LiveScriptBlockTable - = new ConditionalWeakTable(); + private static readonly ConcurrentDictionary s_IdToScriptBlock + = new ConcurrentDictionary(); - internal static ConditionalWeakTable GetCompiledScriptBlockTable() => s_LiveScriptBlockTable; + internal static void ResetIdToScriptBlock() + { + s_IdToScriptBlock.Clear(); + } + + internal static bool TryGetCompiledScriptBlockData(Guid key, /* [MaybeNullWhen(false)] */ out CompiledScriptBlockData value) + { + return s_IdToScriptBlock.TryGetValue(key, out value); + } + + internal static ConcurrentDictionary GetCompiledScriptBlockData() + { + return s_IdToScriptBlock; + } + + internal void RegisterCompiledScriptBlockData() + { + s_IdToScriptBlock.TryAdd(this.Id, this); + } internal CompiledScriptBlockData(IParameterMetadataProvider ast, bool isFilter) { _ast = ast; IsFilter = isFilter; Id = Guid.NewGuid(); - s_LiveScriptBlockTable.Add(this, this); } internal CompiledScriptBlockData(string scriptText, bool isProductCode) @@ -57,7 +74,6 @@ internal CompiledScriptBlockData(string scriptText, bool isProductCode) _isProductCode = isProductCode; _scriptText = scriptText; Id = Guid.NewGuid(); - s_LiveScriptBlockTable.Add(this, this); } internal bool Compile(bool optimized) @@ -85,6 +101,11 @@ internal bool Compile(bool optimized) CompileOptimized(); } + if (ProfilerEventSource.LogInstance.IsEnabled()) + { + RegisterCompiledScriptBlockData(); + } + return optimized; } diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 69fb73490c0..5d55d86ce6a 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -112,25 +112,17 @@ public void SequencePointRundown( [NonEvent] internal void WriteRundownEvents() { - foreach (var pair in CompiledScriptBlockData.GetCompiledScriptBlockTable()) + foreach (var csb in CompiledScriptBlockData.GetCompiledScriptBlockData().Values) { - var compiledScriptBlock = pair.Key; - ScriptBlockRundown(compiledScriptBlock.Id, compiledScriptBlock.Ast.Body.Extent.Text); + ScriptBlockRundown(csb.Id, csb.Ast.Body.Extent.Text); - if (compiledScriptBlock.SequencePoints is null) + for (var position = 0; position < csb.SequencePoints.Length; position++) { - // Why do we get script blocks without sequence points? - // See a comment in Compiler.cs line 2035. - continue; - } - - for (var position = 0; position < compiledScriptBlock.SequencePoints.Length; position++) - { - var sequencePoint = compiledScriptBlock.SequencePoints[position]; + var sequencePoint = csb.SequencePoints[position]; SequencePointRundown( - compiledScriptBlock.Id, - compiledScriptBlock.SequencePoints.Length, + csb.Id, + csb.SequencePoints.Length, position, sequencePoint.File, sequencePoint.StartLineNumber, @@ -143,6 +135,22 @@ internal void WriteRundownEvents() } } } + + protected override void OnEventCommand(EventCommandEventArgs command) + { + base.OnEventCommand(command); + + if (command.Command == EventCommand.Enable) + { + CompiledScriptBlockData.ResetIdToScriptBlock(); + } + } + + protected override void Dispose(bool disposing) + { + CompiledScriptBlockData.ResetIdToScriptBlock(); + base.Dispose(disposing); + } } /// From f3e31297cddf251831305a7c37326fc2971b547b Mon Sep 17 00:00:00 2001 From: Ilya Date: Mon, 28 Sep 2020 16:59:12 +0500 Subject: [PATCH 06/25] Initialize CompiledScriptBlockTable with scriptblockCache --- .../engine/runtime/CompiledScriptBlock.cs | 31 +++++++++++++------ .../engine/runtime/Profiler.cs | 27 +++++++++++----- 2 files changed, 41 insertions(+), 17 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index fa19add7761..8403bccb746 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -39,27 +39,32 @@ internal enum ScriptBlockClauseToInvoke internal class CompiledScriptBlockData { - private static readonly ConcurrentDictionary s_IdToScriptBlock - = new ConcurrentDictionary(); + private static readonly ConcurrentDictionary s_compiledScriptBlockTable + = new ConcurrentDictionary(); - internal static void ResetIdToScriptBlock() + internal static void ClearCompiledScriptBlockTable() { - s_IdToScriptBlock.Clear(); + s_compiledScriptBlockTable.Clear(); } - internal static bool TryGetCompiledScriptBlockData(Guid key, /* [MaybeNullWhen(false)] */ out CompiledScriptBlockData value) + internal static ICollection GetCompiledScriptBlockList() { - return s_IdToScriptBlock.TryGetValue(key, out value); + return s_compiledScriptBlockTable.Values; } - internal static ConcurrentDictionary GetCompiledScriptBlockData() + internal static void InitCompiledScriptBlockTable() { - return s_IdToScriptBlock; + ClearCompiledScriptBlockTable(); + + foreach (var csb in ScriptBlock.GetCachedCompiledScriptBlockData()) + { + s_compiledScriptBlockTable.TryAdd(csb, csb); + } } internal void RegisterCompiledScriptBlockData() { - s_IdToScriptBlock.TryAdd(this.Id, this); + s_compiledScriptBlockTable.TryAdd(this, this); } internal CompiledScriptBlockData(IParameterMetadataProvider ast, bool isFilter) @@ -607,6 +612,14 @@ protected ScriptBlock(SerializationInfo info, StreamingContext context) private static readonly ConcurrentDictionary, ScriptBlock> s_cachedScripts = new ConcurrentDictionary, ScriptBlock>(); + internal static IEnumerable GetCachedCompiledScriptBlockData() + { + foreach (var pair in s_cachedScripts) + { + yield return pair.Value.ScriptBlockData; + } + } + internal static ScriptBlock TryGetCachedScriptBlock(string fileName, string fileContents) { if (InternalTestHooks.IgnoreScriptBlockCache) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 5d55d86ce6a..4c4a20336b1 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -112,17 +112,24 @@ public void SequencePointRundown( [NonEvent] internal void WriteRundownEvents() { - foreach (var csb in CompiledScriptBlockData.GetCompiledScriptBlockData().Values) + foreach (var compiledScriptBlock in CompiledScriptBlockData.GetCompiledScriptBlockList()) { - ScriptBlockRundown(csb.Id, csb.Ast.Body.Extent.Text); + ScriptBlockRundown(compiledScriptBlock.Id, compiledScriptBlock.Ast.Body.Extent.Text); - for (var position = 0; position < csb.SequencePoints.Length; position++) + if (compiledScriptBlock.SequencePoints is null) { - var sequencePoint = csb.SequencePoints[position]; + // Why do we get script blocks without sequence points? + // See a comment in Compiler.cs line 2035. + continue; + } + + for (var position = 0; position < compiledScriptBlock.SequencePoints.Length; position++) + { + var sequencePoint = compiledScriptBlock.SequencePoints[position]; SequencePointRundown( - csb.Id, - csb.SequencePoints.Length, + compiledScriptBlock.Id, + compiledScriptBlock.SequencePoints.Length, position, sequencePoint.File, sequencePoint.StartLineNumber, @@ -142,13 +149,17 @@ protected override void OnEventCommand(EventCommandEventArgs command) if (command.Command == EventCommand.Enable) { - CompiledScriptBlockData.ResetIdToScriptBlock(); + CompiledScriptBlockData.InitCompiledScriptBlockTable(); + } + else if (command.Command == EventCommand.Disable) + { + CompiledScriptBlockData.ClearCompiledScriptBlockTable(); } } protected override void Dispose(bool disposing) { - CompiledScriptBlockData.ResetIdToScriptBlock(); + CompiledScriptBlockData.ClearCompiledScriptBlockTable(); base.Dispose(disposing); } } From 354a41b0f5a626e1f8f62c8922aa6a0b52663ed0 Mon Sep 17 00:00:00 2001 From: Ilya Date: Mon, 28 Sep 2020 17:19:06 +0500 Subject: [PATCH 07/25] Simplify scriptblock cache --- .../engine/ExternalScriptInfo.cs | 11 +++-- .../engine/runtime/CompiledScriptBlock.cs | 48 ++++++------------- 2 files changed, 23 insertions(+), 36 deletions(-) diff --git a/src/System.Management.Automation/engine/ExternalScriptInfo.cs b/src/System.Management.Automation/engine/ExternalScriptInfo.cs index 642eb4d8fe9..79992d0c276 100644 --- a/src/System.Management.Automation/engine/ExternalScriptInfo.cs +++ b/src/System.Management.Automation/engine/ExternalScriptInfo.cs @@ -188,7 +188,8 @@ public override SessionStateEntryVisibility Visibility { get { - if (Context == null) return SessionStateEntryVisibility.Public; + if (Context == null) + return SessionStateEntryVisibility.Public; return Context.EngineSessionState.CheckScriptVisibility(_path); } @@ -267,7 +268,11 @@ internal ScriptBlockAst GetScriptBlockAst() var scriptContents = ScriptContents; if (_scriptBlock == null) { - this.ScriptBlock = ScriptBlock.TryGetCachedScriptBlock(_path, scriptContents); + var compiledScriptBlockData = ScriptBlock.TryGetCompiledCachedScriptBlock(_path, scriptContents); + if (compiledScriptBlockData != null) + { + this.ScriptBlock = new ScriptBlock(compiledScriptBlockData); + } } if (_scriptBlock != null) @@ -305,7 +310,7 @@ internal ScriptBlockAst GetScriptBlockAst() if (errors.Length == 0) { this.ScriptBlock = new ScriptBlock(_scriptBlockAst, isFilter: false); - ScriptBlock.CacheScriptBlock(_scriptBlock.Clone(), _path, scriptContents); + ScriptBlock.CacheCompiledScriptBlock(_scriptBlock.Clone(), _path, scriptContents); } } diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index 8403bccb746..4bc917f810c 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -581,7 +581,7 @@ internal ScriptBlock(IParameterMetadataProvider ast, bool isFilter) { } - private ScriptBlock(CompiledScriptBlockData scriptBlockData) + internal ScriptBlock(CompiledScriptBlockData scriptBlockData) { _scriptBlockData = scriptBlockData; @@ -609,32 +609,25 @@ protected ScriptBlock(SerializationInfo info, StreamingContext context) { } - private static readonly ConcurrentDictionary, ScriptBlock> s_cachedScripts = - new ConcurrentDictionary, ScriptBlock>(); + private static readonly ConcurrentDictionary, CompiledScriptBlockData> s_cachedScripts = + new ConcurrentDictionary, CompiledScriptBlockData>(); - internal static IEnumerable GetCachedCompiledScriptBlockData() + internal static ICollection GetCachedCompiledScriptBlockData() { - foreach (var pair in s_cachedScripts) - { - yield return pair.Value.ScriptBlockData; - } + return s_cachedScripts.Values; } - internal static ScriptBlock TryGetCachedScriptBlock(string fileName, string fileContents) + internal static CompiledScriptBlockData TryGetCompiledCachedScriptBlock(string fileName, string fileContents) { if (InternalTestHooks.IgnoreScriptBlockCache) { return null; } - ScriptBlock scriptBlock; var key = Tuple.Create(fileName, fileContents); - if (s_cachedScripts.TryGetValue(key, out scriptBlock)) + if (s_cachedScripts.TryGetValue(key, out var compiledScriptBlockData)) { - Diagnostics.Assert( - scriptBlock.SessionStateInternal == null, - "A cached scriptblock should not have it's session state bound, that causes a memory leak."); - return scriptBlock.Clone(); + return compiledScriptBlockData; } return null; @@ -646,7 +639,7 @@ private static bool IsDynamicKeyword(Ast ast) private static bool IsUsingTypes(Ast ast) => ast is UsingStatementAst cmdAst && cmdAst.IsUsingModuleOrAssembly(); - internal static void CacheScriptBlock(ScriptBlock scriptBlock, string fileName, string fileContents) + internal static void CacheCompiledScriptBlock(ScriptBlock scriptBlock, string fileName, string fileContents) { if (InternalTestHooks.IgnoreScriptBlockCache) { @@ -673,15 +666,7 @@ internal static void CacheScriptBlock(ScriptBlock scriptBlock, string fileName, } var key = Tuple.Create(fileName, fileContents); - s_cachedScripts.TryAdd(key, scriptBlock); - } - - /// - /// Clears the cached scriptblocks. - /// - internal static void ClearScriptBlockCache() - { - s_cachedScripts.Clear(); + s_cachedScripts.TryAdd(key, scriptBlock.ScriptBlockData); } internal static readonly ScriptBlock EmptyScriptBlock = @@ -689,10 +674,10 @@ internal static void ClearScriptBlockCache() internal static ScriptBlock Create(Parser parser, string fileName, string fileContents) { - var scriptBlock = TryGetCachedScriptBlock(fileName, fileContents); - if (scriptBlock != null) + var compiledScriptBlockData = TryGetCompiledCachedScriptBlock(fileName, fileContents); + if (compiledScriptBlockData != null) { - return scriptBlock; + return new ScriptBlock(compiledScriptBlockData); } var ast = parser.Parse(fileName, fileContents, null, out ParseError[] errors, ParseMode.Default); @@ -702,12 +687,9 @@ internal static ScriptBlock Create(Parser parser, string fileName, string fileCo } var result = new ScriptBlock(ast, isFilter: false); - CacheScriptBlock(result, fileName, fileContents); + CacheCompiledScriptBlock(result, fileName, fileContents); - // The value returned will potentially be bound to a session state. We don't want - // the cached script block to end up being bound to any session state, so clone - // the return value to ensure the cached value has no session state. - return result.Clone(); + return result; } internal ScriptBlock Clone() => new ScriptBlock(_scriptBlockData); From 1f175738ec559be1e29e7da9a6318952d0bf8034 Mon Sep 17 00:00:00 2001 From: Ilya Date: Mon, 28 Sep 2020 17:19:32 +0500 Subject: [PATCH 08/25] Add temporary helpuri --- src/System.Management.Automation/engine/runtime/Profiler.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 4c4a20336b1..b21029ad232 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -349,7 +349,7 @@ public void DisableEvents() /// /// The cmdlet profiles a script block. /// - [Cmdlet(VerbsDiagnostic.Measure, "Script", RemotingCapability = RemotingCapability.None)] + [Cmdlet(VerbsDiagnostic.Measure, "Script", HelpUri = "https://go.microsoft.com/fwlink/?LinkID=2097029", RemotingCapability = RemotingCapability.None)] public class MeasureScriptCommand : PSCmdlet { /// From 12760c8a88743a664c974f70bbd1b0bfe436bea0 Mon Sep 17 00:00:00 2001 From: Ilya Date: Mon, 28 Sep 2020 21:57:08 +0500 Subject: [PATCH 09/25] Fix tests --- src/System.Management.Automation/engine/runtime/Profiler.cs | 2 +- test/powershell/engine/Basic/DefaultCommands.Tests.ps1 | 1 + test/powershell/engine/Help/HelpSystem.Tests.ps1 | 3 ++- 3 files changed, 4 insertions(+), 2 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index b21029ad232..5be556cbf48 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -349,7 +349,7 @@ public void DisableEvents() /// /// The cmdlet profiles a script block. /// - [Cmdlet(VerbsDiagnostic.Measure, "Script", HelpUri = "https://go.microsoft.com/fwlink/?LinkID=2097029", RemotingCapability = RemotingCapability.None)] + [Cmdlet(VerbsDiagnostic.Measure, "Script", HelpUri = "", RemotingCapability = RemotingCapability.None)] public class MeasureScriptCommand : PSCmdlet { /// diff --git a/test/powershell/engine/Basic/DefaultCommands.Tests.ps1 b/test/powershell/engine/Basic/DefaultCommands.Tests.ps1 index e970d5a06a8..8950c958e4f 100644 --- a/test/powershell/engine/Basic/DefaultCommands.Tests.ps1 +++ b/test/powershell/engine/Basic/DefaultCommands.Tests.ps1 @@ -357,6 +357,7 @@ Describe "Verify approved aliases list" -Tags "CI" { "Cmdlet", "Limit-EventLog", "", $($FullCLR ), "", "", "" "Cmdlet", "Measure-Command", "", $($FullCLR -or $CoreWindows -or $CoreUnix), "", "", "None" "Cmdlet", "Measure-Object", "", $($FullCLR -or $CoreWindows -or $CoreUnix), "", "", "None" +"Cmdlet", "Measure-Script", "", $( $CoreWindows -or $CoreUnix), "", "", "None" "Cmdlet", "Move-Item", "", $($FullCLR -or $CoreWindows -or $CoreUnix), "", "", "Medium" "Cmdlet", "Move-ItemProperty", "", $($FullCLR -or $CoreWindows -or $CoreUnix), "", "", "Medium" "Cmdlet", "New-Alias", "", $($FullCLR -or $CoreWindows -or $CoreUnix), "", "", "Low" diff --git a/test/powershell/engine/Help/HelpSystem.Tests.ps1 b/test/powershell/engine/Help/HelpSystem.Tests.ps1 index bd523b1033e..3aa189fae81 100644 --- a/test/powershell/engine/Help/HelpSystem.Tests.ps1 +++ b/test/powershell/engine/Help/HelpSystem.Tests.ps1 @@ -17,7 +17,8 @@ $script:cmdletsToSkip = @( "Enable-ExperimentalFeature", "Disable-ExperimentalFeature", "Get-PSSubsystem", - "Switch-Process" + "Switch-Process", + "Measure-Script" ) function UpdateHelpFromLocalContentPath { From a9ae2a2ed6268ef12e390d36de8f8f83e9e6efc7 Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 29 Sep 2020 11:30:36 +0500 Subject: [PATCH 10/25] Add runspace and parent scriptblock Ids in perf event --- .../engine/debugger/debugger.cs | 14 +++ .../engine/parser/Compiler.cs | 6 +- .../engine/runtime/Profiler.cs | 91 ++++++++++++++++--- 3 files changed, 95 insertions(+), 16 deletions(-) diff --git a/src/System.Management.Automation/engine/debugger/debugger.cs b/src/System.Management.Automation/engine/debugger/debugger.cs index e8e8c849442..83ce239979d 100644 --- a/src/System.Management.Automation/engine/debugger/debugger.cs +++ b/src/System.Management.Automation/engine/debugger/debugger.cs @@ -1232,6 +1232,20 @@ internal void RegisterScriptFile(string path, string scriptContents) } } + internal Guid GetParentScriptBlockId() + { + if (_callStack.Count > 1) + { + var scriptBlock = _callStack[_callStack.Count - 2].FunctionContext._scriptBlock; + if (scriptBlock is not null) + { + return scriptBlock.Id; + } + } + + return Guid.Empty; + } + #endregion Call stack management #region setting breakpoints diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index 62e5d9c8d69..e76c3150391 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -815,7 +815,11 @@ internal void UpdatePositionNoBreak(int pos) if (ProfilerEventSource.LogInstance.IsEnabled()) { - ProfilerEventSource.LogInstance.SequencePoint(_scriptBlock.Id, pos); + ProfilerEventSource.LogInstance.SequencePoint( + _scriptBlock.Id, + _scriptBlock.SessionStateInternal.ExecutionContext.CurrentRunspace.InstanceId, + _executionContext.Debugger.GetParentScriptBlockId(), + pos); } } diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 5be556cbf48..35c2832d3c0 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -19,7 +19,7 @@ internal class ProfilerEventSource : EventSource internal static ProfilerEventSource LogInstance = new ProfilerEventSource(); [Event(1)] - public void SequencePoint(Guid ScriptBlockId, int SequencePointPosition) + public void SequencePoint(Guid scriptBlockId, Guid runspaceInstanceId, Guid parentScriptBlockId, int sequencePointPosition) { // We could use: // WriteEvent(eventId: 1, ScriptBlockId, SequencePointPosition); @@ -28,20 +28,30 @@ public void SequencePoint(Guid ScriptBlockId, int SequencePointPosition) { unsafe { - EventData* eventPayload = stackalloc EventData[2]; + EventData* eventPayload = stackalloc EventData[4]; eventPayload[0] = new EventData { Size = sizeof(Guid), - DataPointer = ((IntPtr)(&ScriptBlockId)) + DataPointer = ((IntPtr)(&scriptBlockId)) }; eventPayload[1] = new EventData + { + Size = sizeof(Guid), + DataPointer = ((IntPtr)(&runspaceInstanceId)) + }; + eventPayload[2] = new EventData + { + Size = sizeof(Guid), + DataPointer = ((IntPtr)(&parentScriptBlockId)) + }; + eventPayload[3] = new EventData { Size = sizeof(int), - DataPointer = ((IntPtr)(&SequencePointPosition)) + DataPointer = ((IntPtr)(&sequencePointPosition)) }; - WriteEventCore(eventId: 1, eventDataCount: 2, eventPayload); + WriteEventCore(eventId: 1, eventDataCount: 4, eventPayload); } } } @@ -232,6 +242,16 @@ internal struct SequencePointProfileEventData /// public Guid ScriptId; + /// + /// Unique identifer of the runspace. + /// + public Guid RunspaceId; + + /// + /// Unique identifer of the parent script block. + /// + public Guid ParentScriptBlockId; + /// /// SequencePoint index number/position of the script block. /// @@ -285,7 +305,9 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) { Timestamp = eventData.TimeStamp, ScriptId = (Guid)payload[0]!, - SequencePointPosition = (int)payload[1]! + RunspaceId = (Guid)payload[1]!, + ParentScriptBlockId = (Guid)payload[2]!, + SequencePointPosition = (int)payload[3]! }); break; case 2: @@ -401,21 +423,60 @@ protected override void EndProcessing() for (var i = 0; i < events.Count - 1; i++) { - var profileDate = events[i]; - if (metaData.TryGetValue(profileDate.ScriptId, out var compiledScriptBlockData)) + var profileData = events[i]; + if (metaData.TryGetValue(profileData.ScriptId, out var compiledScriptBlockData)) { - var extent = compiledScriptBlockData.SequencePoints[profileDate.SequencePointPosition]; - - PSObject result = new PSObject(); - result.Properties.Add(new PSNoteProperty("TimeStamp", profileDate.Timestamp.TimeOfDay)); - result.Properties.Add(new PSNoteProperty("Duration", events[i + 1].Timestamp - profileDate.Timestamp)); - result.Properties.Add(new PSNoteProperty("ExtentText", extent.Text)); - result.Properties.Add(new PSNoteProperty("Extent", extent)); + var extent = compiledScriptBlockData.SequencePoints[profileData.SequencePointPosition]; + var result = new ProfileEventRecord + { + StartTime = profileData.Timestamp.TimeOfDay, + Duration = events[i + 1].Timestamp - profileData.Timestamp, + Source = extent.Text, + Extent = extent, + RunspaceId = profileData.RunspaceId, + ParentScriptBlockId = profileData.ParentScriptBlockId + }; WriteObject(result); } } } } + + /// + /// Measure-ScriptBlock output type. + /// + internal struct ProfileEventRecord + { + /// + /// StartTime of event. + /// + public TimeSpan StartTime; + + /// + /// Duration of event. + /// + public TimeSpan Duration; + + /// + /// Script text. + /// + public string Source; + + /// + /// Script Extent. + /// + public ScriptExtentEventData Extent; + + /// + /// Unique identifer of the runspace. + /// + public Guid RunspaceId; + + /// + /// Unique identifer of the parent script block. + /// + public Guid ParentScriptBlockId; + } } } From 7c631e432c21e073872cedacc0f712a63fd0d54c Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 29 Sep 2020 11:41:37 +0500 Subject: [PATCH 11/25] Add Start Opcode --- src/System.Management.Automation/engine/runtime/Profiler.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 35c2832d3c0..f3efd9caafd 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -18,7 +18,7 @@ internal class ProfilerEventSource : EventSource { internal static ProfilerEventSource LogInstance = new ProfilerEventSource(); - [Event(1)] + [Event(1, Opcode = EventOpcode.Start, ActivityOptions = EventActivityOptions.Recursive)] public void SequencePoint(Guid scriptBlockId, Guid runspaceInstanceId, Guid parentScriptBlockId, int sequencePointPosition) { // We could use: @@ -372,6 +372,7 @@ public void DisableEvents() /// The cmdlet profiles a script block. /// [Cmdlet(VerbsDiagnostic.Measure, "Script", HelpUri = "", RemotingCapability = RemotingCapability.None)] + [OutputType(typeof(ProfileEventRecord))] public class MeasureScriptCommand : PSCmdlet { /// From f8ef7a4ebc9b1d113afab308dd81caa7a156d8a8 Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 29 Sep 2020 20:18:28 +0500 Subject: [PATCH 12/25] Add ScriptBlockId to output --- .../engine/runtime/Profiler.cs | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index f3efd9caafd..02d2c51161e 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -435,7 +435,8 @@ protected override void EndProcessing() Source = extent.Text, Extent = extent, RunspaceId = profileData.RunspaceId, - ParentScriptBlockId = profileData.ParentScriptBlockId + ParentScriptBlockId = profileData.ParentScriptBlockId, + ScriptBlockId = profileData.ScriptId }; WriteObject(result); @@ -478,6 +479,11 @@ internal struct ProfileEventRecord /// Unique identifer of the parent script block. /// public Guid ParentScriptBlockId; + + /// + /// Unique identifer of the script block. + /// + public Guid ScriptBlockId; } } } From dc344ef64a5f280678d852e8f5d1921a33a40301 Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 29 Sep 2020 20:32:28 +0500 Subject: [PATCH 13/25] Get correct parent id --- .../engine/debugger/debugger.cs | 11 ++++++++--- .../engine/parser/Compiler.cs | 6 +++--- 2 files changed, 11 insertions(+), 6 deletions(-) diff --git a/src/System.Management.Automation/engine/debugger/debugger.cs b/src/System.Management.Automation/engine/debugger/debugger.cs index 83ce239979d..3defa54017a 100644 --- a/src/System.Management.Automation/engine/debugger/debugger.cs +++ b/src/System.Management.Automation/engine/debugger/debugger.cs @@ -1232,11 +1232,16 @@ internal void RegisterScriptFile(string path, string scriptContents) } } - internal Guid GetParentScriptBlockId() + internal Guid GetParentScriptBlockId(int sequencePointPosition) { - if (_callStack.Count > 1) + // Sequence point on 0 position is an entry point in a scriptblock. + // In the time the callstack has still point to parent scriptblock + // so we take last element from the callstack, + // for rest sequence points we take an element before last as parent. + int shift = sequencePointPosition == 0 ? 1 : 2; + if (_callStack.Count - shift > 0) { - var scriptBlock = _callStack[_callStack.Count - 2].FunctionContext._scriptBlock; + var scriptBlock = _callStack[_callStack.Count - shift].FunctionContext._scriptBlock; if (scriptBlock is not null) { return scriptBlock.Id; diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index e76c3150391..5f2359d84f2 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -816,9 +816,9 @@ internal void UpdatePositionNoBreak(int pos) if (ProfilerEventSource.LogInstance.IsEnabled()) { ProfilerEventSource.LogInstance.SequencePoint( - _scriptBlock.Id, - _scriptBlock.SessionStateInternal.ExecutionContext.CurrentRunspace.InstanceId, - _executionContext.Debugger.GetParentScriptBlockId(), + _scriptBlock is not null ? _scriptBlock.Id : Guid.Empty, + _executionContext.CurrentRunspace.InstanceId, + _executionContext.Debugger.GetParentScriptBlockId(pos), pos); } } From 2f84f19dad1b91546ed311fa140467ae6529b0c3 Mon Sep 17 00:00:00 2001 From: Ilya Date: Wed, 30 Sep 2020 12:13:38 +0500 Subject: [PATCH 14/25] Add tracking default parameter expressions --- .../engine/debugger/debugger.cs | 2 +- .../engine/parser/Compiler.cs | 19 +++++++++++++++++-- 2 files changed, 18 insertions(+), 3 deletions(-) diff --git a/src/System.Management.Automation/engine/debugger/debugger.cs b/src/System.Management.Automation/engine/debugger/debugger.cs index 3defa54017a..27d70233a2a 100644 --- a/src/System.Management.Automation/engine/debugger/debugger.cs +++ b/src/System.Management.Automation/engine/debugger/debugger.cs @@ -1239,7 +1239,7 @@ internal Guid GetParentScriptBlockId(int sequencePointPosition) // so we take last element from the callstack, // for rest sequence points we take an element before last as parent. int shift = sequencePointPosition == 0 ? 1 : 2; - if (_callStack.Count - shift > 0) + if (_callStack.Count - shift >= 0) { var scriptBlock = _callStack[_callStack.Count - shift].FunctionContext._scriptBlock; if (scriptBlock is not null) diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index 5f2359d84f2..896fd83e9fc 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -819,7 +819,7 @@ internal void UpdatePositionNoBreak(int pos) _scriptBlock is not null ? _scriptBlock.Id : Guid.Empty, _executionContext.CurrentRunspace.InstanceId, _executionContext.Debugger.GetParentScriptBlockId(pos), - pos); + pos); } } @@ -2174,13 +2174,28 @@ private static object GetExpressionValue( var pipe = new Pipe(resultList); try { + ScriptBlock scriptBlock = null; + if (ProfilerEventSource.LogInstance.IsEnabled()) + { + // We need a scriptblock Id to keep track of the call stack. + scriptBlock = ScriptBlock.Create(context, expressionAst.Extent.Text); + + // No need to optimize - we only want to add to the scriptblock cache + // so that we can get rundown events. + // We can safely do this because lambda and sequencePoints + // parameters of the method come always from callsites as null. + // (We could remove them at all.) + scriptBlock.Compile(optimized: false); + } + var functionContext = new FunctionContext { _sequencePoints = sequencePoints, _executionContext = context, _file = expressionAst.Extent.File, _outputPipe = pipe, - _localsTuple = MutableTuple.MakeTuple(localsTupleType, DottedLocalsNameIndexMap) + _localsTuple = MutableTuple.MakeTuple(localsTupleType, DottedLocalsNameIndexMap), + _scriptBlock = scriptBlock }; if (usingValues != null) { From 03ff23483a437a8c2da1f2a31494a41ac6eadb1e Mon Sep 17 00:00:00 2001 From: Ilya Date: Wed, 30 Sep 2020 12:16:02 +0500 Subject: [PATCH 15/25] Avoid lock if scriptblock is already compiled --- .../engine/runtime/CompiledScriptBlock.cs | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index 4bc917f810c..d4ee97e80e6 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -164,6 +164,11 @@ private void InitializeMetadata() private void CompileUnoptimized() { + if (_compiledUnoptimized) + { + return; + } + lock (this) { if (_compiledUnoptimized) @@ -179,6 +184,11 @@ private void CompileUnoptimized() private void CompileOptimized() { + if (_compiledOptimized) + { + return; + } + lock (this) { if (_compiledOptimized) From a7d6abbde8768684b836f06be8dd288bff5edfcf Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 13 Oct 2020 20:43:47 +0500 Subject: [PATCH 16/25] Add support runspaces to Measure-ScriptBlock --- .../engine/runtime/Profiler.cs | 62 +++++++++++++++---- 1 file changed, 49 insertions(+), 13 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 02d2c51161e..a85e7e2560d 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -414,29 +414,65 @@ protected override void EndProcessing() var metaData = profiler.CompiledScriptBlockMetaData; - // We have only start timestamp for sequence point. + // 1. We have only start timestamp for a sequence point. // To evaluate a duration of the sequence point // we take a start timestamp from next sequence point // that is actually a stop timestamp for the previous sequence point. - // For last sequence point we have not next timestamp - // so we add a copy of the last sequence point as a workaround. - events.Add(events[events.Count - 1]); + // + // 2. We handle events separately for each runspace. + // + // 3. Last event of every runspace we output as-is + // without evaluating a duration because we have not a stop event. + // + Dictionary runspaceCurrentEvent = new(); + + for (var i = 0; i < events.Count; i++) + { + var nextEvent = events[i]; + + if (runspaceCurrentEvent.TryGetValue(nextEvent.RunspaceId, out var currentEvent)) + { + runspaceCurrentEvent[nextEvent.RunspaceId] = nextEvent; + } + else + { + // It is first event in the runspace. + runspaceCurrentEvent.Add(nextEvent.RunspaceId, nextEvent); + continue; + } + + if (metaData.TryGetValue(currentEvent.ScriptId, out var compiledScriptBlockData)) + { + var extent = compiledScriptBlockData.SequencePoints[currentEvent.SequencePointPosition]; + var result = new ProfileEventRecord + { + StartTime = currentEvent.Timestamp.TimeOfDay, + Duration = nextEvent.Timestamp - currentEvent.Timestamp, + Source = extent.Text, + Extent = extent, + RunspaceId = currentEvent.RunspaceId, + ParentScriptBlockId = currentEvent.ParentScriptBlockId, + ScriptBlockId = currentEvent.ScriptId + }; + + WriteObject(result); + } + } - for (var i = 0; i < events.Count - 1; i++) + foreach (var currentEvent in runspaceCurrentEvent.Values) { - var profileData = events[i]; - if (metaData.TryGetValue(profileData.ScriptId, out var compiledScriptBlockData)) + if (metaData.TryGetValue(currentEvent.ScriptId, out var compiledScriptBlockData)) { - var extent = compiledScriptBlockData.SequencePoints[profileData.SequencePointPosition]; + var extent = compiledScriptBlockData.SequencePoints[currentEvent.SequencePointPosition]; var result = new ProfileEventRecord { - StartTime = profileData.Timestamp.TimeOfDay, - Duration = events[i + 1].Timestamp - profileData.Timestamp, + StartTime = currentEvent.Timestamp.TimeOfDay, + Duration = TimeSpan.Zero, Source = extent.Text, Extent = extent, - RunspaceId = profileData.RunspaceId, - ParentScriptBlockId = profileData.ParentScriptBlockId, - ScriptBlockId = profileData.ScriptId + RunspaceId = currentEvent.RunspaceId, + ParentScriptBlockId = currentEvent.ParentScriptBlockId, + ScriptBlockId = currentEvent.ScriptId }; WriteObject(result); From 8899bb6f0bff870598d378a796b29c63efdf27de Mon Sep 17 00:00:00 2001 From: Ilya Date: Tue, 16 Feb 2021 23:33:28 +0500 Subject: [PATCH 17/25] Address Robert's feedback --- .../engine/ExternalScriptInfo.cs | 4 +++- .../engine/debugger/debugger.cs | 2 +- src/System.Management.Automation/engine/parser/Compiler.cs | 2 +- .../engine/runtime/CompiledScriptBlock.cs | 6 +++--- 4 files changed, 8 insertions(+), 6 deletions(-) diff --git a/src/System.Management.Automation/engine/ExternalScriptInfo.cs b/src/System.Management.Automation/engine/ExternalScriptInfo.cs index 79992d0c276..9f817bb8bdb 100644 --- a/src/System.Management.Automation/engine/ExternalScriptInfo.cs +++ b/src/System.Management.Automation/engine/ExternalScriptInfo.cs @@ -189,7 +189,9 @@ public override SessionStateEntryVisibility Visibility get { if (Context == null) + { return SessionStateEntryVisibility.Public; + } return Context.EngineSessionState.CheckScriptVisibility(_path); } @@ -268,7 +270,7 @@ internal ScriptBlockAst GetScriptBlockAst() var scriptContents = ScriptContents; if (_scriptBlock == null) { - var compiledScriptBlockData = ScriptBlock.TryGetCompiledCachedScriptBlock(_path, scriptContents); + CompiledScriptBlockData compiledScriptBlockData = ScriptBlock.TryGetCachedCompiledScriptBlock(_path, scriptContents); if (compiledScriptBlockData != null) { this.ScriptBlock = new ScriptBlock(compiledScriptBlockData); diff --git a/src/System.Management.Automation/engine/debugger/debugger.cs b/src/System.Management.Automation/engine/debugger/debugger.cs index 27d70233a2a..3c18ac996f7 100644 --- a/src/System.Management.Automation/engine/debugger/debugger.cs +++ b/src/System.Management.Automation/engine/debugger/debugger.cs @@ -1241,7 +1241,7 @@ internal Guid GetParentScriptBlockId(int sequencePointPosition) int shift = sequencePointPosition == 0 ? 1 : 2; if (_callStack.Count - shift >= 0) { - var scriptBlock = _callStack[_callStack.Count - shift].FunctionContext._scriptBlock; + ScriptBlock scriptBlock = _callStack[_callStack.Count - shift].FunctionContext._scriptBlock; if (scriptBlock is not null) { return scriptBlock.Id; diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index 896fd83e9fc..cfb07e363a4 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -7099,7 +7099,7 @@ public override Expression Reduce() exprs.Add(Expression.DebugInfo(_debugSymbolDocument, _extent.StartLineNumber, _extent.StartColumnNumber, _extent.EndLineNumber, _extent.EndColumnNumber)); } - var method = _checkBreakpoints + MethodInfo method = _checkBreakpoints ? CachedReflectionInfo.FunctionContext_UpdatePosition : CachedReflectionInfo.FunctionContext_UpdatePositionNoBreak; exprs.Add(Expression.Call(Compiler.s_functionContext, method, ExpressionCache.Constant(_sequencePoint))); diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index d4ee97e80e6..adbeefd293c 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -56,7 +56,7 @@ internal static void InitCompiledScriptBlockTable() { ClearCompiledScriptBlockTable(); - foreach (var csb in ScriptBlock.GetCachedCompiledScriptBlockData()) + foreach (CompiledScriptBlockData csb in ScriptBlock.GetCachedCompiledScriptBlockData()) { s_compiledScriptBlockTable.TryAdd(csb, csb); } @@ -627,7 +627,7 @@ internal static ICollection GetCachedCompiledScriptBloc return s_cachedScripts.Values; } - internal static CompiledScriptBlockData TryGetCompiledCachedScriptBlock(string fileName, string fileContents) + internal static CompiledScriptBlockData TryGetCachedCompiledScriptBlock(string fileName, string fileContents) { if (InternalTestHooks.IgnoreScriptBlockCache) { @@ -684,7 +684,7 @@ internal static void CacheCompiledScriptBlock(ScriptBlock scriptBlock, string fi internal static ScriptBlock Create(Parser parser, string fileName, string fileContents) { - var compiledScriptBlockData = TryGetCompiledCachedScriptBlock(fileName, fileContents); + var compiledScriptBlockData = TryGetCachedCompiledScriptBlock(fileName, fileContents); if (compiledScriptBlockData != null) { return new ScriptBlock(compiledScriptBlockData); From 483b2ea21dafca63b86c12c2330c67ada87719a4 Mon Sep 17 00:00:00 2001 From: Ilya Date: Wed, 24 Mar 2021 23:11:05 +0500 Subject: [PATCH 18/25] Make file parameter nullable --- src/System.Management.Automation/engine/runtime/Profiler.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index a85e7e2560d..28f6286b471 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -94,7 +94,7 @@ public void SequencePointRundown( Guid ScriptBlockId, int SequencePointCount, int SequencePoint, - string File, + string? File, int StartLineNumber, int StartColumnNumber, int EndLineNumber, From 9bdc7630220187d3ba1f4ce20a248fda259fa58c Mon Sep 17 00:00:00 2001 From: Ilya Date: Wed, 24 Mar 2021 23:57:29 +0500 Subject: [PATCH 19/25] Fix style issues --- .../engine/runtime/Profiler.cs | 57 ++++++++++--------- 1 file changed, 29 insertions(+), 28 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 28f6286b471..4ea106b3682 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -33,22 +33,22 @@ public void SequencePoint(Guid scriptBlockId, Guid runspaceInstanceId, Guid pare eventPayload[0] = new EventData { Size = sizeof(Guid), - DataPointer = ((IntPtr)(&scriptBlockId)) + DataPointer = (IntPtr)(&scriptBlockId) }; eventPayload[1] = new EventData { Size = sizeof(Guid), - DataPointer = ((IntPtr)(&runspaceInstanceId)) + DataPointer = (IntPtr)(&runspaceInstanceId) }; eventPayload[2] = new EventData { Size = sizeof(Guid), - DataPointer = ((IntPtr)(&parentScriptBlockId)) + DataPointer = (IntPtr)(&parentScriptBlockId) }; eventPayload[3] = new EventData { Size = sizeof(int), - DataPointer = ((IntPtr)(&sequencePointPosition)) + DataPointer = (IntPtr)(&sequencePointPosition) }; WriteEventCore(eventId: 1, eventDataCount: 4, eventPayload); @@ -91,32 +91,32 @@ public void ScriptBlockRundown( [Event(3)] public void SequencePointRundown( - Guid ScriptBlockId, - int SequencePointCount, - int SequencePoint, - string? File, - int StartLineNumber, - int StartColumnNumber, - int EndLineNumber, - int EndColumnNumber, - string Text, - int StartOffset, - int EndOffset) + Guid scriptBlockId, + int sequencePointCount, + int sequencePoint, + string? file, + int startLineNumber, + int startColumnNumber, + int endLineNumber, + int endColumnNumber, + string text, + int startOffset, + int endOffset) { // It is not performance critical so we use the standard method overload. WriteEvent( eventId: 3, - ScriptBlockId, - SequencePointCount, - SequencePoint, - File, - StartLineNumber, - StartColumnNumber, - EndLineNumber, - EndColumnNumber, - Text, - StartOffset, - EndOffset); + scriptBlockId, + sequencePointCount, + sequencePoint, + file, + startLineNumber, + startColumnNumber, + endLineNumber, + endColumnNumber, + text, + startOffset, + endOffset); } [NonEvent] @@ -345,6 +345,7 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) CompiledScriptBlockMetaData.TryAdd(sbe.ScriptId, sbe); } + break; } } @@ -376,7 +377,7 @@ public void DisableEvents() public class MeasureScriptCommand : PSCmdlet { /// - /// A script block to profile. + /// Gets or sets a script block to profile. /// [Parameter(Position = 0, Mandatory = true)] public ScriptBlock ScriptBlock { get; set; } = null!; @@ -423,7 +424,7 @@ protected override void EndProcessing() // // 3. Last event of every runspace we output as-is // without evaluating a duration because we have not a stop event. - // + // --------------------------------------------------------------- Dictionary runspaceCurrentEvent = new(); for (var i = 0; i < events.Count; i++) From 4867a4501dd82ce6f9cf53b94ad0ed2c240dc275 Mon Sep 17 00:00:00 2001 From: Ilya Date: Thu, 25 Mar 2021 08:01:43 +0500 Subject: [PATCH 20/25] Fix style issues 2 --- .../engine/runtime/Profiler.cs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 4ea106b3682..2ceeefca457 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -79,14 +79,14 @@ internal class ProfilerRundownEventSource : EventSource [Event(2)] public void ScriptBlockRundown( - Guid ScriptBlockId, - string ScriptBlockText) + Guid scriptBlockId, + string scriptBlockText) { // It is not performance critical so we use the standard method overload. WriteEvent( eventId: 2, - ScriptBlockId, - ScriptBlockText); + scriptBlockId, + scriptBlockText); } [Event(3)] From 3d260baef01785c413a805345ce0eeba5efc3746 Mon Sep 17 00:00:00 2001 From: Ilya Date: Thu, 25 Mar 2021 18:33:28 +0500 Subject: [PATCH 21/25] Experiment with UpdatePosition() --- .../engine/parser/Compiler.cs | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index cfb07e363a4..d1ff134a0db 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -1172,9 +1172,12 @@ private Expression UpdatePosition(Ast ast) // in EnterScriptFunction. // Except for while/do loops, in this case we want to check breakpoints on the first sequence point since it // will be executed multiple times. - return (index == 0 && !_generatingWhileOrDoLoop) - ? ExpressionCache.Empty - : new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression); + //return (index == 0 && !_generatingWhileOrDoLoop) + // ? ExpressionCache.Empty + // : new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression); + return _generatingWhileOrDoLoop + ? new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression) + : new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression); } private int _tempCounter; From 04bcd4c01c5638d0992e6f68207f14ea186c7cd1 Mon Sep 17 00:00:00 2001 From: Ilya Date: Fri, 26 Mar 2021 09:02:15 +0500 Subject: [PATCH 22/25] Revert "Experiment with UpdatePosition()" This reverts commit a26f3c5c8c868b95e5dfd3098cbe682dacb98a73. --- .../engine/parser/Compiler.cs | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index d1ff134a0db..cfb07e363a4 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -1172,12 +1172,9 @@ private Expression UpdatePosition(Ast ast) // in EnterScriptFunction. // Except for while/do loops, in this case we want to check breakpoints on the first sequence point since it // will be executed multiple times. - //return (index == 0 && !_generatingWhileOrDoLoop) - // ? ExpressionCache.Empty - // : new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression); - return _generatingWhileOrDoLoop - ? new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression) - : new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression); + return (index == 0 && !_generatingWhileOrDoLoop) + ? ExpressionCache.Empty + : new UpdatePositionExpr(extent, index, _debugSymbolDocument, !_compilingSingleExpression); } private int _tempCounter; From ffdfc911a99a8929cf7c17ddcb5938286bdc1c43 Mon Sep 17 00:00:00 2001 From: Ilya Date: Fri, 26 Mar 2021 10:13:35 +0500 Subject: [PATCH 23/25] Add profiling in EnterScriptFunction() --- .../engine/debugger/debugger.cs | 10 ++++++++++ .../engine/parser/Compiler.cs | 2 +- 2 files changed, 11 insertions(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/debugger/debugger.cs b/src/System.Management.Automation/engine/debugger/debugger.cs index 3c18ac996f7..418d1d4d7e5 100644 --- a/src/System.Management.Automation/engine/debugger/debugger.cs +++ b/src/System.Management.Automation/engine/debugger/debugger.cs @@ -1135,6 +1135,16 @@ internal void EnterScriptFunction(FunctionContext functionContext) Diagnostics.Assert(functionContext._executionContext == _context, "Wrong debugger is being used."); var invocationInfo = (InvocationInfo)functionContext._localsTuple.GetAutomaticVariable(AutomaticVariable.MyInvocation); + + if (ProfilerEventSource.LogInstance.IsEnabled()) + { + ProfilerEventSource.LogInstance.SequencePoint( + functionContext._scriptBlock?.Id ?? Guid.Empty, + functionContext._executionContext.CurrentRunspace.InstanceId, + _callStack.Last()?.FunctionContext._scriptBlock.Id ?? Guid.Empty, + 0); + } + var newCallStackInfo = new CallStackInfo { InvocationInfo = invocationInfo, diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index cfb07e363a4..3d96b59510a 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -816,7 +816,7 @@ internal void UpdatePositionNoBreak(int pos) if (ProfilerEventSource.LogInstance.IsEnabled()) { ProfilerEventSource.LogInstance.SequencePoint( - _scriptBlock is not null ? _scriptBlock.Id : Guid.Empty, + _scriptBlock?.Id ?? Guid.Empty, _executionContext.CurrentRunspace.InstanceId, _executionContext.Debugger.GetParentScriptBlockId(pos), pos); From 83b72d3c58d30c3e463a2371f5af4c6e7aee6ae1 Mon Sep 17 00:00:00 2001 From: Ilya Date: Mon, 29 Mar 2021 23:45:30 +0500 Subject: [PATCH 24/25] Move logging to UpdatePosition() --- .../engine/parser/Compiler.cs | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index 3d96b59510a..3b79ee406d6 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -812,6 +812,11 @@ internal void PopTrapHandlers() internal void UpdatePositionNoBreak(int pos) { _currentSequencePointIndex = pos; + } + + internal void UpdatePosition(int pos) + { + UpdatePositionNoBreak(pos); if (ProfilerEventSource.LogInstance.IsEnabled()) { @@ -821,11 +826,7 @@ internal void UpdatePositionNoBreak(int pos) _executionContext.Debugger.GetParentScriptBlockId(pos), pos); } - } - internal void UpdatePosition(int pos) - { - UpdatePositionNoBreak(pos); if (_executionContext._debuggingMode > 0) { _executionContext.Debugger.OnSequencePointHit(this); From bf38033a546e38dc91d4c85a4748de2b896da771 Mon Sep 17 00:00:00 2001 From: Steve Lee Date: Mon, 23 May 2022 10:07:13 -0700 Subject: [PATCH 25/25] add temp URI to get it to build --- src/System.Management.Automation/engine/runtime/Profiler.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/System.Management.Automation/engine/runtime/Profiler.cs b/src/System.Management.Automation/engine/runtime/Profiler.cs index 2ceeefca457..4345ed3ebde 100644 --- a/src/System.Management.Automation/engine/runtime/Profiler.cs +++ b/src/System.Management.Automation/engine/runtime/Profiler.cs @@ -372,7 +372,7 @@ public void DisableEvents() /// /// The cmdlet profiles a script block. /// - [Cmdlet(VerbsDiagnostic.Measure, "Script", HelpUri = "", RemotingCapability = RemotingCapability.None)] + [Cmdlet(VerbsDiagnostic.Measure, "Script", HelpUri = "https://go.microsoft.com/fwlink/?LinkId=", RemotingCapability = RemotingCapability.None)] [OutputType(typeof(ProfileEventRecord))] public class MeasureScriptCommand : PSCmdlet {