8p / EightPointsGuzzleBundle

⛽️ Integrates Guzzle 6.x, a PHP HTTP Client, into Symfony
MIT License
440 stars 71 forks source link

$response->getBody()->getContents() returns always empty content #48

Closed marcj closed 7 years ago

marcj commented 8 years ago
$ composer show --installed | grep guzzle
eightpoints/guzzle-bundle            v4.5.1             Integrates Guzzle into Symfony2, comes with WSSE Plugin for RESTful Interfaces
eightpoints/guzzle-wsse-middleware   v4.2.0             WSSE Middleware for Guzzle, a PHP HTTP client library and framework for building RESTful web service clients
guzzlehttp/guzzle                    6.2.0              Guzzle is a PHP HTTP client library
guzzlehttp/promises                  1.2.0              Guzzle promises library
guzzlehttp/psr7                      1.3.0              PSR-7 message implementation

My code:

$response = $this->githubClient->post('access_token', ['form_params' => $params]);
$response = $response->getBody()->getContents(); //empty string ''

$this->githubClient is a \GuzzleHttp\Client instance configured through the guzzle bundle.

This whole stuff works, when I run $response->getBody()->rewind(); before getContents call.

$response = $this->githubClient->post('access_token', ['form_params' => $params]);
$response->getBody()->rewind();
$response = $response->getBody()->getContents(); //string '{blaa}'

I guess it has something todo with this bundle, as it reads already the body for the profiler tab. I guess you should call rewind() when you read the body for your purposes. However, I'm not sure about it yet as I haven't looked into the code.

siraic commented 8 years ago

GuzzleBundle/Log/LogResponse.php:70 and GuzzleBundle/Log/LogRequest.php:103 read the full body without resetting the pointer after.

Best would probably be if they store the location of the pointer, read the contents, and reset it to previous point after reading.

As a quick fix you can use __toSting() instead of getContents(); __toString() will always read from the start of the stream.

example solution, and more discussion of a similar issue: https://github.com/guzzle/guzzle/pull/1262#issuecomment-149080749

florianpreusner commented 8 years ago

Released new bugfix versions:

florianpreusner commented 8 years ago

Thanks for contribution, @siraic!

ThomasTr commented 7 years ago

This issue seems not solved. I have the same behaviour here: If logging: true i have to rewind to see the body. I'm on eightpoints/guzzle-bundle": "^5.1"

florianpreusner commented 7 years ago

To take a closer look into this issue it would be great if you can check if the new code is really executed: https://github.com/8p/GuzzleBundle/blob/3c309629b8b93cc65d7654e18b878b31aab78613/Log/LogRequest.php#L100

ThomasTr commented 7 years ago

Hi Florian, code is executed, when logging is enabled. I modified therefore the code a little bit:

        if($request->getBody() && $request->getBody()->isSeekable()) {
            $readPosition = $request->getBody()->tell();
            var_dump($readPosition);
        }

        $this->setBody($request->getBody() ? $request->getBody()->__toString() : null);

        if($readPosition) {
            $request->getBody()->seek($readPosition);
            var_dump('rewinded');
        }

This is my request with some debug output:

          $campaignResponse = $this->apiClient->post('campaigns', [
                'body' => json_encode( ['some data']
            ]);

            var_dump($campaignResponse->getBody()->getContents());
            $campaignResponse->getBody()->rewind();
            var_dump($campaignResponse->getBody()->getContents());`

And this is the response:

int 321
string 'rewinded' (length=8)
string '' (length=0)
string '{"the response data..."}' (length=2721)
siraic commented 7 years ago

Hi ThomasTr,

The first output indicates that the read position is already at 321 before the guzzle bundle logging starts. Our code doesn't fully rewind, but puts the pointer back where it found it. I think you have other logging(?) middleware earlier in your handler stack that already consumed the body without rewinding.

ThomasTr commented 7 years ago

Hi,

i do only the normal logging into several channels, nothing special.

emirb commented 7 years ago

Same problem here, even with a clean Symfony install, meaning that turning on this bundle's logging effectively breaks responses.

Steps to reproduce

  1. Install Symfony 3.1 using Symfony installer:

    symfony new 3.1
    
    Downloading Symfony...
    
    5.1 MiB/5.1 MiB ▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓  100%
    
    Preparing project...
    
    ✔  Symfony 3.1.7 was successfully installed. Now you can...
  2. Require the bundle via composer:

    
    composer require eightpoints/guzzle-bundle

Using version ^5.1 for eightpoints/guzzle-bundle ./composer.json has been updated Loading composer repositories with package information Updating dependencies (including require-dev)

Writing lock file Generating autoload files

Incenteev\ParameterHandler\ScriptHandler::buildParameters Updating the "app/config/parameters.yml" file Sensio\Bundle\DistributionBundle\Composer\ScriptHandler::buildBootstrap Sensio\Bundle\DistributionBundle\Composer\ScriptHandler::clearCache

// Clearing the cache for the dev environment with debug true

[OK] Cache for the "dev" environment (debug=true) was successfully cleared.

Sensio\Bundle\DistributionBundle\Composer\ScriptHandler::installAssets

Trying to install assets as relative symbolic links.


  Bundle            Method / Error

✔ FrameworkBundle relative symlink


[OK] All assets were successfully installed.

Sensio\Bundle\DistributionBundle\Composer\ScriptHandler::installRequirementsFile Sensio\Bundle\DistributionBundle\Composer\ScriptHandler::prepareDeploymentTarget

  1. Load the bundle in AppKernel

  2. Add a sample debugging client in config.yml with logging enabled:

    guzzle:
    # (de)activate logging/profiler; default: %kernel.debug%
    logging: true
    
    clients:
        httpbin:
            base_url: "https://httpbin.org"
  3. Sample controller code:

        $client = $this->get('guzzle.client.httpbin');
        $response = $client->get('/get');
        $body = $response->getBody()->getContents();
        var_dump($body);

$body is an empty string: string(0) ""

The profiler tab shows request/response correctly: image

A fix would be to rewind the request in Log/LogResponse:77

By adding simple

$response->getBody()->rewind();
florianpreusner commented 7 years ago

The problem is that $response->getBody()->getContents() is not changing the position of seek to 0. So when using getContents() this behavior appears. When using __toString() or (string) $response->getBody() everything works fine because this function uses rewinding: https://github.com/guzzle/psr7/blob/master/src/Stream.php#L93

I think it's totally valid to rewind directly in Log/LogResponse:77 like suggested by @emirb. I will change/implement that.

florianpreusner commented 7 years ago

Implemention/Fix can be found in following PR: https://github.com/8p/GuzzleBundle/pull/80 Would be awesome if someone can check if everything works like expected. Did some tests, should be fine.

Going to release a new version tomorrow evening (Monday, December 12, 10pm) if nothing gets reported.

florianpreusner commented 7 years ago

Released v5.2.1: https://github.com/8p/GuzzleBundle/releases/tag/v5.2.1