Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix Tracing when exception is thrown. Prevent Tracing from throwing InvalidOperationException #223

Merged

Conversation

hjgraca
Copy link
Contributor

@hjgraca hjgraca commented Mar 24, 2023

Fix Tracing when exception is thrown. Prevent Tracing from throwing InvalidOperationException

Please provide the issue number

Issue number: 211

Summary

This issue occurs when:

  • Tracing feature was enabled and the setting POWERTOOLS_TRACER_CAPTURE_ERROR was set to true
  • If there was an exception not handled or an exception thrown in the code

The following exception would occur


  "errorType": "TargetInvocationException",
  "errorMessage": "Exception has been thrown by the target of an invocation.",
  "stackTrace": [
    "at System.RuntimeMethodHandle.InvokeMethod(Object target, Span1& arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)",
    "at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)",
    "at System.Reflection.RuntimePropertyInfo.GetValue(Object obj, BindingFlags invokeAttr, Binder binder, Object[] index, CultureInfo culture)",
    "at System.Reflection.RuntimePropertyInfo.GetValue(Object obj, Object[] index)",
    "at ThirdParty.LitJson.JsonMapper.WriteValue(Object obj, JsonWriter writer, Boolean writer_is_private, Int32 depth) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 836",
    "at ThirdParty.LitJson.JsonMapper.WriteValue(Object obj, JsonWriter writer, Boolean writer_is_private, Int32 depth) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 836",
    "at ThirdParty.LitJson.JsonMapper.WriteValue(Object obj, JsonWriter writer, Boolean writer_is_private, Int32 depth) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 836",
    "at ThirdParty.LitJson.JsonMapper.WriteValue(Object obj, JsonWriter writer, Boolean writer_is_private, Int32 depth) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 767",
    "at ThirdParty.LitJson.JsonMapper.WriteValue(Object obj, JsonWriter writer, Boolean writer_is_private, Int32 depth) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 767",
    "at Amazon.XRay.Recorder.Core.Internal.Emitters.JsonSegmentMarshaller.WriteEntityFields(Entity entity, JsonWriter writer) in //sdk/src/Core/Internal/Emitters/JsonSegmentMarshaller.cs:line 152",
    "at Amazon.XRay.Recorder.Core.Internal.Emitters.JsonSegmentMarshaller.EntityExporter(Entity entity, JsonWriter writer) in //sdk/src/Core/Internal/Emitters/JsonSegmentMarshaller.cs:line 65",
    "at ThirdParty.LitJson.JsonMapper.<>c__DisplayClass38_01.<RegisterExporter>b__0(Object obj, JsonWriter writer) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 919",
    "at ThirdParty.LitJson.JsonMapper.WriteValue(Object obj, JsonWriter writer, Boolean writer_is_private, Int32 depth) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 790",
    "at ThirdParty.LitJson.JsonMapper.ToJson(Object obj) in //sdk/src/Core/ThirdParty/LitJson/JsonMapper.cs:line 851",
    "at Amazon.XRay.Recorder.Core.Internal.Emitters.JsonSegmentMarshaller.Marshall(Entity segment) in //sdk/src/Core/Internal/Emitters/JsonSegmentMarshaller.cs:line 58",
    "at Amazon.XRay.Recorder.Core.Internal.Emitters.UdpSegmentEmitter.Send(Entity segment) in //sdk/src/Core/Internal/Emitters/UdpSegmentEmitter.cs:line 73",
    "at Amazon.XRay.Recorder.Core.Strategies.DefaultStreamingStrategy.Stream(Entity entity, ISegmentEmitter emitter) in //sdk/src/Core/Strategies/DefaultStreamingStrategy.cs:line 80",
    "at Amazon.XRay.Recorder.Core.Strategies.DefaultStreamingStrategy.Stream(Entity entity, ISegmentEmitter emitter) in //sdk/src/Core/Strategies/DefaultStreamingStrategy.cs:line 65",
    "at Amazon.XRay.Recorder.Core.AWSXRayRecorder.EndFacadeSegment() in //sdk/src/Core/AWSXRayRecorder.netcore.cs:line 407",
    "at Amazon.XRay.Recorder.Core.AWSXRayRecorder.ProcessEndSubsegmentInLambdaContext(Nullable1 timestamp) in //sdk/src/Core/AWSXRayRecorder.netcore.cs:line 371",
    "at Amazon.XRay.Recorder.Core.AWSXRayRecorder.EndSubsegment(Nullable1 timestamp) in /_/sdk/src/Core/AWSXRayRecorder.netcore.cs:line 328",
    "at AWS.Lambda.Powertools.Tracing.Internal.XRayRecorder.EndSubsegment()",
    "at AWS.Lambda.Powertools.Tracing.Internal.TracingAspectHandler.OnExit(AspectEventArgs eventArgs)",
    "at AWS.Lambda.Powertools.Common.MethodAspectAttribute.WrapAsync[T](Func`2 target, Object[] args, AspectEventArgs eventArgs)",
    "at lambda_method1(Closure , Stream , ILambdaContext , Stream )",
    "at Amazon.Lambda.RuntimeSupport.Bootstrap.UserCodeLoader.Invoke(Stream lambdaData, ILambdaContext lambdaContext, Stream outStream) in /src/Repo/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs:line 145",
    "at Amazon.Lambda.RuntimeSupport.HandlerWrapper.<>c__DisplayClass8_0.<GetHandlerWrapper>b__0(InvocationRequest invocation) in /src/Repo/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/HandlerWrapper.cs:line 55",
    "at Amazon.Lambda.RuntimeSupport.LambdaBootstrap.InvokeOnceAsync(CancellationToken cancellationToken) in /src/Repo/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/LambdaBootstrap.cs:line 176"
  ],
  "cause": {
    "errorType": "InvalidOperationException",
    "errorMessage": "Method may only be called on a Type for which Type.IsGenericParameter is true.",
    "stackTrace": [
      "at System.RuntimeType.get_DeclaringMethod()"
    ]
  }

