common icon indicating copy to clipboard operation
common copied to clipboard

Proxy's `__debugInfo()` must not have side effects

Open flack opened this issue 3 years ago • 24 comments

Bug Report

Q A
BC Break yes/no
Version 2.12.3

Summary

I'm using Entity classes which have the magic __debugInfo() method defined. When I try to load a reference to a nonexistant Entity and var_dump it with the following code:

$proxy = $em->getReference($my_classname, $this_id_does_not_exist);
var_dump($proxy);

the program dies

Current behavior

I get the following error (edited for readability):

PHP Warning:  Uncaught Doctrine\ORM\EntityNotFoundException: Entity of type 'my_class' for IDs id(1) was not found in vendor/doctrine/orm/lib/Doctrine/ORM/EntityNotFoundException.php:33
Stack trace:
#0 vendor/doctrine/orm/lib/Doctrine/ORM/Proxy/ProxyFactory.php(139): Doctrine\ORM\EntityNotFoundException::fromClassNameAndIdentifier()
doctrine/orm#1 /tmp/cache/__CG__my_class.php(224): Doctrine\ORM\Proxy\ProxyFactory->Doctrine\ORM\Proxy\{closure}()
doctrine/orm#2 /tmp/cache/__CG__my_class.php(224): Closure->__invoke()
doctrine/orm#3 [internal function]: DoctrineProxies\__CG__\my_class->__debugInfo()
doctrine/orm#4 testscript.php(2): var_dump()
doctrine/orm#5 {main}
  thrown in vendor/doctrine/orm/lib/Doctrine/ORM/EntityNotFoundException.php on line 33
PHP Fatal error:  __debuginfo() must return an array in test.php on line 2
PHP Stack trace:
PHP  1. test() testscript.php:1
PHP  2. var_dump($value = class DoctrineProxies\__CG__\my_class { /*...*/ public $__initializer__ = class Closure { virtual $closure = "$this->Doctrine\ORM\Proxy\{closure}",  }; public $__cloner__ = class Closure { virtual $closure = "$this->Doctrine\ORM\Proxy\{closure}",  }; public $__isInitialized__ = FALSE }) testscript.php:2
PHP Fatal error:  __debuginfo() must return an array in testscript.php on line 2
PHP Stack trace:
PHP  1. test() testscript.php:1
PHP  2. var_dump($value = class DoctrineProxies\__CG__\my_class { /*...*/ public $__initializer__ = class Closure { virtual $closure = "$this->Doctrine\ORM\Proxy\{closure}",  }; public $__cloner__ = class Closure { virtual $closure = "$this->Doctrine\ORM\Proxy\{closure}",  }; public $__isInitialized__ = FALSE }) testscript.php:2

How to reproduce

You need PHP 8 or greater and Xdebug loaded. Without xdebug, it works, and with xdebug it works in PHP 7.4 and below. I can try to make some minimal reproduction if it's necessary, for a quick reproduction, you can run the tests of https://github.com/flack/midgard-portable. The result will look like here: https://scrutinizer-ci.com/g/flack/midgard-portable/inspections/464a6111-e297-4cbb-9637-e90870531345

Expected behavior

It should work like it does in PHP 7.x

flack avatar Jun 23 '22 14:06 flack

P.S.: Wrapping getReference() and var_dump in a try/catch block doesn't help. Just in case someone wants to suggest that :-)

flack avatar Jun 23 '22 14:06 flack

Shouldn't this be reported to Xdebug instead?

derrabus avatar Jun 23 '22 16:06 derrabus

Yeah, maybe. I originally did not find a way to reproduce it without the Doctrine proxy involved, but I just found that this also triggers it:

class test
{
    public function __debugInfo()
    {
        throw new Exception('X');
        return [];
    }
}

var_dump(new test);

So the problem is that Doctrine throws here:

https://github.com/doctrine/orm/blob/b9f2488c6c08c89c329e0643f146e974c099e075/lib/Doctrine/ORM/Proxy/ProxyFactory.php#L137-L140

There is only one thing I don't understand, and that is where var_dump gets called in the first place. I just made the example above because it was the shortest way to reproduce, but in the actual code where I found the problem, there are no calls to var_dump, not even in the vendor tree. The error occurs in this code block:

https://github.com/flack/midgard-portable/blob/cfa49efefecb943d55602ed158c49572837032d3/test/api/mgdobjectTest.php#L88-L92

