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

[9.x] memory exhausted because JSON payload is unwanted parsed twice by Illuminate\Http\Request::createFromBase #42403

Closed
MircoBabin opened this issue May 16, 2022 · 25 comments

Comments

@MircoBabin
Copy link

  • Laravel Version: 9.12.2
  • PHP Version: PHP 8.1.4 (cli) (built: Mar 16 2022 09:33:31) (ZTS Visual C++ 2019 x64)
  • Database Driver & Version: MySql 8.0.16

Description:

I have an api POST route with json contents. Very unexpected this route was giving Allowed memory size of 134217728 bytes exhausted (tried to allocate ... bytes) errors.

To debug this issue:

  1. I adjusted public/index.php so the request would run to the end and would not be aborted by memory exhausted errors.
ini_set("memory_limit", "-1");
  1. I attached XDEBUG in profile mode.

  2. I replayed the request.

  3. I used QCacheGrind to visualize the profile:

image

As the profile shows, Illuminate\Http\Request::createFromBase via Request->json() calls json_decode() twice. Which is unwanted, because I don't use the Request::json() to retrieve the json contents. I do my own json_decode((string) Request::getContents()).

I did some digging in the Laravel History and found the commit introducing the json_decode behaviour in [9.x]: 13e4a7f The commit message states: ... This commit solves the underlying issue without breaking compatibility with the original functionality. ...

This commit is breaking compatibility, because it does not take memory consumption into account. Neither does it take performance into account, decoding the same request body twice is performance degradation. For large JSON (in my case Content-Length: 6428178) this can easily lead to memory exhausted errors. In Laravel 7.x there was no memory exhausted error.

@lk77
Copy link

lk77 commented May 16, 2022

You can remove your json_decode and use the decoded data in the request instead, with $request->all() for example, to retrieve the whole decoded data, you can also use ->get('key') to retrieve a specific field in your json, you can even use ->input('root.sub') to retrieve nested data, so there is no need to do your own json decode

If you have to do that, you should do it in your custom request (or create one with you don't use one), by overriding the ->json() method to ensure that data is not decoded twice and is consistent, but there is no reason to do it in 99% of the cases, the only exception is json_decode flags that you might need

And for the underlying issue, in my testings, json() is called once by createFromBase :

Screenshot from 2022-05-16 18-25-39

clean function does seems to do extra calls to json though

@rodrigopedra
Copy link
Contributor

@IK77 Request@json has an if clause to only decode the JSON payload if it was not yet decoded.

if (! isset($this->json)) {
$this->json = new ParameterBag((array) json_decode($this->getContent(), true));
}

So the subsequent calls doesn't call json_decode again.

@MircoBabin the change introduced in 13e4a7f

Replaced this call:

$newRequest->request = $newRequest->getInputSource();

By this:

if ($newRequest->isJson()) {
$newRequest->request = $newRequest->json();
}

So, before it called Request@getInputSource to fill the request, which in turn already decoded JSON requests on its own, since 2013, as you can see in this commit: e7f07b9

protected function getInputSource()
{
if ($this->isJson()) {
return $this->json();
}
return in_array($this->getRealMethod(), ['GET', 'HEAD']) ? $this->query : $this->request;
}

Request@createFromBase has been calling Request@getInputSource, and by consequence decoding JSON requests, since 2015, introduced by this commit: 9312bec

Bottom line: I think it is very unlikely this behavior will be changed by maintainers after so many years.

You could take @IK77 suggestions and either use the already decoded data, or if really want to decode it yourself, maybe to use different parameters on json_decode, you can:

  • extend the Illuminate/Http/Request class
  • override its createFromBase method and avoid JSON parsing
  • Modify your app's ./public/index.php to use your Request subclass
  • Bind your subclass to Illuminate/Http/Request on your apps' AppServiceProvider@register method, this would look something like this:
class AppServiceProvider extends ServiceProvider
{
    public function register()
    {
        $this->app->bind(\Illuminate\Http\Request::class, \App\Http\Request::class);
    }

    public function boot()
    {
    }
}

Note, while FormRequests will still extend the original Request class and not your subclass, they are hydrated from the request resolved from the container, which after binding it to the container, will be an instance of your subclass.

$this->app->resolving(FormRequest::class, function ($request, $app) {
$request = FormRequest::createFrom($app['request'], $request);
$request->setContainer($app)->setRedirector($app->make(Redirector::class));
});

Hope this helps you solve your issue.

@rodrigopedra
Copy link
Contributor

@driesvints after doing research to answer @MircoBabin , I noted PR #37921 , which introduced the check if a request is a JSON request before replacing its $request property, apparently didn't change anything as Request@getInputSource already did that check internally.

Actually the tests (one changed, and one added) on that PR, both passes if one reverts the change made by it.

I am not sure it makes any change if reverted, as for non-JSON requests Request@getInputSource would return the contents of $request->request anyways which are already populated on the Request@duplicate call some lines above, but it is curious tests passed without the proposed change.

I have no idea on how to do so, but maybe there is a way to automate to check if any added tests fail before committing a PR's proposed change?

@driesvints
Copy link
Member

Thanks @rodrigopedra.

@LukeTowers could you weigh in here?

@MircoBabin
Copy link
Author

I have taken @IK77 advice and do not json_decode() myself anymore. Instead i'm using Request::json() now.

But still I'm getting memory exhausted because Laravel is decoding twice. Here is new the profile:

image

@MircoBabin
Copy link
Author

@rodrigopedra thanks for you detailed explanation. So it seems I'm wrong concluding 13e4a7f was the commit introducing wrong behaviour.

Your solution to extend the Illuminate/Http/Request, while being a very creative solution, is not really a viable solution. Upon each Laravel update I still would have to compare the Request::createFromBase with the extended class.

Walking this path it would be easier to just directly modify the Illuminate/Http/Request.php source file, what would break with each Laravel update. I could write a test for this, that would fail after update. But I'm not going to take this path, as it is not maintainable in the long run. (Yep against all best practices, I am committing the vendor directory. Because on shared webhosting you can't composer install, there is no shell. Using DeployHQ ftp deployment with a committed vendor directory is the easiest solution.)

