CommentResourceTestBase::testPostDxWithoutCriticalBaseFields() always fails on PHP 5.6 & MySQL 5.5 (works fine on other PHP versions)

So, it's not just CommentHalJsonAnonTest. It's \Drupal\Tests\rest\Functional\EntityResource\Comment\CommentResourceTestBase::testPostDxWithoutCriticalBaseFields() that fails on PHP 5.6+MySQL 5.5, for every subclass:

1. ComentHalJsonAnonTest
2. ComentHalJsonBasicAuthTest
3. ComentHalJsonCookieTest
4. ComentJsonAnonTest
5. ComentJsonBasicAuthTest
6. ComentJsonCookieTest

The failing line:

$this->assertResourceErrorResponse(500, 'A fatal error occurred: Internal Server Error', $response);

It seems that for some reason, Drupal 8 does not generate a 500 response with a response body containing A fatal error occurred: Internal Server Error on PHP 5.6. On PHP 5.5 and PHP 7, it does. But on 5.6, it outputs this instead:

Error: Call to a member function get() on null
Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator->getAnonymousContactDetailsSetting()() (Line: 96)

In other words, it seems that Drupal 8 on PHP 5.6 does not succeed in hiding the fatal error from the end user, unlike 5.5/7.

See #5.

1. I will try to reproduce this locally with PHP 5.6.
2. The full code is
   

       // @todo Uncomment, remove next line in https://www.drupal.org/node/2820364.
       $this->assertResourceErrorResponse(500, 'A fatal error occurred: Internal Server Error', $response);
       //$this->assertResourceErrorResponse(422, "Unprocessable Entity: validation failed.\nentity_type: This value should not be null.\n", $response);
   

   , for which we have this issue: #2820364: Entity + Field + Property validation constraints are processed in the incorrect order.

Reproduced locally on PHP 5.6.27:

wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ php vendor/bin/phpunit -c core core/modules/rest/tests/src/Functional/EntityResource/Comment/CommentJsonCookieTest.php
PHPUnit 4.8.27 by Sebastian Bergmann and contributors.

F

Time: 14.1 seconds, Memory: 6.25Mb

There was 1 failure:

1) Drupal\Tests\rest\Functional\EntityResource\Comment\CommentJsonCookieTest::testPostDxWithoutCriticalBaseFields
Failed asserting that two strings are identical.
--- Expected
+++ Actual
@@ @@
-Error: Call to a member function get() on null
-Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator->getAnonymousContactDetailsSetting()() (Line: 96)
-
+Failed asserting that 200 is identical to 500.

/Users/wim.leers/Work/d8/core/modules/rest/tests/src/Functional/EntityResource/Comment/CommentResourceTestBase.php:296

FAILURES!
Tests: 1, Assertions: 7, Failures: 1.

Now I can determine the root cause.

I think testing for 500s is tricky, as these errors might depend on PHP configurations. I think commenting this test out with the todo might be not the worst idea.

My analysis in #2 pointed to the wrong code.

This is the relevant test code:

    // DX: 422 when missing 'entity_id' field.
    $request_options[RequestOptions::BODY] = $this->serializer->encode(array_diff_key($this->getNormalizedPostEntity(), ['entity_id' => TRUE]), static::$format);
    // @todo Remove the try/catch in favor of the two commented lines in
    // https://www.drupal.org/node/2820364.
    try {
      $response = $this->request('POST', $url, $request_options);
      // This happens on DrupalCI.
      $this->assertSame(500, $response->getStatusCode());
    }
    catch (\Exception $e) {
      // This happens on Wim's local machine.
      $this->assertSame("Error: Call to a member function get() on null\nDrupal\\comment\\Plugin\\Validation\\Constraint\\CommentNameConstraintValidator->getAnonymousContactDetailsSetting()() (Line: 96)\n", $e->getMessage());
    }
    //$response = $this->request('POST', $url, $request_options);
    //$this->assertResourceErrorResponse(422, "Unprocessable Entity: validation failed.\nentity_type: This value should not be null.\n", $response);

And it's that very long line below // This happens on Wim's local machine. that is failing on PHP 5.6. That try/catch is to show the difference between testbot (where the "catch" was not being used) and my local machine (where the "catch" was necessary). It seems like testbot does need that "catch" in the case of PHP 5.6, but not PHP 5.5 or PHP 7. The "catch" therefore describes inconsistencies in PHP execution behavior". But it seems like testbot fails in an even different way than my local machine. Except on PHP 5.6, it seems to match.

