Capture request body aspnet core#402
Conversation
initial feature commit - Added config values + behavior in the Apm middle-ware class. Errors body extraction still pending.
Had to make minor changes to the code due to some name changes.
|
FIY - all the tests related to new feature run successfully in my machine (there is one that fails - register user test which expects a web service that's not running ). I'm not sure why there are conflicts. I have the latest version of master locally, branched of course, but still - up to date. There shouldn't be any conflicts. |
|
@katzdan thanks for the PR! To address your question:
Maybe you already figured this out, but just in case: There are 2 ways when we create errors in ASP.NET Core.
As you can see in this screenshot you have access to the
Now one thing you can already do is that before we catch the error you simply set the A nicer way would be to give you access to the error before it's sent out, but that'd require more refactoring, and I think it'd better to do that in a separate PR. So probably the option described above would be more feasible. Hope this helps. |
|
I recommend to test use cases with
By testing I don't imply we have to capture request body in these use cases (it's worth syncing with other agents) - we should have tests verifying whatever is decided agent should do in these use cases. |
I'm not sure this is the case. I think your branch does not have #374. If you compare e.g |
|
Thanks @SergeyKleyman , @gregkalapos , I'll implement according to your guidelines and report back here. |
gregkalapos
left a comment
There was a problem hiding this comment.
I went through the code, added some comments.
Most of them are just small things, but the exception I mention is something which we should think about. Other than those, in my view this definitely goes the right direction. 👍👍
Thanks for your effort @katzdan!
| var captureBodyInConfig = kv.Value; | ||
| if (string.IsNullOrEmpty(captureBodyInConfig)) | ||
| { | ||
| return ConfigConsts.SupportedValues.CaptureBodyOff; |
There was a problem hiding this comment.
nit: why not return DefaultValues.captureBody here, as below?
There was a problem hiding this comment.
In order not have to deal with a null/empty value passed in the config file or env variables. Let me know if you prefer to change that. I'd feel better to align the code to the preference of the devs with more experience in this project.
There was a problem hiding this comment.
I'm not sure I can follow you.
So, this is the part I talk about:
if (string.IsNullOrEmpty(captureBodyInConfig))
{
return ConfigConsts.SupportedValues.CaptureBodyOff;
}
All I suggest is to replace ConfigConsts.SupportedValues.CaptureBodyOff with DefaultValues.captureBody, because in case the entered value is null or an empty string we want to return the default value - which is indeed the same as ConfigConsts.SupportedValues.CaptureBodyOff, it just communicates the intent better.
So in this sense... we do deal with null/empty values: we simply return the default in that case.
There was a problem hiding this comment.
Done. code is pushed.
| { | ||
| using (var reader = new StreamReader(context.Request.Body)) | ||
| { | ||
| body = reader.ReadToEnd(); |
There was a problem hiding this comment.
I see some exceptions here when I run the sample app:
fail: Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware[1]
An unhandled exception has occurred while executing the request.
System.IO.IOException: Unexpected end of Stream, the content may have already been read by another component.
at Microsoft.AspNetCore.WebUtilities.MultipartReaderStream.ReadAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.StreamHelperExtensions.DrainAsync(Stream stream, ArrayPool`1 bytePool, Nullable`1 limit, CancellationToken cancellationToken)
at Microsoft.AspNetCore.WebUtilities.MultipartReader.ReadNextSectionAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Http.Features.FormFeature.InnerReadFormAsync(CancellationToken cancellationToken)
at Microsoft.AspNetCore.Mvc.ModelBinding.FormValueProviderFactory.AddValueProviderAsync(ValueProviderFactoryContext context)
at Microsoft.AspNetCore.Mvc.ModelBinding.CompositeValueProvider.CreateAsync(ActionContext actionContext, IList`1 factories)
at Microsoft.AspNetCore.Mvc.ModelBinding.CompositeValueProvider.CreateAsync(ControllerContext controllerContext)
at Microsoft.AspNetCore.Mvc.Internal.ControllerBinderDelegateProvider.<>c__DisplayClass0_0.<<CreateBinderDelegate>g__Bind|0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync()
at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
I googled this and it seems to be a common thing. This one suggest disabling model binding, but that does not help in our case - we can't tell this to all our users.
I'm trying to help here and come up with something. I'd say this is definitely something where we should come up with a solution for.
There was a problem hiding this comment.
Looking into this as well.
There was a problem hiding this comment.
@gregkalapos - I wasn't able to reproduce this problem (please provide instructions on who to do it). However - the problem of an "already read" request/response stream is a well known one. There are several approaches to resolve this , with the one most appropriate for this problem being
- Resetting the body stream reader to position 0 when it's supported.
- Reading the body and then writing it back to the memory to prevent subsequent attempts to the read the body from failing.
I'm implementing and testing it now.
There are other solutions which cannot be used for various reasons -
- EnableRewind() for all requests in the pipeline but that would mean we are changing the behavior of the web app on the server.
- Request.EnableBuffering() would have resolved this problem but is only available from .Net core 2.1.
refs :
https://gunnarpeipman.com/aspnet/aspnet-core-request-body/
http://www.palador.com/2017/05/24/logging-the-body-of-http-request-and-response-in-asp-net-core/
https://devblogs.microsoft.com/aspnet/re-reading-asp-net-core-request-bodies-with-enablebuffering/
There was a problem hiding this comment.
Code committed. Please check on your end if possible or provide instructions for recreating this problem.
There was a problem hiding this comment.
How do you test? I simply sent an HTTP POST to http://localhost:5000/api/Home/Post with Postman. If I remember correctly, HTTP GET requests from a browser did not repro the problem for me either (I should have said this earlier.)
To the current version: I still see some problems, and this time it happens always:
Application started. Press Ctrl+C to shut down.
fail: Elastic.Apm[0]
{ApmMiddleware} General Error reading request body , Error msg : Specified method is not supported. , stack trace : at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.set_Position(Int64 value)
at Elastic.Apm.AspNetCore.Extensions.HttpRequestExtensions.ExtractRequestBody(HttpRequest request, IApmLogger logger) in /Users/gergelykalapos/Repos/apm-agent-dotnet/src/Elastic.Apm.AspNetCore/Extensions/RequestExtentions.cs:line 28
fail: Elastic.Apm[0]
{ApmMiddleware} General Error reading request body , Error msg : Specified method is not supported. , stack trace : at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpRequestStream.set_Position(Int64 value)
at Elastic.Apm.AspNetCore.Extensions.HttpRequestExtensions.ExtractRequestBody(HttpRequest request, IApmLogger logger) in /Users/gergelykalapos/Repos/apm-agent-dotnet/src/Elastic.Apm.AspNetCore/Extensions/RequestExtentions.cs:line 28
^CApplication is shutting down...
It's very strange that on this post no one mentions this problem.
Doesn't this happen on your machine?
This GitHub issue is the same: aspnet/KestrelHttpServer#1548
And the solution for that is to call request.EnableRewind(); - that's currently not available, for that we need a reference to the Microsoft.AspNetCore.Http package. But it's still very strange that on the 1. blogpost people seem to suggest that as an alternative, and no one says that the original version without request.EnableRewind(); does not seem to work. It defiantly fails on my machine and the referenced GitHub issue seems to verify that without request.EnableRewind(); it should not work.
There was a problem hiding this comment.
@gregkalapos - I tested using the SampleAspNetCoreApp and with test methods (
TestJsonBodyRetrievalOnRequestFailureInAspNetCore, FailingPostRequestWithoutConfiguredExceptionPage, HomeSimplePagePostTransactionTest, all in AspNetCoreMiddlewareTests.cs).
I'll try it your way. The test methods for this worked but since I merged master into my working branch - these tests fail. It looks like the initialization of the agent in the test method (with the captureBody setting being set to all/errors/transactions) is being ignored and then debugging I can see that the loaded value in the website being used in the test is "off". I'm still trying to understand why this is happening.
There was a problem hiding this comment.
I removed the request.body.position=0 statement after re-creating the problem.
Still working on the 'Unexpected end of Stream' problem (Which I haven't been able to recreate yet).
@SergeyKleyman - I started to go over the resources you mentioned and will comment with some recommendations. @SergeyKleyman - The Apm agent Java implementation supports collection of UTF-8 encoded plain text content types. It would make sense to do the same with the dotnet agent. Let me know what you think. |
This commit includes the following :
1. Errors monitoring now supports the 'captureBody' feature + tests.
2. Values Controller is removed, the Post methods for testing have been moved to the Home Controller.
3. Refactoring : Functionality of the request body retrieval has been moved to an extension method class ('RequestExtensions.cs').
4. Added more tests.
5. Small changes to captureBody default values in tests.
1. Added request body capturing in the ApmMiddle InvokeAsync method. 2. Added a test to verify this scenario. 3. Refactored some of the code that determines if the agent should capture the request body for better readability and maintainability.
|
@gregkalapos - I added the second case of error handling in ApmMiddleware.cs. |
I recommend to follow Java agent approach - https://www.elastic.co/guide/en/apm/agent/java/current/config-http.html#config-capture-body-content-types Please note that |
|
@katzdan If you arrive to conclusion that supporting Chunked transfer encoding and/or HTTP compression is a lot of additional effort we can declare those use cases as not supported for now and see if there is any demand for them from the customers. |
|
@SergeyKleyman - indeed, I think that supporting text content is enough for now. Supporting these cases would increase the amount of code here considerably. I think it would make sense to align with the Java agent and add support for non text content types in the future based on customers' input. |
Yeah, I'd also take this approach.
Regarding the conflicted changed: It seems you resolved those 👍 |
gregkalapos
left a comment
There was a problem hiding this comment.
@katzdan - adding some other small things I saw in the code.
| @@ -1,5 +1,6 @@ | |||
| using System; | |||
| using System.Collections.Generic; | |||
| using System.IO; | |||
There was a problem hiding this comment.
nit: this is unused - it can be removed.
There was a problem hiding this comment.
I did a file clean-up in my last commit.
| } catch (IOException ioException){ | ||
| logger.Error()?.Log("IO Error reading request body , Error msg : {exception} , stack trace : {stacktrace} " , ioException.Message , ioException.StackTrace); | ||
| } catch (Exception e) { | ||
| //TODO : remove this after havning finalized all cases and testing all scenarios |
There was a problem hiding this comment.
Not sure we should remove this. Keep in mind that there is no other try-catch outside of this. So somehow, just to sleep well we should make sure no exception caused by the agent can escape from this - e.g. on my machine currently die to the exception on request.Body.Position = 0; (discussed separately) would crash the whole app.
Either we deal with it here, or we make sure on the caller side that there is no case which could affect the application.
There was a problem hiding this comment.
If there is no exception handler in a wrapper context (calling function/class etc) then obviously we need to keep the general exception handler block. I'll remove the comment.
There was a problem hiding this comment.
👍 Sounds good! We plan to have a better solution for this long term (#208) but currently every exception caused by the agent will bubble up to the user code unless we manually try-catch.
|
|
||
| } | ||
| } catch (IOException ioException){ | ||
| logger.Error()?.Log("IO Error reading request body , Error msg : {exception} , stack trace : {stacktrace} " , ioException.Message , ioException.StackTrace); |
There was a problem hiding this comment.
jfyi: we have an overload that logs the exception for you:
logger.Error()?.LogException(ioException, "IO Error reading request body");
The result is same to what you did here manually.
Same below.
There was a problem hiding this comment.
I updated the code to use logger.Error()?.LogException.
1. Created a new Exception filter in the Elastic.Apm.AspNetCore project to be used instead of the Elastic.Apm one (to enable request body capturing). 2. Added the configuration option 'CaptureBodyContentTypes' that defines which request content types will be matched with the requests. The default value is common text content types : application/x-www-form-urlencoded* text/* application/json* application/xml* 3. Some refactoring and code-arranging. 4. Added some tests
|
@gregkalapos , @SergeyKleyman - I'm done with the implementation, with 3 issues:
|
|
@SergeyKleyman , @gregkalapos , |
|
@katzdan Hi Dan. We have a few urgent things to finish for the latest release and we will get back to this feature ASAP. |
|
Hey @katzdan, sorry for the delay!
I think we are almost done here. :) |
|
@gregkalapos , @SergeyKleyman -
|
All sounds good @katzdan 👍 |
1. Added a reference to 'Microsoft.AspNetcore.Http' ver 2.0.0 2. Added a call to 'EnableRewind' when reading the request body and reset the body stream position to 0 after that in case subsequent readings of the body. 3. Removed a commented line in AspNetCoreMiddlewareTests.cs
|
@gregkalapos , @SergeyKleyman - |
Thanks, great; will take a look at it soon! |
|
hi all, Thanks, |
Hi @skynet2, yes, that's exactly what's happening here. In this PR the reading of the request body happens in the So I think we have the same approach here as in your code. Or do I miss something? |
gregkalapos
left a comment
There was a problem hiding this comment.
I went through it again, this looks good to me, thank you very much @katzdan! 🚀
There are some minor code styling things - I started focusing more on those, because sometimes people run auto cleanup before they open a PR and all those tiny things are reformatted based on the .editorconfig causing lots of minor code style changes without any functional change and that makes PRs harder to review. Once there aren't too many PRs open I'll do a bigger cleanup (see #427) If you want I can quickly fix those, just let me know - otherwise just feel free to push it.
Other than that I think this is ready to merge. Thanks again!
| Ms, | ||
| S | ||
| } | ||
|
|
There was a problem hiding this comment.
nit: there are 2 new lines here.
Codecov Report
@@ Coverage Diff @@
## master #402 +/- ##
==========================================
- Coverage 79.36% 79.01% -0.35%
==========================================
Files 80 84 +4
Lines 2777 2812 +35
Branches 517 509 -8
==========================================
+ Hits 2204 2222 +18
- Misses 385 394 +9
- Partials 188 196 +8
Continue to review full report at Codecov.
|
|
@gregkalapos - I'll make the changes today or tomorrow. |
Several small code clean up changes.
|
@gregkalapos - I pushed the files updated in the code clean up. You can merge this into the Master branch unless there are additional changes to be implemented. |
Remove some unused fields
|
Merged! 🎉 Thanks for your work and your patience on this @katzdan. Welcome on the contributors list! 🚀 |
|
Hi pals,
I received the following log message with does not show what the body request and response are: |
|
Hi @brezaie I see you don’t configure Also please note that this PR is only about capturing the |
|
Hi @gregkalapos Thanks for your response. It did work now. Do you have any plans for adding the |
Unfortunately we have no such plans currently. |
|
Dear @gregkalapos Thanks for your reply. When adding the following configuration, surprisingly, I receive a Here is my |
Thanks for reporting this @brezaie. This is not good - I also managed to reproduce this. I opened a separate bug for this: #460. If there is anything to add to it, feel free to comment there. |



Closes #213
initial feature commit -
Added config values + behavior in the Apm middle-ware class.
Errors body extraction still pending.
@SergeyKleyman , @gregkalapos
As there are differences between the node.js and java docs - Iv'e kept the implementation to whatever is common :
please let me know if anything else is required for this feature.
I added tests to verify this works along side a test that creates a 'post' http call ad in order for that to work properly I added a new controller that accepts post requests to the 'SampleAspNetCoreApp' project. There are other controllers that have post actions but these redirect the UI to another page and that would have made the tests more complicated.
There is one part of the implementation I don't know how to do - when the 'captureBody' is set to 'errors' than the apm module should retrieve the body from the request but there is no HttpContext in the error class or anywhere in the classes that handle this scenario. I'll need some guidance with this.