@driesvints
Copy link
Member

To be fair, isn't the real issue that your JSON payloads are simply too large? What kind of payloads are you handling?

@MircoBabin
Copy link
Author

The payloads are order request payloads for renting a touringcar. In the payload also is the calculated Google Maps route present. That together constitutes a lot of bytes.

The http-payload is ~7 MB, which is not that big. Json_decoded() it becomes ~69MB, which still is not beyond default PHP limits.

But then comes Laravel, deciding to decode twice and keeping 2 copies in memory. So claiming 2 times 69MB which is beyond the default PHP limits.

@taylorotwell
Copy link
Member

If you have a solution to this issue that does not break other use cases please PR it. Thank you.

@LukeTowers
Copy link
Contributor

after doing research to answer @MircoBabin , I noted PR #37921 , which introduced the check if a request is a JSON request before replacing its $request property, apparently didn't change anything as Request@getInputSource already did that check internally.

I am not sure it makes any change if reverted, as for non-JSON requests Request@getInputSource would return the contents of $request->request anyways which are already populated on the Request@duplicate call some lines above, but it is curious tests passed without the proposed change.

@rodrigopedra thanks for your detailed response! My change however is absolutely critical, although it might not appear so at first glance which is why the original behaviour was so dangerous.

The problem is that the internal request property is intended to only hold POST parameters; while Request@getInputSource will return GET parameters (the query property) if the request method is GET or HEAD. This means that any calls to Laravel's methods asking for POST data on a GET request would return GET data previously (i.e. Request::post('somevar'); would return the value of ?somevar=bad on GET requests). The Request@duplicate call above does not have this problem because the request and query parameters are properly separated during the duplication process.

Ultimately there are two things to keep in mind:

  1. The Request->request property should ONLY ever hold POST data
  2. The Request@getInputSource() method returns data from different locations depending on the type of request made.

@LukeTowers
Copy link
Contributor

@MircoBabin where is Laravel calling json_decode twice? I'm not seeing it in the source.

@rodrigopedra
Copy link
Contributor

@LukeTowers gotcha. Thanks for the heads up.

My misunderstanding was due to Request@getInputSource checking if a request wants JSON as its first thing, but by moving the if clause to Request@createFromBase you avoid overwriting $request->request for non JSON requests.

Still, I found weird the added test passed if the change is reverted. Maybe is it worth adding another one that fails without the change?

@rodrigopedra
Copy link
Contributor

