Internal Server Error when calling dump() #34993

flack · 2019-12-16T09:32:35Z

Symfony version(s) affected: VarDumper 4.4.1

Description
I'm using the VarDumper component on a project that is not based on Symfony framework. When I try to call dump() on certain objects (basically wrapped Doctrine ORM entities, but produced by a custom driver), I get a 500 Server Error. There is no error message on screen (even though XDebug is installed), and nothing in Apache logs or syslog. I've reproduced this on Debian 10.2 , Kubuntu 19.10 (both PHP 7.3.11) and macOS 10.14 (PHP 7.4 from Homebrew).

How to reproduce

I have tried following the steps in the reproducer howto, but I can't install the required dependencies due to lots of incomprehensible composer errors. If it helps, I could try to make a repo which reproduces the bug without using the skeleton stuff, but then it'll probably take a few more steps...

Additional context
Not sure it it helps, but this is how the object I'm trying to dump looks in regular var_dump:

object(de_ccb_site_content_dba)[688]
  public '__midcom_class_name__' => string 'de_ccb_site_content_dba' (length=23)
  public '__mgdschema_class_name__' => string 'de_ccb_site_content' (length=19)
  public '__object' => 
    object(de_ccb_site_content)[695]
      protected 'id' => int 111
      protected 'name' => string '' (length=0)
      protected 'extra1' => string '
Content management
' (length=20)
      protected 'extra2' => string '' (length=0)
      protected 'extra3' => string '' (length=0)
      protected 'type' => int 0
      protected 'up' => 
        object(de_ccb_site_content)[673]
          protected 'id' => int 106
          protected 'name' => string 'what' (length=4)
          protected 'extra1' => string '' (length=0)
          protected 'extra2' => string '' (length=0)
          protected 'extra3' => string 'Was wir für Sie tun können' (length=28)
          protected 'type' => int 0
          protected 'up' => null
          protected 'topic' => 
            object(DoctrineProxies\__CG__\midgard_topic)[637]
              ...
          protected 'title' => string '' (length=0)
          protected 'abstract' => string '' (length=0)
          protected 'content' => string 'Ihr Layout ist bisher nur analoger Entwurf und keine digitale Realität? Sie planen den Relaunch und diesmal soll von Anfang an alles stimmen? Sie haben eine Idee für eine neue Webanwendung und könnten Hilfe bei der Umsetzung gebrauchen? Sprechen Sie uns an. Wir bringen Ihre Idee ins Netz.<br><!--[if gte mso 9]><xml>
 <o:OfficeDocumentSettings>
  <o:RelyOnVML/>
  <o:AllowPNG/>
 </o:OfficeDocumentSettings>
</xml><![endif]-->



