Powershell: Get-Error: Avoid duplicate information contained in nested ErrorRecord blocks

Created on 19 Nov 2019  路  18Comments  路  Source: PowerShell/PowerShell

Summary of the new feature/enhancement

_Update_: The issue is primarily that a nested ErrorRecord: prints duplicate information, which results in "noisy" output that is hard to parse; see the discussion in the comments.


Currently, when Get-Error pretty-prints an error, the information about the error record's .Exception and Exception.InnerException values are pretty far apart.

It would be helpful if they were grouped together in the output.

Currently (look for <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<< markers; note that in this simple example the messages happen to be the same, but that's not typical):

Exception             :
    ErrorRecord    :
        Exception             :   <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
            Message : Attempted to divide by zero.
            HResult : -2146233087
        CategoryInfo          : NotSpecified: (:) [], ParentContainsErrorRecordException
        FullyQualifiedErrorId : RuntimeException
        InvocationInfo        :
            ScriptLineNumber : 1
            OffsetInLine     : 1
            HistoryId        : -1
            Line             : 1/0
            PositionMessage  : At line:1 char:1
                               + 1/0
                               + ~~~
            CommandOrigin    : Internal
        ScriptStackTrace      : at <ScriptBlock>, <No file>: line 1
    TargetSite     :
        Name          : Divide
        DeclaringType : System.Management.Automation.IntOps
        MemberType    : Method
        Module        : System.Management.Automation.dll
    StackTrace     :
   at System.Management.Automation.IntOps.Divide(Int32 lhs, Int32 rhs)
   at System.Dynamic.UpdateDelegates.UpdateAndExecute2[T0,T1,TRet](CallSite site, T0 arg0, T1 arg1)
   at System.Management.Automation.Interpreter.DynamicInstruction`3.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
    Message        : Attempted to divide by zero.
    Data           : System.Collections.ListDictionaryInternal
    InnerException :  <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
        Message : Attempted to divide by zero.
        HResult : -2147352558

Desired:

Exception             :
    ErrorRecord    :
        Exception             :   <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
            Message : Attempted to divide by zero.
            HResult : -2146233087
            InnerException     :  <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
                Message : Attempted to divide by zero.
                HResult : -2147352558
        CategoryInfo          : NotSpecified: (:) [], ParentContainsErrorRecordException
        FullyQualifiedErrorId : RuntimeException
        InvocationInfo        :
            ScriptLineNumber : 1
            OffsetInLine     : 1
            HistoryId        : -1
            Line             : 1/0
            PositionMessage  : At line:1 char:1
                               + 1/0
                               + ~~~
            CommandOrigin    : Internal
        ScriptStackTrace      : at <ScriptBlock>, <No file>: line 1
    TargetSite     :
        Name          : Divide
        DeclaringType : System.Management.Automation.IntOps
        MemberType    : Method
        Module        : System.Management.Automation.dll
    StackTrace     :
   at System.Management.Automation.IntOps.Divide(Int32 lhs, Int32 rhs)
   at System.Dynamic.UpdateDelegates.UpdateAndExecute2[T0,T1,TRet](CallSite site, T0 arg0, T1 arg1)
   at System.Management.Automation.Interpreter.DynamicInstruction`3.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
    Message        : Attempted to divide by zero.
    Data           : System.Collections.ListDictionaryInternal
Area-Cmdlets-Utility Issue-Enhancement

Most helpful comment

Get-Error currently stops recursion at 10 (hard coded).

@mklement0 the current code for the formatting already special cases the object types to expand into. It's basically Exceptions, ErrorRecords, and anything in a fixed list. TargetSite is treated specially as I think it's useful, but contains many properties that are not so they aren't shown.

So if there's other types to include or exclude, it can be done.

All 18 comments

In your example, InnerException is a child of the top level Exception so it wouldn't be under ErrorRecord/Exception. At best, InnerException could follow ErrorRecord or be ahead of it.

@SteveL-MSFT, I think I'm missing something:

  • The _whole object_ is an ErrorRecord instance, so why is there a top-level Exception : label with a nested ErrorRecord: label at all?

  • Isn't .Exception _always_ a direct property of the ErrorRecord instance, and .InnerException always nested in it?

@mklement0

  • The _whole object_ is an ErrorRecord instance, so why is there a top-level Exception : label with a nested ErrorRecord: label at all?

Exceptions that inherit RuntimeException or implement the IContainsErrorRecord interface then they construct their own error record. That's what this ErrorRecord constructor is for iirc: ErrorRecord(ErrorRecord errorRecord, Exception replaceParentContainsErrorRecordException).

It's so some non-cmdlet API's can throw an exception and still control the error record if uncaught.

@mklement0 in your specific example, it's an exception wrapped by an errorrecord wrapped by an exception. $error can contain both Exceptions and ErrorRecords

Thanks, @SeeminglyScience and @SteveL-MSFT.

Still trying to wrap my head around this, but it appears to me that the nested ErrorRecord: block contains only _duplicated_ information and could therefore simply be omitted (the only extra information is ParentContainsErrorRecordException in .CategoryInfo, which I think is not of interest to end users, and neither are the implementation details of how exceptions / error records can be nested / wrapped).

Additionally, in the specific case at hand, the inner exception is virtually useless, because it is of the same type as the outer one, so it could be omitted too.

With the error record at hand, with my property-reordering suggestion from https://github.com/PowerShell/PowerShell/issues/11121#issuecomment-555712295 applied, as well as with a Type: line reflecting the exception's full type name added (per #11076), this would give us a much simplified:

Exception          :
    Type           : System.Management.Automation.RuntimeException 
    Message        : Attempted to divide by zero.
    Source         : System.Management.Automation
    HResult        : -2146233087
    Data           : System.Collections.ListDictionaryInternal
    TargetSite     :
        Name          : CheckActionPreference
        DeclaringType : System.Management.Automation.ExceptionHandlingOps
        MemberType    : Method
        Module        : System.Management.Automation.dll
    StackTrace     :
   at System.Management.Automation.ExceptionHandlingOps.CheckActionPreference(FunctionContext funcContext, Exception exception)
   at System.Management.Automation.Interpreter.ActionCallInstruction`2.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
   at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame)
CategoryInfo          : NotSpecified: (:) [], RuntimeException
FullyQualifiedErrorId : RuntimeException
InvocationInfo        :
    ScriptLineNumber : 1
    OffsetInLine     : 7
    HistoryId        : -1
    Line             : try { 1/0 } catch {}; $Error[0].GetType().FullName | scb
    PositionMessage  : At line:1 char:7
                       + try { 1/0 } catch {}; $Error[0].GetType().FullName | scb
                       +       ~~~
    CommandOrigin    : Internal
ScriptStackTrace      : at <ScriptBlock>, <No file>: line 1

Also note that the .Data property is currently uselessly represented by its .ToString() stringification. Its entries should be represented individually; alternatively, the property could be omitted altogether.

@mklement0 The nested ErrorRecord and InnerException is simply what is in the actual error object itself. I don't think the formatter should be making a check to see if any information is duplicate and omitting it. The ordering looks fine so I can update that.

Thanks, @SteveL-MSFT.

I don't think the formatter should be making a check to see if any information is duplicate and omitting it.

I don't have the full picture, but it seems to me that whenever I see ParentContainsErrorRecordException in the nested ErrorRecord: block's CategoryInfo, the information is duplicated - and all the extra information generates so much noise that it's easy to get confused.

Therefore:

  • Assuming that the presence of ParentContainsErrorRecordException reliably indicates duplication, it can be tested for in order to then omit the nested ErrorRecord: block.

  • Are there cases where this duplication does _not_ occur? If so, to satisfy my own curiosity, can you give me an example command that provokes such an error?

    • I've tried 1 / 0, [int]::Parse('foo'), Get-Item /NoSuch and Get-Item /NoSuch -ea Stop, and they all have the duplication.

@mklement0

  • Are there cases where this duplication does _not_ occur? If so, to satisfy my own curiosity, can you give me an example command that provokes such an error?
  • Exceptions thrown during prompt level pipeline creation, such as entering [type]::psobject directly into an interactive prompt.
  • Any other API that throws an IContainsErrorRecord exception in a circumstance where the engine the engine will not catch it (or will not specifically check for IContainsErrorRecord) and reform the record correctly

ParentContainsErrorRecordException is the exception you're supposed to use when creating the error record stored by IContainsErrorRecord.ErrorRecord.

Here's a basic example:

using System;
using System.Management.Automation;

public class MyRuntimeException : Exception, IContainsErrorRecord
{
    private ErrorRecord _errorRecord;

    public MyRuntimeException(string message) : base(message)
    {
    }

    public ErrorRecord ErrorRecord => _errorRecord ??= new ErrorRecord(
        new ParentContainsErrorRecordException(Message),
        "MySpecialErrorId",
        ErrorCategory.LimitsExceeded,
        targetObject: null);
}

[Cmdlet(VerbsDiagnostic.Test, "Exception")]
public class TestExceptionCommand : PSCmdlet
{
    protected override void BeginProcessing()
    {
        throw new MyRuntimeException("My message!");
    }

    public static void ThrowMyException() => throw new MyRuntimeException("My message!");
}

If you call Test-Exception, the error record will be correct. If you call ThrowMyException, it'll instead be wrapped in a MethodInvocationException. In the case of the latter, the details of the inner ErrorRecord are not duplicated.

Thank you, @SeeminglyScience - a helpful peek behind the curtain, as usual. It'll take me a while to fully digest these intricacies.

As an aside: Why does [type]::psobject fail?

Using the intentional ordering of the properties will help, but I'm still concerned about the volume and structural complexity of the output.

Do you see a way to algorithmically simplify the output in a manner that is more helpful to end users (hides implementation details) while avoiding omission of important information?

As an aside: Why does [type]::psobject fail?

Just a bug. I have an issue open about it, but tbh it doesn't really affect anyone so it probably won't be fixed. If it ever does I guess I'll have to find another example 馃槈

If you're curious, it fails because member binding expects that members with a reserved member name always exist, but it doesn't check if it's a static invocation. So it sees PSObject and says "oh I know that member, that's literally always there" and then it tries to use it.

Or... at least that's my guess. I can't remember if I actually looked at the code to see if I was right...

Using the intentional ordering of the properties will help, but I'm still concerned about the volume and structural complexity of the output.

Do you see a way to algorithmically simplify the output in a manner that is more helpful to end users (hides implementation details) while avoiding omission of important information?

Maybe you could keep a hash set of ErrorId's and avoid recursing when there's a match? Dunno, I'll think about it.

Side note, if it currently recurses infinitely there should probably be some protection. I've definitely accidently used this instead of ParentContainsErrorRecordException when creating the IContainsErrorRecord.ErrorRecord, which would be a fun stack overflow to debug 馃檪

I had the same issue trying to add a Suggestion member to ErrorRecord. CommandNotFoundException can get fun to debug when you accidentally trigger it recursively. 馃榿

Get-Error currently stops recursion at 10 (hard coded).

@mklement0 the current code for the formatting already special cases the object types to expand into. It's basically Exceptions, ErrorRecords, and anything in a fixed list. TargetSite is treated specially as I think it's useful, but contains many properties that are not so they aren't shown.

So if there's other types to include or exclude, it can be done.

Maybe rather than hard-code 10, add a parameter MaxDepth or RecursionLimit and default it to 10?

Is there a scenario where someone would change the MaxDepth? Seems like a parameter that would never get used. In my experience, 10 is already way bigger than probably necessary. Limiting MaxDepth to 1 would just be dumping $Error[0] to Format-List. A MaxDepth of 2 or 3 is going to be most cases anyways as I haven't encountered any Exceptions/ErrorRecords that are more than 4 deep anyways. The 10 was just a protective measure against infinite recursion.

Fair point. and yeah, you're likely right on this. It's just that hard-coded values that the user can't change make me a bit nervous. :-) I guess if it turns out to be an issue, you can always add such a parameter later.

The only reason I can think to make it configurable is that there may potentially be cases where a user would like to ensure that as much detail as possible is logged (e.g., in a CI runner) and there may be cause to need over 10. It would definitely be an edge case, but it could still be helpful to have such a parameter.

Conversely, users may want to explicitly limit depth in the case of recursing exceptions to something much lower to improve the readability of the output.

@vexx32 such a param is easily added, but once added nearly impossible to remove. Let's wait until there's a real customer ask for this :)

Was this page helpful?
0 / 5 - 0 ratings