All Exceptions Showing up as RpcException for innermessage

[JustinGrote]

Not sure if this belongs here or in the functions runtime repository, but when an exception is thrown in the Powershell Worker, when it reaches the logs/Application Insights, its innermost type is RpcException, meaning the exception type got lost in translation on the gRPC interface. This should pass through so that clear exceptions (InvalidOperationException, etc.) can be seen in application insights so issues can be triaged more quickly.

Workaround

Use the telemetry client to throw the "original" exception in a try/catch, this however leads to the dilemma of having "duplicate" exceptions for the failure, or forcing the function to succeed so as to avoid duplication (but then the consequences of that in terms of discovery, queue retry, etc.)

[Francisco-Gamino]

We will look into this. We will check to ensure we are consistent with other language, e.g., C#.

[JustinGrote]

With the recent update that added the TraceContext, I wanted to revisit this item again. Now that the parent ID trace context is provided, can errors be passed to Application Insights with the appropriate context IDs? I know I could "roll my own" solution here but ideally this would be native to the worker, so that viewing exceptions in application insights is more rich and insightful.

@SatishRanjan Since this is assigned to you, what do you think?

[AnatoliB]

@JustinGrote If you are talking about exceptions thrown by the function code, do you think #328 addressed this problem? Or you are talking about exceptions thrown by the PS Worker internal code?

[JustinGrote]

Talking about function code exceptions. They all show up as RPCException in Application Insights, so it's hard to do any kind of fault analysis at all.

…

On Wed, Oct 2, 2019 at 4:27 PM Anatoli Beliaev ***@***.***> wrote: @JustinGrote <https://github.com/JustinGrote> If you are talking about exceptions thrown by the function code, do you think #328 <#328> addressed this problem? Or you are talking about exceptions thrown by the PS Worker internal code? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#244?email_source=notifications&email_token=ADUNKUQPV5QIGFGS2ZVU7OLQMUU4ZA5CNFSM4HTPZWO2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEAGP7IQ#issuecomment-537722786>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADUNKUQHSR5CUYGCTDP2YATQMUU4ZANCNFSM4HTPZWOQ> .

[JustinGrote]

@AnatoliB to expound on this item:

Given the following HTTPTrigger function:

param($Request, $TriggerMetadata)

throw 'I want to see where this failed in Application Insights'

This is what I get in App Insights:

Notes:

1. All errors are RPCException errors. I should have the original type of this error shown which is System.Management.Automation.RuntimeException. I have no way to quickly distinguish issues from each other in app insights.
3. The stack trace doesn't tell me where in my script things failed. I expect this kind of stacktrace:

Exception             : 
    Type                        : System.Management.Automation.RuntimeException
    ErrorRecord                 : 
        Exception             : 
            Type    : System.Management.Automation.ParentContainsErrorRecordException
            Message : I want to see where this failed in Application Insights
            HResult : -2146233087
        CategoryInfo          : NotSpecified: (:) [], ParentContainsErrorRecordException
        FullyQualifiedErrorId : RuntimeException
    WasThrownFromThrowStatement : True
    Message                     : I want to see where this failed in Application Insights
    HResult                     : -2146233087
TargetObject          : I want to see where this failed in Application Insights
CategoryInfo          : OperationStopped: (I want to see where…pplication Insights:String) [], RuntimeException
FullyQualifiedErrorId : I want to see where this failed in Application Insights
InvocationInfo        : 
    ScriptLineNumber : 6
    OffsetInLine     : 1
    HistoryId        : -1
    ScriptName       : C:\Users\jgrote\Projects\ADSLUSPRTGAPI\Sandbox\run.ps1
    Line             : throw 'I want to see where this failed in Application Insights'
    PositionMessage  : At C:\Users\jgrote\Projects\ADSLUSPRTGAPI\Sandbox\run.ps1:6 char:1
                       + throw 'I want to see where this failed in Application Insights'
                       + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    PSScriptRoot     : C:\Users\jgrote\Projects\ADSLUSPRTGAPI\Sandbox
    PSCommandPath    : C:\Users\jgrote\Projects\ADSLUSPRTGAPI\Sandbox\run.ps1
    CommandOrigin    : Internal
ScriptStackTrace      : at <ScriptBlock>, C:\Users\jgrote\Projects\ADSLUSPRTGAPI\Sandbox\run.ps1: line 6
                        at <ScriptBlock>, <No file>: line 1

Recommended resolution

The worker should write a custom exception to Application Insights or logging that has the relevant stack trace information before passing it back to the host.

Workaround

I had to make my own Application Insights client with Microsoft.ApplicationInsights.WorkerService and read the instrumentation key from an env variable, and then trap thrown errors and write my own custom exception to Application Insights before passing it along. I get duplicate error reports (my error and the rpc exception) but at least I have better error information to work with.

[AnatoliB]

Thank you @JustinGrote, I understand the issue.

I just want to make sure you know that the data you are asking for is in a different table in Application Insights:

traces
| where timestamp > ago(1h)
| where message startswith "EXCEPTION:" 
| project timestamp, message

EXCEPTION: I want to see where this failed in Application Insights
At D:\home\site\wwwroot\HttpTrigger2\run.ps1:3 char:1
+ throw 'I want to see where this failed in Application Insights'
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+ CategoryInfo          : OperationStopped: (I want to see where\u2026pplication Insights:String) [], RuntimeException
+ FullyQualifiedErrorId : I want to see where this failed in Application Insights
 
Script stack trace:
   at <ScriptBlock>, D:\home\site\wwwroot\HttpTrigger2\run.ps1: line 3

System.Management.Automation.RuntimeException: I want to see where this failed in Application Insights

The format of this data is different from your example because I took it from a PS6 app. As soon as we deploy PS7 support to Azure, it will be using the Get-Error cmdlet to format exceptions, so it will match your example. But, even now, you can see the stack trace including the function source code line.

So, is this issue about making these exceptions go to the exceptions table instead of (or in addition to) the traces table? In this case, making the worker write exceptions data directly to Application Insights seems to be the most practical solution. It may take some time for us to implement this, though. If you already have a solution that you could share in the meantime, we will appreciate it.

[JustinGrote]

I do have a solution that basically uses trap to intercept the errors. I'll prepare a module and an article as a workaround.