<!--[if gte mso 9]><xml>
 <w:WordDocument>
  <w:View>Normal</w:View>
  <w:Zoom>'... (length=18273)
          protected 'url' => string '' (length=0)
          protected 'calstart' => 
            object(midgard_datetime)[674]
              ...
          protected 'caldays' => int 0
          protected 'icon' => int 0
          protected 'view' => int 0
          protected 'print' => int 0
          protected 'score' => int 0
          protected 'metadata_creator' => string '1e0337927bb0d18337911e09a3a6d68ac99ac2bac2b' (length=43)
          protected 'metadata_created' => 
            object(midgard_datetime)[675]
              ...
          protected 'metadata_revisor' => string 'c5a9785cceb211debcb263422b06a075a075' (length=36)
          protected 'metadata_revised' => 
            object(midgard_datetime)[676]
              ...
          protected 'metadata_revision' => int 36
          protected 'metadata_locker' => string 'c5a9785cceb211debcb263422b06a075a075' (length=36)
          protected 'metadata_locked' => 
            object(midgard_datetime)[677]
              ...
          protected 'metadata_approver' => string '' (length=0)
          protected 'metadata_approved' => 
            object(midgard_datetime)[678]
              ...
          protected 'metadata_authors' => string '|1e0337927bb0d18337911e09a3a6d68ac99ac2bac2b|' (length=45)
          protected 'metadata_owner' => string 'c5a8a274ceb211debcb263422b06a075a075' (length=36)
          protected 'metadata_schedulestart' => 
            object(midgard_datetime)[679]
              ...
          protected 'metadata_scheduleend' => 
            object(midgard_datetime)[680]
              ...
          protected 'metadata_hidden' => boolean false
          protected 'metadata_navnoentry' => boolean false
          protected 'metadata_size' => int 18779
          protected 'metadata_published' => 
            object(midgard_datetime)[681]
              ...
          protected 'metadata_score' => int 0
          protected 'metadata_imported' => 
            object(midgard_datetime)[682]
              ...
          protected 'metadata_exported' => 
            object(midgard_datetime)[683]
              ...
          protected 'metadata_deleted' => boolean false
          protected 'metadata_islocked' => boolean true
          protected 'metadata_isapproved' => boolean false
          protected 'metadata' => null
          public 'action' => string '' (length=0)
          private 'collections' (midgard\portable\api\mgdobject) => 
            array (size=0)
              ...
          protected 'guid' => string '1e1981cae760192981c11e1be79a1ee855a94f694f6' (length=43)
          protected 'cm' => 
            object(midgard\portable\mapping\classmetadata)[573]
              ...
          protected 'changed_associations' => 
            array (size=0)
              ...
      protected 'topic' => 
        object(DoctrineProxies\__CG__\midgard_topic)[637]
          public '__initializer__' => 
            object(Closure)[269]
              ...
          public '__cloner__' => 
            object(Closure)[270]
              ...
          public '__isInitialized__' => boolean false
          protected 'id' => int 19
          protected 'name' => string '' (length=0)
          protected 'code' => string '' (length=0)
          protected 'up' => null
          protected 'component' => string '' (length=0)
          protected 'style' => string '' (length=0)
          protected 'styleInherit' => boolean false
          protected 'title' => string '' (length=0)
          protected 'extra' => string '' (length=0)
          protected 'description' => string '' (length=0)
          protected 'metadata_creator' => string '' (length=0)
          protected 'metadata_created' => null
          protected 'metadata_revisor' => string '' (length=0)
          protected 'metadata_revised' => null
          protected 'metadata_revision' => int 0
          protected 'metadata_locker' => string '' (length=0)
          protected 'metadata_locked' => null
          protected 'metadata_approver' => string '' (length=0)
          protected 'metadata_approved' => null
          protected 'metadata_authors' => string '' (length=0)
          protected 'metadata_owner' => string '' (length=0)
          protected 'metadata_schedulestart' => null
          protected 'metadata_scheduleend' => null
          protected 'metadata_hidden' => boolean false
          protected 'metadata_navnoentry' => boolean false
          protected 'metadata_size' => int 0
          protected 'metadata_published' => null
          protected 'metadata_score' => int 0
          protected 'metadata_imported' => null
          protected 'metadata_exported' => null
          protected 'metadata_deleted' => boolean false
          protected 'metadata_islocked' => boolean false
          protected 'metadata_isapproved' => boolean false
          protected 'metadata' => null
          public 'action' => string '' (length=0)
          private 'collections' (midgard\portable\api\mgdobject) => 
            array (size=0)
              ...
          protected 'guid' => string '' (length=0)
          protected 'cm' => null
          protected 'changed_associations' => 
            array (size=0)
              ...
      protected 'title' => string '' (length=0)
      protected 'abstract' => string '' (length=0)
      protected 'content' => string '
