Deduplicate request logs, couple request<>response by UID

[ro0NL]

Q	A
Bug fix?	no
New feature?	yes
BC breaks?	no
Deprecations?	no
Related tickets	fixes #18
Documentation	if this is a new feature, link to pull request in https://github.com/php-http/documentation that adds relevant documentation
License	MIT

Given

httplug:
    clients:
        test:
            service: 'psr18.http_client'
            plugins:
                - httplug.plugin.logger
        test_with_error_handler:
            service: 'psr18.http_client'
            plugins:
                - httplug.plugin.logger
                - httplug.plugin.error

$request = $this->requestFactory->createRequest('GET', 'https://httpbin.org/status/200');
$requestError = $this->requestFactory->createRequest('GET', 'https://httpbin.org/status/500');

$this->test->sendRequest($request);
$this->test->sendRequest($requestError);
$this->testWithErrorHandler->sendRequest($requestError);

18:54:46 INFO      [httplug] Sending request:
GET https://httpbin.org/status/200 1.1 ["request" => Nyholm\Psr7\Request { …},"uid" => "61fd6866755f45.27019150"]
18:54:46 INFO      [httplug] Received response:
200 OK 1.1 ["request" => Nyholm\Psr7\Request { …},"response" => Nyholm\Psr7\Response { …},"milliseconds" => 490,"uid" => "61fd6866755f45.27019150"]

18:54:46 INFO      [httplug] Sending request:
GET https://httpbin.org/status/500 1.1 ["request" => Nyholm\Psr7\Request { …},"uid" => "61fd6866ed29b5.48079388"]
18:54:47 INFO      [httplug] Received response:
500 Internal Server Error 1.1 ["request" => Nyholm\Psr7\Request { …},"response" => Nyholm\Psr7\Response { …},"milliseconds" => 129,"uid" => "61fd6866ed29b5.48079388"]

18:54:47 INFO      [httplug] Sending request:
GET https://httpbin.org/status/500 1.1 ["request" => Nyholm\Psr7\Request { …},"uid" => "61fd686718a270.30706898"]
18:54:47 ERROR     [httplug] Error:
Internal Server Error
with response:
500 Internal Server Error 1.1 ["request" => Nyholm\Psr7\Request { …},"response" => Nyholm\Psr7\Response { …},"exception" => Http\Client\Common\Exception\ServerErrorException { …},"milliseconds" => 107,"uid" => "61fd686718a270.30706898"]

For me this works OK, and could go as a patch release. But any next version works for us 👍

[dbu]

thanks, looks good to me. can you please look at the failing tests? i think the tests have assertions on how the logger is called (which makes sense, as this is the whole purpose of this plugin).

i think i see this as a new minor version, as it adds something significant.

please add a note to the changelog about the change. i think it would be correct to mention there to configure a logger with the fingerscrossed behaviour (don't need detailed instructions, just mention it so people can find the doc if they are not familiar). because if you only log something more severe than info, this new behaviour will no longer let you see the request that led to an error.

[dbu]

we should also update https://github.com/php-http/documentation/blob/master/plugins/logger.rst to have the example use a fingers crossed logger and a note why we use that instead of a straight logger.

[ro0NL]

@dbu done. I'll let you update docs, i dont see how "fingerscrossed" is relevant. We always log certain channels, that are used dedicated for http traffic.

[dbu]

you still specify the request in the context. is that on purpose?

[ro0NL]

yes, i left other context entries untouched.

this is for #16 to solve, but in CLI it works well:

16:07:07 INFO      [app] Received response:
HTTP/1.1 200 OK

[
  "request" => GuzzleHttp\Psr7\Request {
    -method: "GET"

i wouldnt mind if these are dropped though :) if these objects become stringable/serializable one day, it starts leaking into prod logs.

Arguably, even in dev env it's just noise.

[dbu]

thanks a lot!

i addjusted the changelog and squashed commits, then merged locally.

[dbu]

i wait with tagging until #16 is clarified and maybe php-http/message#146 as well