aws / aws-xray-sdk-dotnet

The official AWS X-Ray SDK for .NET.
Apache License 2.0
109 stars 64 forks source link

Entity doesn't exist in CallContext #26

Open mpetito opened 6 years ago

mpetito commented 6 years ago

The logical call context used to store the segment in ASP.NET / .NET Framework seems to be lost depending on the size of the request made to the application. This results in the following exception:

Amazon.XRay.Recorder.Core.Exceptions.EntityNotAvailableException: Entity doesn't exist in CallContext https://github.com/aws/aws-xray-sdk-dotnet/blob/b481c9a4333de3d501deb6d74ff112bd24d23456/sdk/src/Core/Internal/Utils/TraceContext.net45.cs#L47

After tracking this down it is easily reproduced by simply posting a form with data of a sufficient length to either an MVC or Web API controller. See https://github.com/mpetito/xray-mvc-test for an example repo. I've tested this in .NET Framework 4.5 and 4.6.1.

I can only speculate at the root cause. I suspect the length of the request determines whether the request body is read in its entirety before BeginRequest is invoked (where the call context is initialized). If the remainder of the request is read after BeginRequest then the call context is lost.

The only workaround I've come up with is to write a global filter (both for MVC and API) which extracts the current entity set by ProcessHTTPRequest from HttpContext.Items and re-assigns it using SetEntity before the action begins executing.

Kralizek commented 6 years ago

I had the same issue when working on a WCF service behavior to integarte X-Ray.

https://github.com/Kralizek/xray-wcf/blob/master/src/AWSXRayRecorder.Handlers.ServiceModel/Internal/AWSXRayDispatchMessageInspector.cs

Here I fetch and use the correlationState to pass the current segment back to myself in the BeforeSendReply method.

mpetito commented 6 years ago

Yes, my workaround was similar for MVC / API using global filters: https://gist.github.com/mpetito/ec6977cb376ea70c6be3330011ca8c93

yogiraj07 commented 6 years ago

Hi @mpetito, @Kralizek ,

Thank you for raising this limitation. While developing X-Ray handler for ASP.NET, we did find some strange behavior by the framework, where we would see value of Callcontext getting lost in a single request path. For example, when we receive exception in HTTP Modules, we did see exception being executed on another thread, which resulted in empty Callcontext.

In order to have access to the segment started by the X-Ray middleware, we stored it in the Context of the request, so that you work around the scenarios, as you have mentioned above.

We appreciate your efforts for making the community aware about your use case. I would like to keep the issue open, so that we can have users educated with the known behavior for the . ASP.NET.

We also welcome suggestions, pull request if you have any so that we can improvise the middleware.

Best, Yogi

mpetito commented 6 years ago

Hi @yogiraj07 ,

I think that this is more than just a limitation.

  1. The provided handler will not work for a majority of ASP.NET applications which accept POST requests.
  2. The issue may not become apparent during testing, depending on the size of the request body.
  3. By default, the case where the context is lost raises an exception that affects the execution of the request.

Minimally, the documentation should call attention to this issue and discourage use of the ASP.NET handler without considering one of the work arounds.

yogiraj07 commented 6 years ago

Hi @mpetito , We will make sure in our documentation, the users are aware about this issue.

Best, Yogi

yogiraj07 commented 5 years ago

Hi @mpetito , @Kralizek , We have made a release 2.4.0-beta which solves this issue. Please refer Changelog. I have also analyzed the issue here . Please feel free to try new release and let us know if this solves the issue.

Thanks for the patience.

Yogi

lvanderbijl commented 4 years ago

I'm still getting this error with v2.7.2. I'm not able to get the filters workaround to work because the httpcontext items array doesn't have a "XRayEntity" property. Is there any alternative fix?

srprash commented 4 years ago

Hi @lvanderbijl Can you provide some logs or a stack trace for the error you are getting? Also, if you can provide a repro code, it would be very helpful.