<i>Wir minimieren Abhängigkeit.</i>&nbsp;<div><br></div><div>Mithilfe eines Content-Management-Systems können Sie Ihre Website ohne professionelle Hilfe administrieren. Neben Drupal, Wordpress, Joomla und anderen Systemen gehört auch das von uns mitentwickelte Midgard CMS zu unserem Portfolio. Wir bieten ein individuelles, flexibel erweiterbares System, mit dem Sie effektiv kommunizieren können. CMS von der Stange bekommen Sie woanders.<br></div>
' (length=456)
      protected 'url' => string '' (length=0)
      protected 'calstart' => 
        object(midgard_datetime)[696]
          public 'date' => string '0001-01-01 00:00:00.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'caldays' => int 0
      protected 'icon' => int 0
      protected 'view' => int 0
      protected 'print' => int 0
      protected 'score' => int 0
      protected 'metadata_creator' => string '1e0337927bb0d18337911e09a3a6d68ac99ac2bac2b' (length=43)
      protected 'metadata_created' => 
        object(midgard_datetime)[697]
          public 'date' => string '2012-05-07 08:16:38.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_revisor' => string 'c5a9785cceb211debcb263422b06a075a075' (length=36)
      protected 'metadata_revised' => 
        object(midgard_datetime)[698]
          public 'date' => string '2019-10-07 07:51:04.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_revision' => int 20
      protected 'metadata_locker' => string 'c5a9785cceb211debcb263422b06a075a075' (length=36)
      protected 'metadata_locked' => 
        object(midgard_datetime)[699]
          public 'date' => string '2019-10-07 07:51:13.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_approver' => string '' (length=0)
      protected 'metadata_approved' => 
        object(midgard_datetime)[700]
          public 'date' => string '0001-01-01 00:00:00.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_authors' => string '|1e0337927bb0d18337911e09a3a6d68ac99ac2bac2b|' (length=45)
      protected 'metadata_owner' => string 'c5a8a274ceb211debcb263422b06a075a075' (length=36)
      protected 'metadata_schedulestart' => 
        object(midgard_datetime)[701]
          public 'date' => string '0001-01-01 00:00:00.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_scheduleend' => 
        object(midgard_datetime)[702]
          public 'date' => string '0001-01-01 00:00:00.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_hidden' => boolean false
      protected 'metadata_navnoentry' => boolean false
      protected 'metadata_size' => int 985
      protected 'metadata_published' => 
        object(midgard_datetime)[703]
          public 'date' => string '2012-05-07 08:16:38.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_score' => int 2
      protected 'metadata_imported' => 
        object(midgard_datetime)[704]
          public 'date' => string '0001-01-01 00:00:00.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_exported' => 
        object(midgard_datetime)[705]
          public 'date' => string '0001-01-01 00:00:00.000000' (length=26)
          public 'timezone_type' => int 3
          public 'timezone' => string 'UTC' (length=3)
      protected 'metadata_deleted' => boolean false
      protected 'metadata_islocked' => boolean true
      protected 'metadata_isapproved' => boolean false
      protected 'metadata' => null
      public 'action' => string '' (length=0)
      private 'collections' (midgard\portable\api\mgdobject) => 
        array (size=0)
          empty
      protected 'guid' => string '1e1981cf7f4e680981c11e193878706f9b2e3dbe3db' (length=43)
      protected 'cm' => 
        object(midgard\portable\mapping\classmetadata)[573]
          public 'midgard' => 
            array (size=6)
              ...
          public 'name' => string 'de_ccb_site_content' (length=19)
          public 'namespace' => string '' (length=0)
          public 'rootEntityName' => string 'de_ccb_site_content' (length=19)
          public 'customGeneratorDefinition' => null
          public 'customRepositoryClassName' => null
          public 'isMappedSuperclass' => boolean false
          public 'isEmbeddedClass' => boolean false
          public 'parentClasses' => 
            array (size=0)
              ...
          public 'subClasses' => 
            array (size=0)
              ...
          public 'embeddedClasses' => 
            array (size=0)
              ...
          public 'namedQueries' => 
            array (size=0)
              ...
          public 'namedNativeQueries' => 
            array (size=0)
              ...
          public 'sqlResultSetMappings' => 
            array (size=0)
              ...
          public 'identifier' => 
            array (size=1)
              ...
          public 'inheritanceType' => int 1
          public 'generatorType' => int 4
          public 'fieldMappings' => 
            array (size=40)
              ...
          public 'fieldNames' => 
            array (size=40)
              ...
          public 'columnNames' => 
            array (size=40)
              ...
          public 'discriminatorValue' => null
          public 'discriminatorMap' => 
            array (size=0)
              ...
          public 'discriminatorColumn' => null
          public 'table' => 
            array (size=4)
              ...
          public 'lifecycleCallbacks' => 
            array (size=0)
              ...
          public 'entityListeners' => 
            array (size=0)
              ...
          public 'associationMappings' => 
            array (size=2)
              ...
          public 'isIdentifierComposite' => boolean false
          public 'containsForeignIdentifier' => boolean false
          public 'idGenerator' => 
            object(Doctrine\ORM\Id\IdentityGenerator)[574]
              ...
          public 'sequenceGeneratorDefinition' => null
          public 'tableGeneratorDefinition' => null
          public 'changeTrackingPolicy' => int 1
          public 'isVersioned' => null
          public 'versionField' => null
          public 'cache' => null
          public 'reflClass' => 
            object(ReflectionClass)[575]
              ...
          public 'isReadOnly' => boolean false
          protected 'namingStrategy' => null
          public 'reflFields' => 
            array (size=42)
              ...
          private 'instantiator' (Doctrine\ORM\Mapping\ClassMetadataInfo) => 
            object(Doctrine\Instantiator\Instantiator)[576]
              ...
      protected 'changed_associations' => 
        array (size=0)
          empty
  private '__metadata' (midcom_core_dbaobject) => null
  public '_use_rcs' => boolean true
  private '_rcs_message' (midcom_core_dbaobject) => boolean false
  public 'allow_name_catenate' => boolean false
  public 'autodelete_dependents' => 
    array (size=0)
      empty