Investigating further…

So the difference is that PHP 7 converts a fatal error to a 500 response, but PHP 5.6 (and 5.5) convert it to a 200 response. All three PHP runtimes actually produce the same fundamental error.

There are two problems here:

1. Drupal 8 handles fatal errors differently in the case of PHP 5 (fatal error printed directly, printed as a 200 response per default PHP behavior) versus PHP 7 (prints the The website encountered an unexpected error. Please try again later. thing, and then the error, printed as 500 response per Drupal's catchable exception handling) Because fatal errors can actually be caught in PHP 7, but not in PHP 5.
2. \Drupal\Core\Test\HttpClientMiddleware\TestHttpClientMiddleware behaves differently in PHP 5 and PHP 7.

Attached patch contains small modifications to prove these claims.

This should result in this output:

wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ sphp 55
PHP version 55 found
Unlinking old binaries...
Linking new binaries...
Linking /usr/local/Cellar/php55/5.5.38_11... 17 symlinks created
Linking new modphp addon...
Fixing LoadModule...
Updating version file...
Restarting non-root homebrew Apache...
Done.

PHP 5.5.38 (cli) (built: Oct 17 2016 10:59:26) 
Copyright (c) 1997-2015 The PHP Group
Zend Engine v2.5.0, Copyright (c) 1998-2015 Zend Technologies
    with Zend OPcache v7.0.6-dev, Copyright (c) 1999-2015, by Zend Technologies
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ sudo apachectl restart
AH00548: NameVirtualHost has no effect and will be removed in the next release /usr/local/etc/apache2/2.4/httpd.conf:528
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ php vendor/bin/phpunit -c core core/modules/rest/tests/src/Functional/EntityResource/Comment/CommentJsonCookieTest.php
PHPUnit 4.8.27 by Sebastian Bergmann and contributors.

Estring(14) "This is PHP 5!"
string(224) "<br />
<b>Fatal error</b>:  Call to a member function get() on a non-object in <b>/Users/wim.leers/Work/d8/core/modules/comment/src/Plugin/Validation/Constraint/CommentNameConstraintValidator.php</b> on line <b>96</b><br />
"


Time: 12.19 seconds, Memory: 6.25Mb

There was 1 error:

1) Drupal\Tests\rest\Functional\EntityResource\Comment\CommentJsonCookieTest::testPostDxWithoutCriticalBaseFields
This test printed output: string(14) "This is PHP 5!"
string(224) "<br />
<b>Fatal error</b>:  Call to a member function get() on a non-object in <b>/Users/wim.leers/Work/d8/core/modules/comment/src/Plugin/Validation/Constraint/CommentNameConstraintValidator.php</b> on line <b>96</b><br />
"

FAILURES!
Tests: 1, Assertions: 9, Errors: 1.
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ sphp 56
PHP version 56 found
Unlinking old binaries...
Linking new binaries...
Linking /usr/local/Cellar/php56/5.6.27_4... 17 symlinks created
Linking new modphp addon...
Fixing LoadModule...
Updating version file...
Restarting non-root homebrew Apache...
Done.

PHP 5.6.27 (cli) (built: Oct 17 2016 11:11:34) 
Copyright (c) 1997-2016 The PHP Group
Zend Engine v2.6.0, Copyright (c) 1998-2016 Zend Technologies
    with Zend OPcache v7.0.6-dev, Copyright (c) 1999-2016, by Zend Technologies
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ sudo apachectl restart
AH00548: NameVirtualHost has no effect and will be removed in the next release /usr/local/etc/apache2/2.4/httpd.conf:528
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ php vendor/bin/phpunit -c core core/modules/rest/tests/src/Functional/EntityResource/Comment/CommentJsonCookieTest.php
PHPUnit 4.8.27 by Sebastian Bergmann and contributors.

Estring(14) "This is PHP 5!"
string(216) "<br />
<b>Fatal error</b>:  Call to a member function get() on null in <b>/Users/wim.leers/Work/d8/core/modules/comment/src/Plugin/Validation/Constraint/CommentNameConstraintValidator.php</b> on line <b>96</b><br />
"


Time: 11.8 seconds, Memory: 6.25Mb

There was 1 error:

1) Drupal\Tests\rest\Functional\EntityResource\Comment\CommentJsonCookieTest::testPostDxWithoutCriticalBaseFields
This test printed output: string(14) "This is PHP 5!"
string(216) "<br />
<b>Fatal error</b>:  Call to a member function get() on null in <b>/Users/wim.leers/Work/d8/core/modules/comment/src/Plugin/Validation/Constraint/CommentNameConstraintValidator.php</b> on line <b>96</b><br />
"