This exception would be thrown which does not match (hides) the real exception that occurred.

The code responsible to add the exception to the metadata when an exception occurs in our code can be found at AWS.Lambda.Powertools.Tracing/Internal/TracingAspectHandler.cs line 161
And bellow

public T OnException<T>(AspectEventArgs eventArgs, Exception exception)
    {
        if (CaptureError())
        {
            var nameSpace = GetNamespace();
            
            _xRayRecorder.AddMetadata
            (
                nameSpace,
                $"{eventArgs.Name} error",
                exception <--- Issue here
            );
        }

        throw exception;
    }

The problem occurs when we pass the exception object to AddMetadata which internally cals XRay sdk
AWSXRayRecorder.Instance.AddMetadata(nameSpace, key, value);
Although value accepts an object, exception type is not valid in this case due to the type being generic and without a T assigned.

So what exactly is a "Type for which Type.IsGenericParameter is true"
That means it is a generic type argument in an open generic type - i.e. where we haven't picked a T yet; for example:

// true
bool isGenParam = typeof(List<>).GetGenericArguments()[0].IsGenericParameter;

// false (T is System.Int32)
bool isGenParam = typeof(List<int>).GetGenericArguments()[0].IsGenericParameter;

Changes

Transform the exception into a string

public T OnException<T>(AspectEventArgs eventArgs, Exception exception)
    {
        if (CaptureError())
        {
            var nameSpace = GetNamespace();
            
            var message =
                "Exception type " + exception.GetType() + Environment.NewLine +
                "Exception message: " + exception.Message + Environment.NewLine +
                "Stack trace: " + exception.StackTrace + Environment.NewLine;
            if (exception.InnerException != null)
            {
                message += "---BEGIN InnerException--- " + Environment.NewLine +
                           "Exception type " + exception.InnerException.GetType() + Environment.NewLine +
                           "Exception message: " + exception.InnerException.Message + Environment.NewLine +
                           "Stack trace: " + exception.InnerException.StackTrace + Environment.NewLine +
                           "---END Inner Exception";
            }
            
            _xRayRecorder.AddMetadata
            (
                nameSpace,
                $"{eventArgs.Name} error",
                message
            );
        }

        throw exception;
    }

User experience

This approach works and we can see in the image bellow that the original exception is logged in the Lambda logs and added as Metadata in Xray

image

Checklist

Please leave checklist items unchecked if they do not apply to your change.

Is this a breaking change?

RFC issue number:

Checklist:

  • Migration process documented
  • Implement warnings (if it can live side by side)

Acknowledgment

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

Disclaimer: We value your time and bandwidth. As such, any pull requests created on non-triaged issues might not be successful.

@auto-assign auto-assign bot requested a review from sliedig March 24, 2023 14:35
@hjgraca hjgraca added the bug Unexpected, reproducible and unintended software behaviour label Mar 24, 2023
@codecov-commenter
Copy link

codecov-commenter commented Mar 24, 2023

Codecov Report

Patch coverage: 46.15% and project coverage change: -0.10 ⚠️

Comparison is base (263c170) 56.39% compared to head (2e23dec) 56.29%.

Additional details and impacted files
@@             Coverage Diff             @@
##           develop     #223      +/-   ##
===========================================
- Coverage    56.39%   56.29%   -0.10%     
===========================================
  Files           41       41              
  Lines         1784     1796      +12     
===========================================
+ Hits          1006     1011       +5     
- Misses         778      785       +7     
Flag Coverage Δ
unittests 56.29% <46.15%> (-0.10%) ⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Impacted Files Coverage Δ
...owertools.Tracing/Internal/TracingAspectHandler.cs 94.11% <46.15%> (-5.89%) ⬇️

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

☔ View full report in Codecov by Sentry.
📢 Do you have feedback about the report comment? Let us know in this issue.

Copy link
Contributor

@amirkaws amirkaws left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@sliedig sliedig merged commit 865979a into aws-powertools:develop Mar 25, 2023
@hjgraca hjgraca deleted the fix_tracing_on_exception_thrown branch April 12, 2023 10:56
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Unexpected, reproducible and unintended software behaviour
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Bug: Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation
4 participants