diff --git a/CHANGELOG.md b/CHANGELOG.md index 234290e..6febd17 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ ### Features - Send events to Sentry fully synchronously ([#59](https://github.com/SummitHosting/sentry-powershell/pull/59), [#62](https://github.com/SummitHosting/sentry-powershell/pull/62)) +- Add StackTrace context to frames coming from inline script/command ([#65](https://github.com/getsentry/sentry-powershell/pull/65)) ### Fixes diff --git a/modules/Sentry/private/StackTraceProcessor.ps1 b/modules/Sentry/private/StackTraceProcessor.ps1 index 97a59f0..4b49e8b 100644 --- a/modules/Sentry/private/StackTraceProcessor.ps1 +++ b/modules/Sentry/private/StackTraceProcessor.ps1 @@ -114,33 +114,11 @@ class StackTraceProcessor : SentryEventProcessor hidden [Sentry.SentryStackTrace]GetStackTrace() { # We collect all frames and then reverse them to the order expected by Sentry (caller->callee). - # Do not try to make this code go backwards, because it relies on the InvocationInfo from the previous frame. + # Do not try to make this code go backwards because it relies on the InvocationInfo from the previous frame. $sentryFrames = New-Object System.Collections.Generic.List[Sentry.SentryStackFrame] - if ($null -ne $this.StackTraceFrames) - { - $sentryFrames.Capacity = $this.StackTraceFrames.Count + 1 - } - elseif ($null -ne $this.StackTraceString) + if ($null -ne $this.StackTraceString) { $sentryFrames.Capacity = $this.StackTraceString.Count + 1 - } - - if ($null -ne $this.StackTraceFrames) - { - # Note: if InvocationInfo is present, use it to fill the first frame. This is the case for ErrroRecord handling - # and has the information about the actual script file and line that have thrown the exception. - if ($null -ne $this.InvocationInfo) - { - $sentryFrames.Add($this.CreateFrame($this.InvocationInfo)) - } - - foreach ($frame in $this.StackTraceFrames) - { - $sentryFrames.Add($this.CreateFrame($frame)) - } - } - elseif ($null -ne $this.StackTraceString) - { # Note: if InvocationInfo is present, use it to update: # - the first frame (in case of `$_ | Out-Sentry` in a catch clause). # - the second frame (in case of `write-error` and `$_ | Out-Sentry` in a trap). @@ -167,10 +145,21 @@ class StackTraceProcessor : SentryEventProcessor } $sentryFrames.Add($sentryFrame) } + if ($null -ne $sentryFrameInitial) { $sentryFrames.Insert(0, $sentryFrameInitial) } + + $this.EnhanceTailFrames($sentryFrames) + } + elseif ($null -ne $this.StackTraceFrames) + { + $sentryFrames.Capacity = $this.StackTraceFrames.Count + 1 + foreach ($frame in $this.StackTraceFrames) + { + $sentryFrames.Add($this.CreateFrame($frame)) + } } foreach ($sentryFrame in $sentryFrames) @@ -213,7 +202,10 @@ class StackTraceProcessor : SentryEventProcessor $regex = 'at (?[^,]*), (?.*): line (?\d*)' if ($frame -match $regex) { - $sentryFrame.AbsolutePath = $Matches.AbsolutePath + if ($Matches.AbsolutePath -ne '') + { + $sentryFrame.AbsolutePath = $Matches.AbsolutePath + } $sentryFrame.LineNumber = [int]$Matches.LineNumber $sentryFrame.Function = $Matches.Function } @@ -224,6 +216,54 @@ class StackTraceProcessor : SentryEventProcessor return $sentryFrame } + hidden EnhanceTailFrames([Sentry.SentryStackFrame[]] $sentryFrames) + { + if ($null -eq $this.StackTraceFrames) + { + return + } + + # The last frame is usually how the PowerShell was invoked. We need to get this info from $this.StackTraceFrames + # - for pwsh scriptname.ps1 it would be something like `. scriptname.ps1` + # - for pwsh -c `& {..}` it would be the `& {..}` code block. And in this case, the next frame would also be + # just a scriptblock without a filename so we need to get the source code from the StackTraceFrames too. + $i = 0; + for ($j = $sentryFrames.Count - 1; $j -ge 0; $j--) + { + $sentryFrame = $sentryFrames[$j] + $frame = $this.StackTraceFrames | Select-Object -Last 1 -Skip $i + $i++ + + if ($null -eq $frame) + { + break + } + + if ($null -eq $sentryFrame.AbsolutePath -and $null -eq $frame.ScriptName) + { + if ($frame.ScriptLineNumber -gt 0 -and $frame.ScriptLineNumber -eq $sentryFrame.LineNumber) + { + $this.SetScriptInfo($sentryFrame, $frame) + $this.SetModule($sentryFrame) + $this.SetFunction($sentryFrame, $frame) + } + $this.SetContextLines($sentryFrame, $frame) + + # Try to match following frames that are part of the same codeblock. + while ($j -gt 0) + { + $nextSentryFrame = $sentryFrames[$j - 1] + if ($nextSentryFrame.AbsolutePath -ne $sentryFrame.AbsolutePath) + { + break + } + $this.SetContextLines($nextSentryFrame, $frame) + $j-- + } + } + } + } + hidden SetScriptInfo([Sentry.SentryStackFrame] $sentryFrame, [System.Management.Automation.CallStackFrame] $frame) { if (![string]::IsNullOrEmpty($frame.ScriptName)) @@ -268,6 +308,19 @@ class StackTraceProcessor : SentryEventProcessor if ([string]::IsNullOrEmpty($sentryFrame.AbsolutePath) -and $frame.FunctionName -eq '' -and ![string]::IsNullOrEmpty($frame.Position)) { $sentryFrame.Function = $frame.Position.Text + + # $frame.Position.Text may be a multiline command (e.g. when executed with `pwsh -c '& { ... \n ... \n ... }`) + # So we need to trim it to a single line. + if ($sentryFrame.Function.Contains("`n")) + { + $lines = $sentryFrame.Function -split "[`r`n]+" + $sentryFrame.Function = $lines[0] + ' ' + if ($lines.Count -gt 2) + { + $sentryFrame.Function += ' ...... ' + } + $sentryFrame.Function += $lines[$lines.Count - 1] + } } else { @@ -275,6 +328,22 @@ class StackTraceProcessor : SentryEventProcessor } } + hidden SetContextLines([Sentry.SentryStackFrame] $sentryFrame, [System.Management.Automation.CallStackFrame] $frame) + { + if ($sentryFrame.LineNumber -gt 0) + { + try + { + $lines = $frame.InvocationInfo.MyCommand.ScriptBlock.ToString() -split "`n" + $this.SetContextLines($sentryFrame, $lines) + } + catch + { + Write-Warning "Failed to read context lines for frame with function '$($sentryFrame.Function)': $_" + } + } + } + hidden SetContextLines([Sentry.SentryStackFrame] $sentryFrame) { if ([string]::IsNullOrEmpty($sentryFrame.AbsolutePath) -or $sentryFrame.LineNumber -lt 1) @@ -287,21 +356,7 @@ class StackTraceProcessor : SentryEventProcessor try { $lines = Get-Content $sentryFrame.AbsolutePath -TotalCount ($sentryFrame.LineNumber + 5) - if ($null -eq $sentryFrame.ContextLine) - { - $sentryFrame.ContextLine = $lines[$sentryFrame.LineNumber - 1] - } - $preContextCount = [math]::Min(5, $sentryFrame.LineNumber - 1) - $postContextCount = [math]::Min(5, $lines.Count - $sentryFrame.LineNumber) - if ($sentryFrame.LineNumber -gt 6) - { - $lines = $lines | Select-Object -Skip ($sentryFrame.LineNumber - 6) - } - # Note: these are read-only in sentry-dotnet so we just update the underlying lists instead of replacing. - $sentryFrame.PreContext.Clear() - $lines | Select-Object -First $preContextCount | ForEach-Object { $sentryFrame.PreContext.Add($_) } - $sentryFrame.PostContext.Clear() - $lines | Select-Object -Last $postContextCount | ForEach-Object { $sentryFrame.PostContext.Add($_) } + $this.SetContextLines($sentryFrame, $lines) } catch { @@ -309,4 +364,34 @@ class StackTraceProcessor : SentryEventProcessor } } } + + hidden SetContextLines([Sentry.SentryStackFrame] $sentryFrame, [string[]] $lines) + { + if ($lines.Count -lt $sentryFrame.LineNumber) + { + Write-Debug "Couldn't set frame context because the line number ($($sentryFrame.LineNumber)) is lower than the available number of source code lines ($($lines.Count))." + return + } + + $numContextLines = 5 + + if ($null -eq $sentryFrame.ContextLine) + { + $sentryFrame.ContextLine = $lines[$sentryFrame.LineNumber - 1] + } + + $preContextCount = [math]::Min($numContextLines, $sentryFrame.LineNumber - 1) + $postContextCount = [math]::Min($numContextLines, $lines.Count - $sentryFrame.LineNumber) + + if ($sentryFrame.LineNumber -gt $numContextLines + 1) + { + $lines = $lines | Select-Object -Skip ($sentryFrame.LineNumber - $numContextLines - 1) + } + + # Note: these are read-only in sentry-dotnet so we just update the underlying lists instead of replacing. + $sentryFrame.PreContext.Clear() + $lines | Select-Object -First $preContextCount | ForEach-Object { $sentryFrame.PreContext.Add($_) } + $sentryFrame.PostContext.Clear() + $lines | Select-Object -First $postContextCount -Skip ($preContextCount + 1) | ForEach-Object { $sentryFrame.PostContext.Add($_) } + } } diff --git a/modules/Sentry/public/Out-Sentry.ps1 b/modules/Sentry/public/Out-Sentry.ps1 index c605a1c..389bcf4 100644 --- a/modules/Sentry/public/Out-Sentry.ps1 +++ b/modules/Sentry/public/Out-Sentry.ps1 @@ -94,7 +94,7 @@ function Out-Sentry return } - if ($options.AttachStackTrace -and $null -eq $processor.StackTraceFrames -and $null -eq $processor.StackTraceString) + if ($options.AttachStackTrace -and $null -eq $processor.StackTraceFrames) { $processor.StackTraceFrames = Get-PSCallStack | Select-Object -Skip 1 } diff --git a/tests/integration-test-script.ps1 b/tests/integration-test-script.ps1 index 37e3eb4..5968095 100644 --- a/tests/integration-test-script.ps1 +++ b/tests/integration-test-script.ps1 @@ -2,9 +2,15 @@ Set-StrictMode -Version latest $ErrorActionPreference = 'Stop' $PSNativeCommandUseErrorActionPreference = $true -Import-Module ../modules/Sentry/Sentry.psd1 -. ./utils.ps1 -. ./throwingshort.ps1 +Import-Module ./modules/Sentry/Sentry.psd1 +. ./tests/utils.ps1 +. ./tests/throwingshort.ps1 + +function funcA +{ + # Call to another file + funcC +} $events = [System.Collections.Generic.List[Sentry.SentryEvent]]::new(); $transport = [RecordingTransport]::new() @@ -12,7 +18,7 @@ StartSentryForEventTests ([ref] $events) ([ref] $transport) try { - funcC + funcA } catch { @@ -29,7 +35,7 @@ $thread.Stacktrace.Frames | ForEach-Object { $value = $frame.$prop | Out-String -Width 500 if ("$value" -ne '') { - "$($prop): $value" + "$($prop): $value".TrimEnd() } } } diff --git a/tests/integration.tests.ps1 b/tests/integration.tests.ps1 index f6a5635..50d0b2b 100644 --- a/tests/integration.tests.ps1 +++ b/tests/integration.tests.ps1 @@ -18,6 +18,8 @@ BeforeAll { $output = $output | Where-Object { $_ -ne '' } # Print out so that we can compare the whole output if the test fails + Write-Host '================' + Write-Host 'Testing output:' $output | Write-Host for ($i = 0; $i -lt $expected.Count -and $i -lt $output.Count; $i++) @@ -25,6 +27,9 @@ BeforeAll { $output[$i] | Should -Be $expected[$i] -Because "Output line $i" } $output.Count | Should -Be $expected.Count + Write-Host '----------------' + Write-Host 'LGTM!' + Write-Host '================' } } @@ -40,18 +45,44 @@ BeforeAll { # And we can live without testing on PowerShell 7.2 & 7.3 because we have tests for 7.4. Describe 'Out-Sentry captures expected stack traces for command argument' -Skip:(($PSVersionTable.PSVersion.Major -eq 7 -and $PSVersionTable.PSVersion.Minor -le 3) -or $PSVersionTable.PSEdition -eq 'Desktop') { BeforeEach { - Push-Location "$PSScriptRoot" + Push-Location "$PSScriptRoot/.." $expected = @( '----------------' - 'AbsolutePath: ' - 'Function: ' + 'ContextLine: & {Set-StrictMode -Version latest' + 'Function: & {Set-StrictMode -Version latest ...... }' 'InApp: True' 'LineNumber: 1' + "PostContext: `$ErrorActionPreference = 'Stop'" + '$PSNativeCommandUseErrorActionPreference = $true' + 'Import-Module ./modules/Sentry/Sentry.psd1' + '. ./tests/utils.ps1' '----------------' - 'AbsolutePath: ' + 'ContextLine: funcA' 'Function: ' 'InApp: True' - 'LineNumber: 15' + 'LineNumber: 21' + 'PostContext: }' + 'catch' + '{' + ' $_ | Out-Sentry | Out-Null' + '}' + 'PreContext: $transport = [RecordingTransport]::new()' + 'StartSentryForEventTests ([ref] $events) ([ref] $transport)' + 'try' + '{' + '----------------' + 'ContextLine: funcC' + 'Function: funcA' + 'InApp: True' + 'LineNumber: 12' + 'PostContext: }' + '$events = [System.Collections.Generic.List[Sentry.SentryEvent]]::new();' + '$transport = [RecordingTransport]::new()' + 'StartSentryForEventTests ([ref] $events) ([ref] $transport)' + 'PreContext: . ./tests/throwingshort.ps1' + 'function funcA' + '{' + ' # Call to another file' '----------------' "AbsolutePath: $integrationTestThrowingScript" 'ColumnNumber: 5' @@ -62,7 +93,6 @@ Describe 'Out-Sentry captures expected stack traces for command argument' -Skip: 'PostContext: }' 'PreContext: function funcC {' ) - } AfterEach { @@ -70,25 +100,46 @@ Describe 'Out-Sentry captures expected stack traces for command argument' -Skip: } It 'Windows PowerShell' -Skip:($env:OS -ne 'Windows_NT') { - $output = powershell.exe -Command "& {$integrationTestScriptContent}" -ErrorAction Continue + $output = powershell.exe -Command "& {$integrationTestScriptContent}" $checkOutput.Invoke($output, $expected) } It 'PowerShell' { - $output = pwsh -Command "& {$integrationTestScriptContent}" -ErrorAction Continue + $output = pwsh -Command "& {$integrationTestScriptContent}" $checkOutput.Invoke($output, $expected) } } +# Note: for piped command we only actually get a single stack frame for the call to Out-Sentry. +# Not sure yet if there's any better way to get more information. Describe 'Out-Sentry captures expected stack traces for piped command' { BeforeEach { - Push-Location "$PSScriptRoot" + Push-Location "$PSScriptRoot/.." $expected = @( '----------------' - 'AbsolutePath: ' + 'ContextLine: funcA' 'Function: ' 'InApp: True' 'LineNumber: 3' + 'PostContext: }' + 'catch' + '{' + ' $_ | Out-Sentry | Out-Null' + '}' + 'PreContext: try' + '{' + '----------------' + 'ContextLine: }' + 'Function: funcA' + 'InApp: True' + 'LineNumber: 4' + 'PostContext: catch' + '{' + ' $_ | Out-Sentry | Out-Null' + '}' + 'PreContext: try' + '{' + ' funcA' '----------------' "AbsolutePath: $integrationTestThrowingScript" 'ColumnNumber: 5' @@ -118,19 +169,19 @@ Describe 'Out-Sentry captures expected stack traces for piped command' { Describe 'Out-Sentry captures expected stack traces for file input' { BeforeEach { - Push-Location "$PSScriptRoot" + Push-Location "$PSScriptRoot/.." $expected = @( '----------------' - 'AbsolutePath: ' - 'Function: ' + "ContextLine: $integrationTestScript" + "Function: $integrationTestScript" 'InApp: True' 'LineNumber: 1' '----------------' "AbsolutePath: $integrationTestScript" - 'ContextLine: funcC' + 'ContextLine: funcA' 'Function: ' 'InApp: True' - 'LineNumber: 15' + 'LineNumber: 21' 'PostContext: }' 'catch' '{' @@ -141,6 +192,20 @@ Describe 'Out-Sentry captures expected stack traces for file input' { 'try' '{' '----------------' + "AbsolutePath: $integrationTestScript" + 'ContextLine: funcC' + 'Function: funcA' + 'InApp: True' + 'LineNumber: 12' + 'PostContext: }' + '$events = [System.Collections.Generic.List[Sentry.SentryEvent]]::new();' + '$transport = [RecordingTransport]::new()' + 'StartSentryForEventTests ([ref] $events) ([ref] $transport)' + 'PreContext: . ./tests/throwingshort.ps1' + 'function funcA' + '{' + ' # Call to another file' + '----------------' "AbsolutePath: $integrationTestThrowingScript" 'ColumnNumber: 5' 'ContextLine: throw "Short context test"' @@ -168,3 +233,60 @@ Describe 'Out-Sentry captures expected stack traces for file input' { $checkOutput.Invoke($output, $expected) } } + +Describe 'Out-Sentry captures expected stack traces for PowerShell.Create()' { + BeforeEach { + Push-Location "$PSScriptRoot/.." + $expected = @( + '----------------' + 'ContextLine: funcA' + 'Function: ' + 'InApp: True' + 'LineNumber: 21' + 'PostContext: }' + 'catch' + '{' + ' $_ | Out-Sentry | Out-Null' + '}' + 'PreContext: $transport = [RecordingTransport]::new()' + 'StartSentryForEventTests ([ref] $events) ([ref] $transport)' + 'try' + '{' + '----------------' + 'ContextLine: funcC' + 'Function: funcA' + 'InApp: True' + 'LineNumber: 12' + 'PostContext: }' + '$events = [System.Collections.Generic.List[Sentry.SentryEvent]]::new();' + '$transport = [RecordingTransport]::new()' + 'StartSentryForEventTests ([ref] $events) ([ref] $transport)' + 'PreContext: . ./tests/throwingshort.ps1' + 'function funcA' + '{' + ' # Call to another file' + '----------------' + "AbsolutePath: $integrationTestThrowingScript" + 'ColumnNumber: 5' + 'ContextLine: throw "Short context test"' + 'Function: funcC' + 'InApp: True' + 'LineNumber: 2' + 'PostContext: }' + 'PreContext: function funcC {' + ) + } + + AfterEach { + Pop-Location + } + + It 'PowerShell' { + $childPs = [PowerShell]::Create() + $childPs.AddScript($integrationTestScriptContent) + $output = $childPs.Invoke() + # Output has weirdly behaving line breaks in this case so let's normalize them: + $output = ($output -join "`n") -split "[`r`n]+" + $checkOutput.Invoke($output, $expected) + } +} diff --git a/tests/stacktrace-processor.tests.ps1 b/tests/stacktrace-processor.tests.ps1 index 2926e37..a48c055 100644 --- a/tests/stacktrace-processor.tests.ps1 +++ b/tests/stacktrace-processor.tests.ps1 @@ -19,7 +19,7 @@ at , : line 3' -split "[`r`n]+" $frames[0].AbsolutePath | Should -Be '' $frames[0].LineNumber | Should -Be 3 $frames[1].Function | Should -Be '' - $frames[1].AbsolutePath | Should -Be '' + $frames[1].AbsolutePath | Should -Be $null $frames[1].LineNumber | Should -Be 1 $frames[2].Function | Should -Be 'funcB' $frames[2].AbsolutePath | Should -Be 'C:\dev\sentry-powershell\tests\throwing.ps1' diff --git a/tests/stacktrace.tests.ps1 b/tests/stacktrace.tests.ps1 index f82dbd6..ae1a662 100644 --- a/tests/stacktrace.tests.ps1 +++ b/tests/stacktrace.tests.ps1 @@ -92,7 +92,7 @@ BeforeAll { $frame = GetListItem $frames -1 - $frame.Function | Should -Be "funcC" + $frame.Function | Should -Be 'funcC' $frame.AbsolutePath | Should -Be (Join-Path $PSScriptRoot 'throwingshort.ps1') $frame.LineNumber | Should -BeGreaterThan 0 $frame.InApp | Should -Be $true