If I comment out either of those two lines, the problem disappears. Digging a bit deeper, I noticed that if I change the code in ProxyFactory to look like this:

try {
    throw EntityNotFoundException::fromClassNameAndIdentifier(
        $classMetadata->getName(),
        $this->identifierFlattener->flattenIdentifier($classMetadata, $identifier)
    );
} catch (EntityNotFoundException $e) {
    die('Caught');
}

The exception does not get caught. I'm not sure, but it kind of seems like there's something funky going on on the doctrine side, too.

Anyway, I also opened https://bugs.xdebug.org/view.php?id=2100 on the xdebug side

flack avatar Jun 23 '22 17:06 flack

after some more research, I'm pretty sure now that this is really only an xdebug issue, closing this one.

flack avatar Jun 27 '22 08:06 flack

Thanks!

derrabus avatar Jun 27 '22 08:06 derrabus

Short update: I've since discovered https://github.com/php/php-src/issues/7922 which states that the Fatal Error mentioned above is actually a current core PHP behavior/bug. The __debugInfo() method generated in doctrine proxies looks like this:

    /**
     * {@inheritDoc}
     */
    public function __debugInfo()
    {

        $this->__initializer__ && $this->__initializer__->__invoke($this, '__debugInfo', []);

        return parent::__debugInfo();
    }

and $this->__initializer__->__invoke($this, '__debugInfo', []); can throw, as shown above. So I would argue that it is currently not really safe to implement __debugInfo() on your Entity classes (at least when using proxies), because they might randomly crash your program.

So I wonder: would it make sense to open a new feature request or similar to add a try/catch around the __invoke call in the generated method? Because at least currently, throwing from __debugInfo simply seems unsupported in PHP.

flack avatar Jun 28 '22 09:06 flack

Makes sense to me.

derrabus avatar Jun 28 '22 10:06 derrabus

I can't really fix this on the @xdebug side, as it expects (quite reasonably) that __debugInfo() can be called without any side-effects. If Doctrine has side effects here (including, but not exclusively, throwing Exceptions), then this needs fixing in Doctrine.

derickr avatar Jun 29 '22 14:06 derickr

changed the title to reflect the latest findings

flack avatar Jun 29 '22 15:06 flack

We should catch the exception and return a debug info including the exception message. This must be in doctrine/common ProxyGenerator

beberlei avatar Jun 29 '22 18:06 beberlei

Context

I only got to this discussion because of recent twitter convos about __debugInfo() ( https://twitter.com/tfidry/status/1555180564243795968 ).

My 2 cents

Don't introduce __debugInfo() at all, as it only adds up to the problem, leave library behavior untouched.

The fact that a proxied object includes __debugInfo() is a clear intent of the author of the object to have __debugInfo() called during inspection, which, in proxies (by design), leads to lazy-loading.

Solution: complete removal of __debugInfo() in parent class.

Regardless off the existence of __debugInfo() (or an override thereof), any state (public properties, mostly) accessed before the object is initialized will lead to lazy-loading.

Ocramius avatar Aug 04 '22 13:08 Ocramius

My two cents:

  • _debugInfo is a default PHP feature and magic method just like __get, __set, __isset,__sleep and __wakeup, all of which have special handling in ProxyGenerator, because they need it. So why not __debugInfo?
  • if you really want to say that __debugInfo is unsupported in Doctrine proxies in general, then there should be code in ProxyGenerator that detects the presence of __debugInfo in the parent class and throws directly upon generation. that way, you can at least catch the problem before going to production.

But again: Why not just add a try/catch block? It's not like this is some major architectural change, it's just removing a potential footgun. (You could argue that this is a PHP bug like __toString which also crashed the program when an exception was thrown a few versions back, but still IMHO the pragmatic solution would be try/catch)

flack avatar Aug 04 '22 13:08 flack

So why not __debugInfo?

Because it actively hurts debugging

detects the presence of __debugInfo in the parent class and throws directly upon generation

Totally on board with this.

But again: Why not just add a try/catch block?

Even more side-effects: breaks exception traps in the debugger, causes autoloading, creates objects, increases memory usage, potentially leads to even more I/O. Don't.

Ocramius avatar Aug 04 '22 13:08 Ocramius

Because it actively hurts debugging

Well, in my case, it helps debugging, because without it var_dump($entity) takes 1-2 minutes and 100s of MB of memory (I use __debugInfo to filter out some complex internal objects). Yes, ideally I should refactor, but I can't due to BC requirements

Even more side-effects: breaks exception traps in the debugger, causes autoloading, creates objects, increases memory usage, potentially leads to even more I/O. Don't.

The catch would only be taken in situations where the program currently simply dies without any chance of recovery, I don't see how that is any better.

In general, if you're of the opinion that __debugInfo is an antipattern and should be abolished, the best course of action would be to create a deprecation RFC with php-core (or whatever the correct process for that is). But that still leaves the footgun here in the meantime.

flack avatar Aug 04 '22 13:08 flack

On 4 August 2022 14:56:30 BST, flack @.***> wrote:

Because it actively hurts debugging

Well, in my case, it helps debugging, because without it var_dump($entity) takes 1-2 minutes

Debugging is done with a debugger, not by introducing echoing statements in your code.

The problem that I pointed @ocramius to on twitter is that debugInfo should not have side effects. If you want to do parent calls in it, then you need to try/catch that yourself so exceptions can never leak out of every implementation that you make as __debugInfo calls

cheers Derick

derickr avatar Aug 04 '22 14:08 derickr

Debugging is done with a debugger, not by introducing echoing statements in your code.

Sure, why not. The way I actually discovered this memory usage issue was because after migrating some code to Doctrine my test server kept dying, because in certain situations it would write entities to a log file, which worked fine in the old system, but due to the different structure in the doctrine entities there was this huge memory blowup. I'm sure that all of that can be avoided by following best practices and so on, but it is still a footgun that you could trigger accidentally, so why make life harder for us poor frontline devs?

flack avatar Aug 04 '22 14:08 flack

Mostly because adding even more layers would make your life even worse, plus worsening things on this end too :-)