FAILURES!
Tests: 1, Assertions: 9, Errors: 1.
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ sphp 70
PHP version 70 found
Unlinking old binaries...
Linking new binaries...
Linking /usr/local/Cellar/php70/7.0.12_5... 17 symlinks created
Linking new modphp addon...
Fixing LoadModule...
Updating version file...
Restarting non-root homebrew Apache...
Done.

PHP 7.0.12 (cli) (built: Oct 17 2016 11:16:49) ( NTS )
Copyright (c) 1997-2016 The PHP Group
Zend Engine v3.0.0, Copyright (c) 1998-2016 Zend Technologies
    with Zend OPcache v7.0.12, Copyright (c) 1999-2016, by Zend Technologies
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ sudo apachectl restart
AH00548: NameVirtualHost has no effect and will be removed in the next release /usr/local/etc/apache2/2.4/httpd.conf:528
wim.leers at acquia in ~/Work/d8 on 8.3.x*
$ php vendor/bin/phpunit -c core core/modules/rest/tests/src/Functional/EntityResource/Comment/CommentJsonCookieTest.php
PHPUnit 4.8.27 by Sebastian Bergmann and contributors.

Estring(14) "This is PHP 7!"
string(2877) "The website encountered an unexpected error. Please try again later.<br /><em class="placeholder">Error</em>: Call to a member function get() on null in <em class="placeholder">Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator-&gt;getAnonymousContactDetailsSetting()</em> (line <em class="placeholder">96</em> of <em class="placeholder">core/modules/comment/src/Plugin/Validation/Constraint/CommentNameConstraintValidator.php</em>). <pre class="backtrace">Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator-&gt;getAnonymousContactDetailsSetting(Object) (Line: 77)
Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator-&gt;validate(Object, Object) (Line: 185)
Drupal\Core\TypedData\Validation\RecursiveContextualValidator-&gt;validateConstraints(Object, &#039;0000000002e747640000000001efe6ea&#039;, Array) (Line: 140)
Drupal\Core\TypedData\Validation\RecursiveContextualValidator-&gt;validateNode(Object, Array, 1) (Line: 99)
Drupal\Core\TypedData\Validation\RecursiveContextualValidator-&gt;validate(Object, NULL, NULL) (Line: 90)
Drupal\Core\TypedData\Validation\RecursiveValidator-&gt;validate(Object) (Line: 135)
Drupal\Core\TypedData\TypedData-&gt;validate() (Line: 381)
Drupal\Core\Entity\ContentEntityBase-&gt;validate() (Line: 29)
Drupal\rest\Plugin\rest\resource\EntityResource-&gt;validate(Object) (Line: 165)
Drupal\rest\Plugin\rest\resource\EntityResource-&gt;post(Object, Object)
call_user_func_array(Array, Array) (Line: 132)
Drupal\rest\RequestHandler-&gt;handle(Object, Object)
call_user_func_array(Array, Array) (Line: 123)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber-&gt;Drupal\Core\EventSubscriber\{closure}() (Line: 574)
Drupal\Core\Render\Renderer-&gt;executeInRenderContext(Object, Object) (Line: 124)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber-&gt;wrapControllerExecutionInRenderContext(Array, Array) (Line: 97)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber-&gt;Drupal\Core\EventSubscriber\{closure}()
call_user_func_array(Object, Array) (Line: 139)
Symfony\Component\HttpKernel\HttpKernel-&gt;handleRaw(Object, 1) (Line: 62)
Symfony\Component\HttpKernel\HttpKernel-&gt;handle(Object, 1, 1) (Line: 57)
Drupal\Core\StackMiddleware\Session-&gt;handle(Object, 1, 1) (Line: 47)
Drupal\Core\StackMiddleware\KernelPreHandle-&gt;handle(Object, 1, 1) (Line: 99)
Drupal\page_cache\StackMiddleware\PageCache-&gt;pass(Object, 1, 1) (Line: 78)
Drupal\page_cache\StackMiddleware\PageCache-&gt;handle(Object, 1, 1) (Line: 47)
Drupal\Core\StackMiddleware\ReverseProxyMiddleware-&gt;handle(Object, 1, 1) (Line: 50)
Drupal\Core\StackMiddleware\NegotiationMiddleware-&gt;handle(Object, 1, 1) (Line: 23)
Stack\StackedHttpKernel-&gt;handle(Object, 1, 1) (Line: 656)
Drupal\Core\DrupalKernel-&gt;handle(Object) (Line: 19)
</pre>"


Time: 7.5 seconds, Memory: 6.00Mb

There was 1 error:

1) Drupal\Tests\rest\Functional\EntityResource\Comment\CommentJsonCookieTest::testPostDxWithoutCriticalBaseFields
This test printed output: string(14) "This is PHP 7!"
string(2877) "The website encountered an unexpected error. Please try again later.<br /><em class="placeholder">Error</em>: Call to a member function get() on null in <em class="placeholder">Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator-&gt;getAnonymousContactDetailsSetting()</em> (line <em class="placeholder">96</em> of <em class="placeholder">core/modules/comment/src/Plugin/Validation/Constraint/CommentNameConstraintValidator.php</em>). <pre class="backtrace">Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator-&gt;getAnonymousContactDetailsSetting(Object) (Line: 77)
Drupal\comment\Plugin\Validation\Constraint\CommentNameConstraintValidator-&gt;validate(Object, Object) (Line: 185)
Drupal\Core\TypedData\Validation\RecursiveContextualValidator-&gt;validateConstraints(Object, &#039;0000000002e747640000000001efe6ea&#039;, Array) (Line: 140)
Drupal\Core\TypedData\Validation\RecursiveContextualValidator-&gt;validateNode(Object, Array, 1) (Line: 99)
Drupal\Core\TypedData\Validation\RecursiveContextualValidator-&gt;validate(Object, NULL, NULL) (Line: 90)
Drupal\Core\TypedData\Validation\RecursiveValidator-&gt;validate(Object) (Line: 135)
Drupal\Core\TypedData\TypedData-&gt;validate() (Line: 381)
Drupal\Core\Entity\ContentEntityBase-&gt;validate() (Line: 29)
Drupal\rest\Plugin\rest\resource\EntityResource-&gt;validate(Object) (Line: 165)
Drupal\rest\Plugin\rest\resource\EntityResource-&gt;post(Object, Object)
call_user_func_array(Array, Array) (Line: 132)
Drupal\rest\RequestHandler-&gt;handle(Object, Object)
call_user_func_array(Array, Array) (Line: 123)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber-&gt;Drupal\Core\EventSubscriber\{closure}() (Line: 574)
Drupal\Core\Render\Renderer-&gt;executeInRenderContext(Object, Object) (Line: 124)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber-&gt;wrapControllerExecutionInRenderContext(Array, Array) (Line: 97)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber-&gt;Drupal\Core\EventSubscriber\{closure}()
call_user_func_array(Object, Array) (Line: 139)
Symfony\Component\HttpKernel\HttpKernel-&gt;handleRaw(Object, 1) (Line: 62)
Symfony\Component\HttpKernel\HttpKernel-&gt;handle(Object, 1, 1) (Line: 57)
Drupal\Core\StackMiddleware\Session-&gt;handle(Object, 1, 1) (Line: 47)
Drupal\Core\StackMiddleware\KernelPreHandle-&gt;handle(Object, 1, 1) (Line: 99)
Drupal\page_cache\StackMiddleware\PageCache-&gt;pass(Object, 1, 1) (Line: 78)
Drupal\page_cache\StackMiddleware\PageCache-&gt;handle(Object, 1, 1) (Line: 47)
Drupal\Core\StackMiddleware\ReverseProxyMiddleware-&gt;handle(Object, 1, 1) (Line: 50)
Drupal\Core\StackMiddleware\NegotiationMiddleware-&gt;handle(Object, 1, 1) (Line: 23)
Stack\StackedHttpKernel-&gt;handle(Object, 1, 1) (Line: 656)
Drupal\Core\DrupalKernel-&gt;handle(Object) (Line: 19)
</pre>"

FAILURES!
Tests: 1, Assertions: 9, Errors: 1.

#6.2 accuses \Drupal\Core\Test\HttpClientMiddleware\TestHttpClientMiddleware inappropriately. There's nothing it can do about that. Because it can only throw exceptions for those things that PHP itself threw exceptions for during the request. Any exceptions are transformed to X-Drupal-Assertion-<ID> headers. In this case:

X-Drupal-Assertion-0: a%3A3%3A%7Bi%3A0%3Bs%3A39%3A%22Call%20to%20a%20member%20function%20get%28%29%20on%20null%22%3Bi%3A1%3Bs%3A5%3A%22Error%22%3Bi%3A2%3Ba%3A3%3A%7Bs%3A8%3A%22function%22%3Bs%3A111%3A%22Drupal%5Ccomment%5CPlugin%5CValidation%5CConstraint%5CCommentNameConstraintValidator-%3EgetAnonymousContactDetailsSetting%28%29%22%3Bs%3A4%3A%22file%22%3Bs%3A113%3A%22%2FUsers%2Fwim.leers%2FWork%2Fd8%2Fcore%2Fmodules%2Fcomment%2Fsrc%2FPlugin%2FValidation%2FConstraint%2FCommentNameConstraintValidator.php%22%3Bs%3A4%3A%22line%22%3Bi%3A96%3B%7D%7D

… but that's only going to happen on PHP 7. And TestHttpClientMiddleware of course can only throw exceptions for those response headers it finds. So the difference in behavior I perceived in #6 is entirely attributable to PHP 7 vs PHP 5 (able to catch fatal errors vs not).

It could be argued that it's up to D8's error handler to ignore PHP 7 catchable fatal errors for consistency with PHP 5, but there are probably good reasons not do to that.

And here then is the solution, to assert the fatal errors correctly on both PHP 5 & 7.

Now working on #2820364: Entity + Field + Property validation constraints are processed in the incorrect order, which will remove the need for all this entirely. In the mean time, these assertions ensure that PHP 5.5, PHP 5.6 and PHP 7.0 all fail in the same way.

+++ b/core/modules/rest/tests/src/Functional/EntityResource/Comment/CommentResourceTestBase.php
@@ -288,11 +288,16 @@ public function testPostDxWithoutCriticalBaseFields() {
+      if (version_compare(phpversion(), '7.0') < 0) {

Should this if have an else and fail if we get there - or should it not exist at all?

Hm, this is interesting. Drupal CI's PHP 5.5 is apparently configured to serve a 500 response instead of the default 200 response for fatal errors. But, we honestly don't care too much about the status code. It's the fact that there's a fatal error … that we do care about.

So, this should do the trick.

#12: good point! Done.

This also applies to Drupal 8.2 BTW.

Also queuing #14 to be tested against 8.2.x, and also against PHP 5.5, 5.6 and 7.0.

I'm having a little trouble with the 2 different approaches for validating the error message. For php < 7.0 only parts of the error are validated. For php >= 7.0 the complete error message is validated. If even a single line is added to CommentNameConstraintValidator.php the test will pass in php < 7.0 and fail in php >= 7.0, to me for no good reason.

I changed it a little to use the same logic. I don't have php 7 or 5.6 running yet so the attached patch might fail, sorry for that.

Hm, still failing on 5.5. It seems like Drupal CI's PHP 5.5 is doing some strange things…

(Ironic that the problem now "jumped" from 5.6 to 5.5…)

I can't really wrap my head around the exact problem as it's impossible to reproduce locally (on php 5.5).

As I saw discussed on IRC: it's the difference in the way the error is reported.

The basic variations are something like:
- Call to a member function get() on null
- Call to a member function get() on CommentNameConstraintValidator

How important is it to check on the CommentNameConstraintValidator? I removed that check form this patch, let's see if that fixes the problem.

I think we should comment out the assertions to get HEAD back to passing on 5.6, then open another issue to uncomment them, but that is likely to require #2688999: Default all responses to 500 before any code is run so PHP will throw 500's on FATAL errors really.

Here's a patch for that. The existing @todo is sufficient if this is going to move to a 422 eventually anyway.

#24 works for me to hotfix the test without rolling back the whole patch, so long as it's explicitly in scope for the followup.

I queued all the environments.

The postgres fail is

Outside_in.Drupal\Tests\outside_in\FunctionalJavascript\OutsideInBlockFormTest

to save people looking.

Yep, #24 is the rougher option that @dawehner proposed in #4. That is obviously guaranteed to work. I'd have preferred to strictly validate the fatal error, but it's really a nit. We can indeed comment its assertions, and the follow-up (#2820364: Entity + Field + Property validation constraints are processed in the incorrect order) A) definitely removes all that hackiness and B) is already in progress!

So, moving this to RTBC.

For future readers: the fail catch mentioned in #26 is a known current random fail: #2830485: \Drupal\Tests\outside_in\FunctionalJavascript\OutsideInBlockFormTest fails randomly.

Committed and pushed f7aed20 to 8.3.x and d34d9dc to 8.2.x. Thanks!

It seems like we have all the followups planned - we could add @todos but the test fails are worse... moving on.

Yep, all follow-ups planned!