The text was updated successfully, but these errors were encountered:

flack · 2019-12-16T15:48:56Z

Small update: I've been playing around a little more, and don't ask me why, but now I get a backtrace on the site (I've cut out the irrelevant part):

 Entity of type 'midgard_topic' for IDs id(0) was not found

in vendor/doctrine/orm/lib/Doctrine/ORM/EntityNotFoundException.php, line 47

Error 500

Stacktrace:
1: vendor/doctrine/orm/lib/Doctrine/ORM/Proxy/ProxyFactory.php:166  Doctrine\ORM\EntityNotFoundException::fromClassNameAndIdentifier
2: var/cache/__CG__midgard_topic.php:223  Doctrine\ORM\Proxy\ProxyFactory->Doctrine\ORM\Proxy\{closure}
3: var/cache/__CG__midgard_topic.php:223  Closure->__invoke
4: vendor/symfony/var-dumper/Caster/Caster.php:85  DoctrineProxies\__CG__\midgard_topic->__debugInfo
5: vendor/symfony/var-dumper/Cloner/AbstractCloner.php:323  Symfony\Component\VarDumper\Caster\Caster::castObject
6: vendor/symfony/var-dumper/Cloner/VarCloner.php:189  Symfony\Component\VarDumper\Cloner\AbstractCloner->castObject
7: vendor/symfony/var-dumper/Cloner/AbstractCloner.php:262  Symfony\Component\VarDumper\Cloner\VarCloner->doClone
8: vendor/symfony/var-dumper/VarDumper.php:46  Symfony\Component\VarDumper\Cloner\AbstractCloner->cloneVar
9: vendor/symfony/var-dumper/VarDumper.php:50  Symfony\Component\VarDumper\VarDumper::Symfony\Component\VarDumper\{closure}
10: vendor/symfony/var-dumper/Resources/functions/dump.php:20  Symfony\Component\VarDumper\VarDumper::dump

I also found out that the error starts happening in version 4.3.2. If I install VarDumper 4.3.1 or lower, everything works as it should

flack · 2019-12-17T15:18:20Z

A small explanation for the backtrace:

My Doctrine entities are all derived from a baseclass which implements __debugInfo
Doctrine autgenerates proxies which contain all methods of the proxied class, including __debugInfo
VarDumper sees that something it is about to dump has the __debugInfo method and tries to call it
the Doctrine proxy sees that one of its methods is called and tries to initialize itself by loading the object from the database
unfortunately the ID is 0, so it throws an exception

What I still don't understand is where the invalid proxy comes from, because regular var_dump doesn't show it. In fact, regular var_dump doesn't seem to call any method on this proxy class. So I don't know, maybe the invalid proxy is there, and regular var_dump just doesn't see it, or the way VarDumper uses to read the object somehow triggers its creation.

Another thing I just found out: The exception/server error (depending on the phase of the moon apparently, today I didn't see the exception again, only the server errors) only happens if I dump more than one object: The dump() call is inside a loop, and when I put it inside an if so that it only dumps one of the items, everything works as it should.

I was wondering: Would you consider simply wrapping the __debugInfo call in Caster/Caster.php:85 in a try/catch block? VarDumper is supposed to be a debugging tool after all, so it should try to stay out of the way as much as possible instead of sending unsuspecting users such as myself down enormous rabbit holes trying to debug the debugger :-)

nicolas-grekas · 2019-12-17T15:54:16Z

Can you please try this patch?

--- a/src/Symfony/Component/VarDumper/Caster/Caster.php
+++ b/src/Symfony/Component/VarDumper/Caster/Caster.php
@@ -54,6 +54,14 @@ class Caster
             $class = $class->name;
         }
 
