orm: Cached SQL Statement leads to 503 error in Apache

BC Break Report

Q A
BC Break yes
Version 2.10.0

Summary

After updating doctrine/orm from 2.9.6 to 2.10.2, I am getting 503 errors from Apache for some cached SQL statements. The Apache logs are empty and did not give me anything useful.

Previous behavior

With doctrine/orm 2.9.6 (and doctrine/dbal 2.13.6) I can call a particular repository method multiple times without an error occurring.

Current behavior

After updating to doctrine/orm 2.10.0 (and doctrine/dbal 2.13.6), calling this special repository method only once is possible. After that, a cached SQL statement is created and any further call to the method will result in a 503 error in Apache.

How to reproduce

I have not yet been able to reproduce this on a local machine. I discovered this behavior on my prod machine a few weeks ago and can reproduce it on my staging machine. Please read this discussion to follow my current journey: https://github.com/symfony/symfony/discussions/44270

I’ve used on my machines:

  • Apache
  • Mysql 5.7
  • PHP 7.4
  • doctrine/orm: 2.10.0
  • doctrine/dbal: 2.13.6 3.1.4
  • doctrine/doctrine-bundle: 2.5.0
  • doctrine/cache: 2.1.1

At the moment I have located doctrine/orm or doctrine/ldap as the source of this problem by partially clearing the cache and re-running the repository method. In this way I have found several caches that I can associate with Apache’s 503 error, but I have not found a pattern between them, so I will focus on a relatively simple SQL statement.

This is the cached SQL statement that results in an Apache 503 error:

<?php //085f6b9716d8e39e78c0de0dcdefffd8

return [PHP_INT_MAX, static function () { return \Symfony\Component\VarExporter\Internal\Hydrator::hydrate(
    $o = [
        clone (($p = &\Symfony\Component\VarExporter\Internal\Registry::$prototypes)['Doctrine\\ORM\\Query\\ParserResult'] ?? \Symfony\Component\VarExporter\Internal\Registry::p('Doctrine\\ORM\\Query\\ParserResult')),
        clone ($p['Doctrine\\ORM\\Query\\Exec\\SingleSelectExecutor'] ?? \Symfony\Component\VarExporter\Internal\Registry::p('Doctrine\\ORM\\Query\\Exec\\SingleSelectExecutor')),
        clone ($p['Doctrine\\ORM\\Query\\ResultSetMapping'] ?? \Symfony\Component\VarExporter\Internal\Registry::p('Doctrine\\ORM\\Query\\ResultSetMapping')),
    ],
    null,
    [
        'Doctrine\\ORM\\Query\\ParserResult' => [
            '_sqlExecutor' => [
                $o[1],
            ],
            '_resultSetMapping' => [
                $o[2],
            ],
            '_parameterMappings' => [
                [
                    1 => [
                        0,
                    ],
                ],
            ],
        ],
        'Doctrine\\ORM\\Query\\Exec\\AbstractSqlExecutor' => [
            '_sqlStatements' => [
                1 => 'SELECT count(u0_.id) AS sclr_0 FROM users u0_ WHERE u0_.deleted_at IS NULL AND u0_.created_at > ?',
            ],
        ],
        'stdClass' => [
            'scalarMappings' => [
                2 => [
                    'sclr_0' => 1,
                ],
            ],
            'typeMappings' => [
                2 => [
                    'sclr_0' => 'integer',
                ],
            ],
        ],
    ],
    $o[0],
    []
); }];

So after deleting this cache file, the repository method can be successfully called once. The cache is created and on the next call Apache returns the 503.

I haven’t found the whole path from the doctrine cache to the Apache error, but I have a hypothesis with circumstantial evidence that doctrine/orm or doctrine/dbal has something to do with it. To confirm my hypothesis, I downgraded back to doctrine/orm 2.9.6 (and doctrine/dbal 2.13.6) and the problems disappeared. (The cache created with doctrine/orm 2.9.6 remains the same as posted above).

I’m not sure if anyone can help me, but I would appreciate any advice on what or where to look next to find the root of this problem. I’m not even sure if this is the right place for this problem, but I don’t know where to look next.

Thank you.

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Reactions: 9
  • Comments: 21 (4 by maintainers)

Most upvoted comments

My final “solution”: Upgrade to PHP 8. I can reproduce this Issue only on PHP 7.4.

I can confirm that this issue is solved after switching to PHP 8.0, so for me this issue is solved.

I’m not sure if I should close this issue.

My final “solution”: Upgrade to PHP 8. I can reproduce this Issue only on PHP 7.4.

We have the same Issue on two different symfony applications. I was not able to log any PHP error, I report what I currently know. We found the following errors in the log on time when the app crashed (IP-Address and domain.dom anonymised):

2021-11-25 08:24:47.858997 [INFO] [1929825] [178.xxx.xxx.x:56490-Q:564B0C92F084CA7F-3#APVH_app.domain.dom:443] connection to [uds://tmp/lshttpd/APVH_directory_S ualt-php74.sock] on request #0, confirmed, 1, associated process: 1931624, running: 1, error: Connection reset by peer! 

2021-11-25 08:24:47.935356 [INFO] [1929825] [178.xxx.xxx.x:56490-Q:564B0C92F084CA7F-3#APVH_app.domain.dom:443] connection to [uds://tmp/lshttpd/APVH_directory_S ualt-php74.sock] on request #0, confirmed, 1, associated process: 1931625, running: 1, error: Connection reset by peer! 

2021-11-25 08:24:48.012028 [INFO] [1929825] [178.xxx.xxx.x:56490-Q:564B0C92F084CA7F-3#APVH_app.domain.dom:443] connection to [uds://tmp/lshttpd/APVH_directory_S ualt-php74.sock] on request #0, confirmed, 1, associated process: 1931626, running: 0, error: Connection reset by peer! 

2021-11-25 08:24:48.012108 [NOTICE] [1929825] [178.xxx.xxx.x:56490-Q:564B0C92F084CA7F-3#APVH_app.domain.dom:443] Max retries has been reached, 503! 

2021-11-25 08:24:48.012330 [NOTICE] [1929825] [178.xxx.xxx.x:56490-Q:564B0C92F084CA7F-3#APVH_app.domain.dom:443] oops! 503 Service Unavailable 

2021-11-25 08:24:48.012386 [NOTICE] [1929825] [178.xxx.xxx.x:56490-Q:564B0C92F084CA7F-3#APVH_app.domain.dom:443] Content len: 0, Request line: 'GET /admin/employee/tool/index HTTP/1.1'

In the system log, we see the following message when the php process got killed:

master: worker is killed by SEGV signal - probably lve PMEM limit or PHP memory_limit hit

We already disable OPCache, without effect.

I need more time to debug this issue more deeply, I’ll do It as soon I can.

The error occurs in my cases only on production and always unexpected. I still don’t know, which request / command / constellation leads to the 503-error. On the second application, we normally have the 503 between 1am and 4 am in the morning, almost every day. After clearing cache, everything works again great for around 24h. No, no cron-jobs or something else this strange behaviour could explain…

Hi @Art4 , thanks for filing this - I was going nuts last days trying to figure out what is causing this 503 on some of various SonataAdmin classes, but only the second time after a cache clear…

~Unfortunately, upgrading to PHP8.0 did not make any difference.~ EDIT: Upgrading to PHP8.0 did fix the issue (during testing / switching versions delirium, I forgot to clear the cache after the 8.0 switch).

My solution was to downgrade and fix the version: "doctrine/orm": "2.9.6".

As there are no known security vulnerabilities with this version, I can live with that.