chronometer.psm1
|
$Script:PSModuleRoot = $PSScriptRoot # .C:\projects\chronometer\chronometer\Classes\MonitoredScript.ps1 class MonitoredScript { [string]$Path [System.Collections.Generic.List[ScriptLine]]$Line hidden $lastNode = $null hidden $lastRecord = $null [timespan]$ExecutionTime = [timespan]::Zero [int]$LinesOfCode = 0 MonitoredScript() { $this.Line = New-Object 'System.Collections.Generic.List[ScriptLine]' } [int] SetScript([string]$Path) { $lineNumber = 0 foreach ( $command in ( Get-Content -Path $Path ) ) { $this.Line.Add( [ScriptLine]::New($command, $path, $lineNumber) ) $lineNumber++ } $this.LinesOfCode = $this.Line.Count return $this.LinesOfCode } [void] AddExecution( [hashtable]$node ) { # Line numbers start at 1 but the array starts at 0 $lineNumber = $node.Breakpoint.Line - 1 $record = $this.Line[$lineNumber] $record.AddExecution($node) # Calclate the delta in time if ( $this.lastNode ) { $duration = $node.Elapsed - $this.lastNode.Elapsed } else { $duration = $node.Elapsed } # The delta is how long the last command ran if ( $this.lastRecord ) { $this.lastRecord.AddExecutionTime($duration) $this.ExecutionTime += $duration } $this.lastRecord = $record $this.lastNode = $node } [void] PostProcessing() { $this.lastNode = $null $this.ExecutionTime = [TimeSpan]::Zero foreach ( $node in $this.line ) { $command = $node.text -replace '\s', '' switch -Regex ( $command ) { '^}$|^}#|^$' { if ( $node.HitCount -eq 0 ) { $node.HitCount = $this.lastNode.HitCount } $node.Duration = [TimeSpan]::Zero $node.Average = 0 $this.lastNode = $node } '^{$|^{#}' { $node.Duration = [TimeSpan]::Zero $node.Average = 0 $this.lastNode = $node } default { $this.lastNode = $node } } $this.ExecutionTime += $node.Duration } } } # .C:\projects\chronometer\chronometer\Classes\ScriptProfiler.ps1 class ScriptProfiler { static [System.Collections.Queue] $Queue static [System.Diagnostics.Stopwatch] $Timer static $LastNode = $null static [void] Start() { [ScriptProfiler]::Queue = New-Object System.Collections.Queue [ScriptProfiler]::Timer = [System.Diagnostics.Stopwatch]::StartNew() } static [void] RecordExecution ([System.Management.Automation.LineBreakpoint]$InputObject) { [ScriptProfiler]::Queue.Enqueue(@{ Breakpoint = $InputObject Elapsed = [ScriptProfiler]::Timer.Elapsed }) [ScriptProfiler]::LastNode = $InputObject } } # .C:\projects\chronometer\chronometer\Classes\Chronometer.ps1 class Chronometer { [hashtable]$FileMap = @{} $Breakpoint = @() [void]AddBreakpoint([string[]]$Path, [int[]]$LineNumber) { if (-not [string]::IsNullOrEmpty($Path)) { foreach ($file in (Resolve-Path $Path -ea 0)) { $script = [MonitoredScript]@{Path = $file.Path} $lines = $script.SetScript($file) if ( $null -ne $LineNumber ) { $bpLine = $LineNumber } else { $bpLine = (1..$lines) } $this.fileMap[$file.Path] = $script $breakpointParam = @{ Script = $file Line = $bpLine Action = { [ScriptProfiler]::RecordExecution( $_) } } $this.breakPoint += Set-PSBreakpoint @breakpointParam } } } [void]ClearBreakpoint() { if ( $null -ne $this.Breakpoint -and $this.Breakpoint.count -gt 0 ) { Remove-PSBreakpoint -Breakpoint $this.Breakpoint } } [void] AddExecution([hashtable]$Execution) { $script = $Execution.Breakpoint.Script if ( $this.FileMap.ContainsKey($script) ) { # Each script tracks it's own execution times $this.FileMap[$script].AddExecution($Execution) } } [MonitoredScript[]] GetResults() { foreach ( $node in $this.FileMap.Values ) { $node.PostProcessing() } return $this.FileMap.Values } } # .C:\projects\chronometer\chronometer\Classes\ScriptLine.ps1 class ScriptLine { [TimeSpan] $Duration = 0 [float] $HitCount = 0 [TimeSpan] $Min = [TimeSpan]::MaxValue [TimeSpan] $Max = [TimeSpan]::MinValue [float] $Average = 0 [int] $LineNumber [string] $Path [string] $Text [System.Collections.ArrayList]$Executions hidden [hashtable]$LastNode = @{} ScriptLine() { $this.Executions = New-Object 'System.Collections.ArrayList' } ScriptLine($Command, $Path, $LineNumber) { $this.Executions = New-Object 'System.Collections.ArrayList' $this.Text = $Command $this.Path = $Path $this.LineNumber = $LineNumber } [void]AddExecutionTime([timespan]$Duration) { $this.LastNode.Duration = $Duration $this.Duration += $Duration $this.HitCount += 1 $this.Average = $this.Duration.TotalMilliseconds / $this.HitCount if ( $Duration -lt $this.Min ) { $this.Min = $Duration } if ( $Duration -gt $this.Max ) { $this.Max = $Duration } } [void] AddExecution([hashtable]$node) { $this.Executions.Add($node) $this.LastNode = $node } [void] Clear() { $this.Duration = [timespan]::Zero $this.HitCount = 0 $this.Average = 0 $this.LastNode = $null $this.Executions.Clear() } [string] ToString() { $values = @( $this.Duration.TotalMilliseconds $this.HitCount $this.Average $this.LineNumber $this.Text ) return ("[{0:0000}ms,{1:000},{2:000}ms] {3,4}:{4}" -f $values) } } # Importing from [C:\projects\chronometer\chronometer\Private] # .\chronometer\Private\Write-ScriptLine.ps1 function Write-ScriptLine { [Diagnostics.CodeAnalysis.SuppressMessageAttribute("PSAvoidUsingWriteHost", "")] [cmdletbinding()] param( [scriptline] $line, $WarningAt = [int]::MaxValue, $ErrorAt = [int]::MaxValue ) if ( $line ) { $Color = 'Green' if ( $line.HitCount -eq 0 ) { $Color = 'Gray' } elseif ( $line.Average -ge $ErrorAt ) { $Color = 'Red' } elseif ( $line.Average -ge $WarningAt ) { $Color = 'Yellow' } Write-Host $line.toString() -ForegroundColor $Color } } # Importing from [C:\projects\chronometer\chronometer\Public] # .\chronometer\Public\Format-Chronometer.ps1 function Format-Chronometer { <# .Description Generates a report from a Chronometer .Example $script = ls C:\workspace\PSGraph\PSGraph -Recurse -Filter *.ps1 $resultes = Get-Chronometer -Path $script.fullname -ScriptBlock {Invoke-Pester C:\workspace\PSGraph} $results | Format-Chronometer -WarnAt 20 -ErrorAt 200 #> [Diagnostics.CodeAnalysis.SuppressMessageAttribute("PSAvoidUsingWriteHost", "")] [cmdletbinding(DefaultParameterSetName = 'Script')] param( # This is a MonitoredScript object from Get-Chronometer [Parameter( ValueFromPipeline = $true, ParameterSetName = 'Script' )] [MonitoredScript[]] $InputObject, # This is a ScriptLine object from a MonitoredScript object [Parameter( ValueFromPipeline = $true, ParameterSetName = 'Line' )] [ScriptLine[]] $Line, # If the average time of a command is more than this, the output is yellow [int] $WarningAt = 20, #If the average time of a comamand is more than this, the output is red [int] $ErrorAt = 200, # Forces the report to show scripts with no execution time [switch] $ShowAll ) process { try { foreach ( $script in $InputObject ) { if ( $script.ExecutionTime -ne [TimeSpan]::Zero -or $ShowAll ) { Write-Host '' Write-Host "Script: $($script.Path)" -ForegroundColor Green Write-Host "Execution Time: $($script.ExecutionTime)" -ForegroundColor Green $script.line | Format-Chronometer -WarningAt $WarningAt -ErrorAt $ErrorAt } } foreach ( $command in $Line ) { Write-ScriptLine $command -WarningAt $WarningAt -ErrorAt $ErrorAt } } catch { $PSCmdlet.ThrowTerminatingError($PSItem) } } } # .\chronometer\Public\Get-Chronometer.ps1 function Get-Chronometer { <# .Description Loads a script and then tracks the line by line execution times .Example Get-Chronometer -Path .\example.ps1 -Script { .\example.ps1 } #> [CmdletBinding()] param( # Script file to measure execution times on [Parameter( ValueFromPipeline = $true )] [Object[]] $Path, # Line numbers within the script file to measure [int[]] $LineNumber = $null, # The script to start the scrupt or execute other commands [Parameter(Position = 0)] [alias('Script', 'CommandScript')] [scriptblock] $ScriptBlock ) process { try { if ( $null -eq $Path ) { $Path = Get-ChildItem -Recurse -Include *.psm1, *.ps1 -File } if ( $Path.FullName ) { $Path = $Path.FullName } $Chronometer = [Chronometer]::New() Write-Verbose "Setting breakpoints" $Chronometer.AddBreakpoint($Path, $LineNumber) if ( $null -ne $Chronometer.breakPoint -and $null -ne $ScriptBlock ) { Write-Verbose "Executing Script" [ScriptProfiler]::Start() [void] $ScriptBlock.Invoke($Path) Write-Verbose "Clearing Breakpoints" $Chronometer.ClearBreakpoint() Write-Verbose "Processing data" foreach ( $node in [ScriptProfiler]::Queue.GetEnumerator() ) { $Chronometer.AddExecution($node) } Write-Output $Chronometer.GetResults() } else { Write-Warning "Parsing files did not result in any breakpoints" } } catch { $PSCmdlet.ThrowTerminatingError($PSItem) } } } |