lvanderbijl commented 4 years ago

I think I was setting up xray incorrectly for .net4.6.

When I removed any explicit setup call for the xray recorder, the errors seem to have stopped.

This means, in .net4.6 applications all I do is add the AWSXRayPlugins entry to appsettings and register xray: AWSXRayASPNET.RegisterXRay(this, "WWW"); in global.asax.

I assume I don't need to set up anything further for basic xray logging?

lupengamzn commented 4 years ago

Hi @lvanderbijl

That should enable tracing on your app, also please take a look at the instruction if you need more information.

BlueMaegi commented 4 years ago

I'm seeing this error as well, using v2.6.2 with .Net 4.5. Basic logging works fine, but as soon as I add a custom trace with BeginSegment() it seems to lose it's connection to the HttpContext and throws the EntityNotAvailable exception.

lupengamzn commented 4 years ago

Hi @BlueMaegi

Can you provide some logs or stack trace for the exception? Also if there's a code repo for the project, that would be very helpful.

kairs commented 4 years ago

.Net 4.6.2 AWSSDK.XRay 3.3.102.31

We're uploading a large file and we get the same exception.

All we do is registering this in Global.asax

public override void Init() {
base.Init();
AWSXRayASPNET.RegisterXRay(this, "Orakel.Store"); }

A stack trace where this happens, :

Orakel.Store.OrakelStoreAppHost|Entity doesn't exist in HTTPContext|Amazon.XRay.Recorder.Core.Exceptions.EntityNotAvailableException: Entity doesn't exist in HTTPContext at Amazon.XRay.Recorder.Core.Internal.Context.HybridContextContainer.InjectEntityInTraceContext() at Amazon.XRay.Recorder.Handlers.AwsSdk.Internal.XRayPipelineHandler.ProcessBeginRequest(IExecutionContext executionContext) --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at Amazon.XRay.Recorder.Handlers.AwsSdk.Internal.XRayPipelineHandler.ProcessBeginRequest(IExecutionContext executionContext) at Amazon.XRay.Recorder.Handlers.AwsSdk.Internal.XRayPipelineHandler.d34`1.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.Runtime.Internal.CallbackHandler.d91.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.S3.Internal.AmazonS3ExceptionHandler.<InvokeAsync>d__11.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.Runtime.Internal.ErrorCallbackHandler.d5`1.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.Runtime.Internal.MetricsHandler.d11.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.S3.Transfer.Internal.MultipartUploadCommand.<UploadPartAsync>d__24.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.S3.Transfer.Internal.BaseCommand.<WhenAllOrFirstExceptionAsync>d__51.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Amazon.S3.Transfer.Internal.MultipartUploadCommand.d23.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.TaskAwaiter.GetResult() at Orakel.Core.Archive.ArchiveS3Provider.d17.MoveNext() in C:\TeamCity\BuildAgentK\work\2cf737ccd5feed25\Orakel.Core\Archive\ArchiveS3Provider.cs:line 244 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at System.Runtime.CompilerServices.TaskAwaiter.GetResult() at Orakel.Core.Archive.ArchiveProvider.d37.MoveNext() in C:\TeamCity\BuildAgentK\work\2cf737ccd5feed25\Orakel.Core\Archive\ArchiveProvider.cs:line 597 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at Orakel.Store.Archive.ArchiveService.d10.MoveNext() in C:\TeamCity\BuildAgentK\work\2cf737ccd5feed25\Orakel.Store\Archive\Service.cs:line 230 --- End of stack trace from previous location where exception was thrown --- at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at ServiceStack.Host.ServiceRunner`1.d__15.MoveNext()

matthewdouglas commented 4 years ago

@kairs That stack trace doesn't look like it is coming from an ASP.NET context. Are you sure you're not using AWSSDKHandler somewhere? If this is happening in ServiceStack's service host, you'll want to manually create a Segment when your request begins and end it when the request completes.