@MircoBabin , I am not familiar with the call trace visualization tool you are using, but comparing the two screenshots you posted, it is not clear to me, in the last one, that json_decode() is called twice.

I apologize in advance if it is a lack of familiarity with the tool.

On the other hand, if you can provide a clearer spot where json_decode() is called multiple times, it would be helpful to help you out on this.

@LukeTowers
Copy link
Contributor

@rodrigopedra I also find it odd that the test passed without the change applied, when I made the PR the test failed without the change.

@MircoBabin
Copy link
Author

@rodrigopedra @LukeTowers I have adjusted \Illuminate\Http\Request.php - function json() to write logging:

/**
     * Get the JSON payload for the request.
     *
     * @param string|null $key
     * @param mixed       $default
     *
     * @return \Symfony\Component\HttpFoundation\ParameterBag|mixed
     */
    public function json($key = null, $default = null)
    {
        if (!isset($this->json)) {
            static $calledCount = 0;
            ++$calledCount;
            file_put_contents('c:\\incoming\\out-of-memory.'.$calledCount.'.log', (strval(new \Exception('\Illuminate\Http\Request.php function json() is called - executing json_decode()'))));
            $this->json = new ParameterBag((array) json_decode($this->getContent(), true));
        }

        if (is_null($key)) {
            return $this->json;
        }

        return data_get($this->json->all(), $key, $default);
    }

2 files are written:

Exception: \Illuminate\Http\Request.php function json() is called - executing json_decode() in D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Request.php:377
Stack trace:
#0 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Request.php(462): Illuminate\Http\Request->json()
#1 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Request.php(67): Illuminate\Http\Request::createFromBase(Object(Symfony\Component\HttpFoundation\Request))
#2 D:\Projects\Webpage\tripportals\public\index.php(83): Illuminate\Http\Request::capture()
#3 {main}
Exception: \Illuminate\Http\Request.php function json() is called - executing json_decode() in D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Request.php:377
Stack trace:
#0 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Request.php(462): Illuminate\Http\Request->json()
#1 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Routing\CompiledRouteCollection.php(155): Illuminate\Http\Request::createFromBase(Object(Illuminate\Http\Request))
#2 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Routing\CompiledRouteCollection.php(114): Illuminate\Routing\CompiledRouteCollection->requestWithoutTrailingSlash(Object(Illuminate\Http\Request))
#3 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Routing\Router.php(680): Illuminate\Routing\CompiledRouteCollection->match(Object(Illuminate\Http\Request))
#4 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Routing\Router.php(667): Illuminate\Routing\Router->findRoute(Object(Illuminate\Http\Request))
#5 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Routing\Router.php(656): Illuminate\Routing\Router->dispatchToRoute(Object(Illuminate\Http\Request))
#6 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Foundation\Http\Kernel.php(167): Illuminate\Routing\Router->dispatch(Object(Illuminate\Http\Request))
#7 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(141): Illuminate\Foundation\Http\Kernel->Illuminate\Foundation\Http\{closure}(Object(Illuminate\Http\Request))
#8 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Foundation\Http\Middleware\ValidatePostSize.php(27): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#9 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(180): Illuminate\Foundation\Http\Middleware\ValidatePostSize->handle(Object(Illuminate\Http\Request), Object(Closure))
#10 D:\Projects\Webpage\tripportals\app\Http\Middleware\CheckDatabaseConnections.php(79): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#11 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(180): App\Http\Middleware\CheckDatabaseConnections->handle(Object(Illuminate\Http\Request), Object(Closure))
#12 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Foundation\Http\Middleware\PreventRequestsDuringMaintenance.php(86): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#13 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(180): Illuminate\Foundation\Http\Middleware\PreventRequestsDuringMaintenance->handle(Object(Illuminate\Http\Request), Object(Closure))
#14 D:\Projects\Webpage\tripportals\app\Http\Middleware\Cors.php(32): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#15 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(180): App\Http\Middleware\Cors->handle(Object(Illuminate\Http\Request), Object(Closure))
#16 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Middleware\TrustProxies.php(39): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#17 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(180): Illuminate\Http\Middleware\TrustProxies->handle(Object(Illuminate\Http\Request), Object(Closure))
#18 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Http\Middleware\TrustHosts.php(48): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#19 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(180): Illuminate\Http\Middleware\TrustHosts->handle(Object(Illuminate\Http\Request), Object(Closure))
#20 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Pipeline\Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}(Object(Illuminate\Http\Request))
#21 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Foundation\Http\Kernel.php(142): Illuminate\Pipeline\Pipeline->then(Object(Closure))
#22 D:\Projects\Webpage\tripportals\vendor\laravel\framework\src\Illuminate\Foundation\Http\Kernel.php(111): Illuminate\Foundation\Http\Kernel->sendRequestThroughRouter(Object(Illuminate\Http\Request))
#23 D:\Projects\Webpage\tripportals\public\index.php(83): Illuminate\Foundation\Http\Kernel->handle(Object(Illuminate\Http\Request))
#24 {main}

