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

[HttpClient][MonologBridge] Add HttpClientProcessor to debug HttpClient errors #35659

Open
wants to merge 1 commit into
base: master
from

Conversation

@B-Galati
Copy link
Contributor

B-Galati commented Feb 10, 2020

Q A
Branch? master
Bug fix? no
New feature? yes/no
Deprecations? no
Tickets Fix #34289
License MIT
Doc PR symfony/symfony-docs#...
  • Tests
  • Doc
  • Changelog

Add HttpClient monolog processor that will write http request / response info in log context.
It can help debugging 4XX / 5XX in a prod context.

Processor can be enabled like this:

services:
    Symfony\Bridge\Monolog\Processor\HttpClientProcessor:
        tags:
            - { name: monolog.processor }
@B-Galati B-Galati changed the title [MonologBridge] Add HttpClientProcessor to debug HttpClient errors [HttpClient][MonologBridge] Add HttpClientProcessor to debug HttpClient errors Feb 10, 2020
…nt errors
@B-Galati B-Galati force-pushed the B-Galati:34289_http_client_monolog_processor branch from de54fe9 to 6ef1c2e Feb 10, 2020
@B-Galati

This comment has been minimized.

Copy link
Contributor Author

B-Galati commented Feb 10, 2020

@nicolas-grekas

At the moment the processor is not able to log http client content for some reasons.

I try to dig a bit and observed that this code is able to get the response content while the processor cannot:

$response = $this->httpClient->request('GET', 'https://127.0.0.1:8000/sleep/1/throw');
try {
    $response->getContent();
} catch(HttpExceptionInterface $e) {
    dump($e->getResponse()->getContent(false));
}

My guess is that the CurlResponse::__destruct is doing stuff that may trash/cancel the request/response.

@nicolas-grekas

This comment has been minimized.

Copy link
Member

nicolas-grekas commented Feb 10, 2020

If you don't read the content, neither will the client. The destructor will ensure headers arrived and close the stream just after. Why would it care about the body if the app doesn't ?

@B-Galati

This comment has been minimized.

Copy link
Contributor Author

B-Galati commented Feb 10, 2020

@nicolas-grekas Thanks for the quick answer.

For example, I was calling an API to update a user profile but that request ends in a 400 because one of the field was wrongly formatted.
The only way to know which field and why, was to read the response content.

@nicolas-grekas nicolas-grekas added this to the next milestone Feb 10, 2020
@nicolas-grekas

This comment has been minimized.

Copy link
Member

nicolas-grekas commented Feb 10, 2020

Then this should be done on the app's side, not in the processor (or you're taking the risk of logging an ISO/AVI file content...)

@B-Galati

This comment has been minimized.

Copy link
Contributor Author

B-Galati commented Feb 10, 2020

Then this should be done on the app's side, not in the processor (or you're taking the risk of logging an ISO/AVI file content...)

That's quite cumbersome to do sadly but I see your point. What do you think if we add safe guards like:

  • Check content size before downloading it? if it's too large let's not even log it.
  • Check if the content-type is safe for logging or not? Whitelist some of them like json, xml, text, etc.

At the moment the processor truncates the content in log after 10.000 characters.

@nicolas-grekas

This comment has been minimized.

Copy link
Member

nicolas-grekas commented Feb 10, 2020

How are people going to enable this processor? Maybe you can update the description of the PR to hint about this as that'd help write the doc afterward?
If it's via service configuration, then providing constructor arguments telling which content-types should log the body might be a fit?
Don't miss fabbot's report, adding tests and a line in the changelog of course :)

@B-Galati

This comment has been minimized.

Copy link
Contributor Author

B-Galati commented Feb 10, 2020

How are people going to enable this processor? Maybe you can update the description of the PR to hint about this as that'd help write the doc afterward?

Updated.

If it's via service configuration, then providing constructor arguments telling which content-types should log the body might be a fit?

Yeap!

Don't miss fabbot's report, adding tests and a line in the changelog of course :)

Yeap it's on my todo but I wanted to talk about it before going too far for 2 reasons:

  • The response content is not logged when the Exception is thrown by CurlResponse::__destruct() and it was the big plus of the feature; at least to me. It is working at the moment for me with Symfony 4.3. I don't know what changed in 5.x. I am not sure to end this PR if I cannot get this working as it was the main reason I did it in the 1st place.
  • We talk about having the processor not breaking asynchronicity of the client in the issue but I don't really get how to achieve it.
@nicolas-grekas

This comment has been minimized.

Copy link
Member

nicolas-grekas commented Feb 10, 2020

The response content is not logged when the Exception is thrown by CurlResponse::__destruct()

I don't get this issue as the response is not destructed yet when the exception is processed, so you should be able to get the body

the processor not breaking asynchronicity

that's not possible, but if this is opt-in (eg by default the body is ever logged), then this is fine I think.

@B-Galati

This comment has been minimized.

Copy link
Contributor Author

B-Galati commented Feb 10, 2020

I don't get this issue as the response is not destructed yet when the exception is processed, so you should be able to get the body

I will set up a reproducer tomorrow hopefully.

that's not possible, but if this is opt-in (eg by default the body is ever logged), then this is fine I think.

Thanks! So what did you have in mind with this comment #34289 (comment)?

@nicolas-grekas

This comment has been minimized.

Copy link
Member

nicolas-grekas commented Feb 10, 2020

My previous comment is not very relevant in the context of errors :)

@B-Galati

This comment has been minimized.

Copy link
Contributor Author

B-Galati commented Feb 11, 2020

@nicolas-grekas Hello! Here is the reproducer https://github.com/B-Galati/symfony_reproducer_34289

Let me know for anything.

while ($exception instanceof \Throwable) {
if ($exception instanceof HttpExceptionInterface) {
// It needs to be the 1st statement in order to fulfil the response info
$responseContent = $exception->getResponse()->getContent(false);

This comment has been minimized.

Copy link
@nicolas-grekas

nicolas-grekas Feb 11, 2020

Member

this must be wrapped in a try/catch(TransportExceptionInterface)


$record['context']['http_client'][] =
$exception->getResponse()->getInfo()
+ ['response_content' => mb_strimwidth($responseContent, 0, 10000)]

This comment has been minimized.

Copy link
@nicolas-grekas

nicolas-grekas Feb 11, 2020

Member

mb_strimwidth is random to me (all mb_* without encoding arguments are, relying on global state).

This comment has been minimized.

Copy link
@B-Galati

B-Galati Feb 11, 2020

Author Contributor

Do you think it should be removed? What would be the alternative otherwise, specify the $encoding argument?

This comment has been minimized.

Copy link
@B-Galati

B-Galati Feb 11, 2020

Author Contributor

I guess it can be removed if the response size is checked before trying to get the content. WDYT?

fabpot added a commit that referenced this pull request Feb 11, 2020
…ctor throwed an HttpExceptionInterface (nicolas-grekas)

This PR was merged into the 4.4 branch.

Discussion
----------

[HttpClient] fix getting response content after its destructor throwed an HttpExceptionInterface

| Q             | A
| ------------- | ---
| Branch?       | 4.4
| Bug fix?      | yes
| New feature?  | no
| Deprecations? | no
| Tickets       | -
| License       | MIT
| Doc PR        | -

Spotted by @B-Galati in #35659 (comment)

Commits
-------

6d1657b [HttpClient] fix getting response content after its destructor throwed an HttpExceptionInterface
@buteihua

This comment has been minimized.

Copy link

buteihua commented Feb 11, 2020

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked issues

Successfully merging this pull request may close these issues.

4 participants
You can’t perform that action at this time.