Ocramius avatar Aug 04 '22 14:08 Ocramius

Yeah, the less layers, the better, I definitely agree with that. But just to circle back to my original problem: I have code roughly equivalent to this:

function show_name($entity) {
    echo $entity->name;
}

try {
    $proxy = $em->getReference($my_classname, $this_id_does_not_exist);
    show_name($proxy);
} catch (Exception $e) {
   echo 'Entity could not be loaded: ' . $e->getMessage();
}

This works fine in production. If I enable the xdebug module, the program dies with the error message in the OP. AFAICT that is because XDebug internally calls __debugInfo when it is enriching the exception's backtrace. If I remove __debugInfo in my code, it will work, but likely use hundreds of megabytes of memory to traverse the complex internal objects for no good reason. So it's still a bit of a lose-lose situation.

flack avatar Aug 04 '22 14:08 flack

What do you guys think about having ProxyGenerator create a __debugInfo function like this:

    public function __debugInfo()
    {
        if (!$this->__isInitialized()) {
            return array_keys(get_object_vars($this)); // or maybe just hardcode what we want
        }

        return parent::__debugInfo();
    }

That way, var_dump($proxy) never causes a DB load (and hence can't throw), while var_dump($entity) can still filter out unneeded crap.

flack avatar Aug 05 '22 09:08 flack

That makes debugging harder, as it is now not clear which properties are set, which are unset() (part of the proxy design), and in case of an initialized proxy, the proxy state is no longer visible.

Firm no on implementing any of this, from my end.

Ocramius avatar Aug 05 '22 09:08 Ocramius

OK, fine. But currently Doctrine generates code that throws an Exception in a place where PHP simply does not allow/support throwing exceptions. That needs to be addressed somehow

flack avatar Aug 05 '22 09:08 flack

It throws an exception for invalid proxy references, because of the __debugInfo() side-effect.

That is still a smaller side-effect than shadowing the entire structure: it's an acceptable trade-off, IMO, even if annoying.

I think the best/safest way forward is preventing proxying objects that implement __debugInfo() overall, by producing an exception to the user upfront, perhaps describing how __debugInfo() is generally to be avoided (as part of the exception message).

Ocramius avatar Aug 05 '22 09:08 Ocramius

We should catch the exception and render that into the debug info

beberlei avatar Aug 05 '22 09:08 beberlei

It throws an exception for invalid proxy references, because of the __debugInfo() side-effect. That is still a smaller side-effect than shadowing the entire structure: it's an acceptable trade-off, IMO, even if annoying.

It throws an exception that cannot be caught. As soon as throw is called from inside __debugInfo the PHP process just dies, there's nothing you can do to prevent it (you can't even really log an error or something, because the error handler is also dead then if I'm not mistaken). Calling that an annoyance is a bit of an understatement IMO.

flack avatar Aug 05 '22 09:08 flack