@MircoBabin
Copy link
Author

The problem is in Illuminate\Routing\CompiledRouteCollection.php - function requestWithoutTrailingSlash().

    /**
     * Get a cloned instance of the given request without any trailing slash on the URI.
     *
     * @param  \Illuminate\Http\Request  $request
     * @return \Illuminate\Http\Request
     */
    protected function requestWithoutTrailingSlash(Request $request)
    {
        $trimmedRequest = Request::createFromBase($request);

        $parts = explode('?', $request->server->get('REQUEST_URI'), 2);

        $trimmedRequest->server->set(
            'REQUEST_URI', rtrim($parts[0], '/').(isset($parts[1]) ? '?'.$parts[1] : '')
        );

        return $trimmedRequest;
    }
  1. it calls Request::createFromBase with an \Illuminate\Http\Request, which already did a internal json() and so already contains 69MB.
  2. Request::createFromBase expects a Symfony\Component\HttpFoundation\Request. Because it is unaware of the already decoded json body, it's decoding again. Claiming again 69MB memory.

Adjusting Request::createFromBase prevents the double json_decode(). But because the ParameterBag is not really copied/cloned I'm unsure if this is really a valid solution.

    /**
     * Create an Illuminate request from a Symfony instance.
     *
     * @return static
     */
    public static function createFromBase(SymfonyRequest $request)
    {
        $newRequest = (new static())->duplicate(
            $request->query->all(), $request->request->all(), $request->attributes->all(),
            $request->cookies->all(), $request->files->all(), $request->server->all()
        );

        $newRequest->headers->replace($request->headers->all());

        $newRequest->content = $request->content;

        if ($newRequest->isJson()) {
            if ($request instanceof self) {
                $newRequest->request = $request->json();
                $newRequest->json = $request->json; // Unsure if this is allowed, because this is a ParameterBag
            } else {
                $newRequest->request = $newRequest->json();
            }
        }

        return $newRequest;
    }

@rodrigopedra
Copy link
Contributor

@MircoBabin can you test changing the first line of CompiledRouteCollection@requestWithoutTrailingSlash

from:

$trimmedRequest = Request::createFromBase($request);

to:

$trimmedRequest = $request->duplicate();

And see if it fixes it?

@MircoBabin
Copy link
Author

@rodrigopedra I can confirm after changing function requestWithoutTrailingSlash(), there is no double json_decode() anymore.

@rodrigopedra
Copy link
Contributor

@MircoBabin I sent PR #42420 to make this change.

Thanks for tracing the spots so we could find where the double encoding happened =)

@MircoBabin
Copy link
Author

@rodrigopedra The PR targets the [8.x] branch. Can it also target the [9.x] branch ? Because that's the version I'm using.

Or must the PR first be accepted on the [8.x] branch and will then later be targeted at the [9.x] branch and future [10.x] branch ? Sorry for the question, I don't know how the Laravel project is handling patches on multiple versions.

@driesvints
Copy link
Member

@MircoBabin all fixes for 8.x are merged upstream to newer versions.

@rodrigopedra
Copy link
Contributor

@MircoBabin as it is a bugfix it should target the 8.x, as this branch is still in bugfix support.

Complementing what @driesvints said, changes in 8.x are merged into 9.x before each weekly release.

@MircoBabin
Copy link
Author

Thank you very much !

@LukeTowers
Copy link
Contributor

@MircoBabin excellent work tracking down the issue and great final solution @rodrigopedra! Glad to see the issue resolved with a general win for Laravel performance :)

@driesvints
Copy link
Member

Will be fixed in the next release. Thanks all.

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

No branches or pull requests

7 participants
@taylorotwell @driesvints @rodrigopedra @LukeTowers @MircoBabin @lk77 and others