+        if ($hasDebugInfo) {
+            try {
+                $debugInfo = $obj->__debugInfo();
+            } catch (\Exception $e) {
+                // ignore failing __debugInfo()
+                $hasDebugInfo = false;
+            }
+        }
+
         $a = $obj instanceof \Closure ? [] : (array) $obj;
 
         if ($obj instanceof \__PHP_Incomplete_Class) {
@@ -89,7 +97,7 @@ class Caster
             }
         }
 
-        if ($hasDebugInfo && \is_array($debugInfo = $obj->__debugInfo())) {
+        if ($hasDebugInfo && \is_array($debugInfo)) {
             foreach ($debugInfo as $k => $v) {
                 if (!isset($k[0]) || "\0" !== $k[0]) {
                     $k = self::PREFIX_VIRTUAL.$k;

flack · 2019-12-17T16:16:45Z

@nicolas-grekas I've adapted your patch to 4.4.1 (can't update to 5 due to conflicts), and it looks good: No more server errors, and dumps are displayed normally. Thx!

This PR was merged into the 3.4 branch. Discussion ---------- [VarDumper] ignore failing __debugInfo() | Q | A | ------------- | --- | Branch? | 3.4 | Bug fix? | yes | New feature? | no | Deprecations? | no | Tickets | Fix #34993 | License | MIT | Doc PR | - Commits ------- eb2eb76 [VarDumper] ignore failing __debugInfo()

javiereguiluz added Bug VarDumper labels Dec 16, 2019

carsonbot added the Status: Needs Review label Dec 16, 2019

flack mentioned this issue Dec 17, 2019

[VarDumper] fix dumping objects that implement __debugInfo() #32024

Merged

nicolas-grekas mentioned this issue Dec 17, 2019

[VarDumper] ignore failing __debugInfo() #35010

Merged

nicolas-grekas closed this as completed Dec 18, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Internal Server Error when calling dump() #34993

Internal Server Error when calling dump() #34993

flack commented Dec 16, 2019

flack commented Dec 16, 2019 •

edited

Loading

flack commented Dec 17, 2019

nicolas-grekas commented Dec 17, 2019 •

edited

Loading

flack commented Dec 17, 2019

Internal Server Error when calling dump() #34993

Internal Server Error when calling dump() #34993

Comments

flack commented Dec 16, 2019

flack commented Dec 16, 2019 • edited Loading

flack commented Dec 17, 2019

nicolas-grekas commented Dec 17, 2019 • edited Loading

flack commented Dec 17, 2019

flack commented Dec 16, 2019 •

edited

Loading

nicolas-grekas commented Dec 17, 2019 •

edited

Loading