Investigate PHP 7.3 workarounds

For MigrationPluginManagerTest, 7.2 and 7.3 are producing different results around the array_multisort call in Drupal\migrate\Plugin\MigrationPluginManager::buildDependencyMigration at line 211

The test tests the order of migrations after sorting them so dependent migrations run first. The broken test is asserting that an set of migrations that do not depend on each other are migrated in a specific order. In this case, the order doesn't actually matter, and the array_multisort call is made with both weighted at 0 (correctly). By the documentation "If two members compare as equal, their relative order in the sorted array is undefined." @see http://php.net/manual/en/function.array-multisort.php. Therefore it isn't correct to test that these particular migrations end up in this particular order.

In fact, if I xdebug pause right before the array_multisort is executed in 7.2 and resume, I get them in a different order and the test fails.

I'm throwing a few things against the testbot. Mixing the patch from part one for my own sanity.

I feel silly tracking down heisingbugs, but... is it the hasTranslation check, or the just the assertion causing the test to pass...

The Migration failure I was able to duplicate in a docker container - no xdebug, but I could at least poke at it with variable dumps. I haven't been able to replicate the EntityQueryTest issue though.

The more variations on this that I try, the more confused I get...

Is the heisingbug part of this due to using print_r with return set to TRUE in a test? According to the print_r docs , "When the return parameter is used, this function uses internal output buffering so it cannot be used inside an ob_start() callback function."

Because the only difference between #7 and #8 is the addition of the print_r to the end of the message in the assertTrue(FALSE) call. It shouldn't have possibly affected whether that assertion was ran...

Trying with serialize instead...

Checking with opcache disabled.

Not convinced... tries harder.

:D
Take a pick: b8ffa370.

Nice find. I figured it was a php bug, but I couldn't find it. I really wish it had occurred to me that I could cut down the test suite too. I need to remember that trick.

This one was driving me nuts all day.

Not sure about it being fixed by bug #76711 as it was committed on Sep 20 and the testbot's environment says:
PHP 7.3.0-dev (cli) (built: Sep 25 2018 18:34:07) ( NTS ).

@alexpott: I based it on drupalci_environments, but don't know what triggers the rebuilds.

Re #25: Checking first if they go away without opcache.
Edit: #25.2 went away.

Digging into #25.1.

Not pretty indeed, tweaking it a bit to be able to compare to known good.

Good news is that for both good and bad run serialization looks the same (only timestamps and random strings differ), so the problem is in unserializer. Another good thing is that it is consistent as both MigrateUpgrade6Test and MigrateUpgrade7Test fail in the same place:

// fails at '@'
...s:13:"_route_params";a:6:
{s:25:"_drupal_request_sanitized";b:1;s:5:"_form";s:41:"\Drupal\migrate_drupal_ui\Form\ReviewForm";s:6:"_title";s:7:"Upgrade";s:13:"_route_object";r:1430;s:14:"_raw_variables";r:1477@;s:14:"_access_result";r:1480;}...

So it is a problem with processing object reference, I've no idea why, maybe it rings a bell somewhere.
PHP's commit log: var_unserializer.c.

Reconstructed (replaced references above 1430 with a dummy one) and trimmed var_dump up to the failing point:

// ... - trimmed, ??? - corrupted references causing error
$batch =
array(12) {
  ["sets"]=>
  array(1) {
    ...
  }
  ["has_form_submits"]=>
  bool(false)
  ["form_state"]=>
  object(Drupal\Core\Form\FormState)#3 (34) {
    [" * complete_form"]=>
    array(30) {
      ...
    }
    [" * build_info"]=>
    array(4) {
      ["args"]=>
      array(0) {
      }
      ["files"]=>
      array(0) {
      }
      ["callback_object"]=>
      object(Drupal\migrate_drupal_ui\Form\ReviewForm)#15 (15) {
        [" * migrations"]=>
        array(114) {
          ...
        }
        ...
        [" * store"]=>
        object(Drupal\Core\TempStore\PrivateTempStore)#44 (6) {
          [" * storage"]=>
          object(Drupal\Core\KeyValueStore\DatabaseStorageExpirable)#45 (5) {
            [" * table"]=>
            string(16) "key_value_expire"
            [" * collection"]=>
            string(35) "tempstore.private.migrate_drupal_ui"
            [" * _serviceIds"]=>
            array(2) {
              ["serializer"]=>
              string(26) "serialization.phpserialize"
              ["connection"]=>
              string(8) "database"
            }
            [" * _entityStorages"]=>
            array(0) {
            }
          }
          ...
          [" * requestStack"]=>
          object(Symfony\Component\HttpFoundation\RequestStack)#49 (3) {
            [" Symfony\Component\HttpFoundation\RequestStack requests"]=>
            array(2) {
              [0]=>
              object(Symfony\Component\HttpFoundation\Request)#50 (24) {
                ["attributes"]=>
                object(Symfony\Component\HttpFoundation\ParameterBag)#51 (2) {
                  [" * parameters"]=>
                  array(9) {
                    ["_drupal_request_sanitized"]=>
                    bool(true)
                    ["_form"]=>
                    string(41) "\Drupal\migrate_drupal_ui\Form\ReviewForm"
                    ["_title"]=>
                    string(7) "Upgrade"
                    ["_route"]=>
                    string(32) "migrate_drupal_ui.upgrade_review"
                    ["_route_object"]=>
                    object(Symfony\Component\Routing\Route)#52 (1) {
                    }
                    ["_raw_variables"]=>
                    object(Symfony\Component\HttpFoundation\ParameterBag)#53 (2) {
                      [" * parameters"]=>
                      array(0) {
                      }
                    }
                    ["_controller"]=>
                    string(32) "controller.form:getContentResult"
                    ["_access_result"]=>
                    object(Drupal\Core\Access\AccessResultAllowed)#54 (4) {
                      [" * cacheContexts"]=>
                      array(0) {
                      }
                      [" * cacheTags"]=>
                      array(0) {
                      }
                      [" * cacheMaxAge"]=>
                      int(0)
                    }
                    ["_route_params"]=>
                    array(6) {
                      ["_drupal_request_sanitized"]=>
                      bool(true)
                      ["_form"]=>
                      string(41) "\Drupal\migrate_drupal_ui\Form\ReviewForm"
                      ["_title"]=>
                      string(7) "Upgrade"
                      ["_route_object"]=>
                      object(Symfony\Component\Routing\Route)#52 (1) {
                      }
                      ["_raw_variables"]=>
                      object(???)#4 (4) {
                      }
                      ["_access_result"]=>
                      object(???)#4 (4) {
                      }
                    }
                  }
                }
                ...
              }
              ...
            }
            ...
          }
          ...
        }
        ...
      }
      ...
    }
    ...
  }
  ...
}

Checking what changes with DependencySerializationTrait.

I meant "in the structure of serialized string", the patches produce log under artifacts\run_tests.functional\phpunit-xml.

Exactly those mentioned in #37 :), the serialized string is 11K smaller after and the only references left in it are to the TranslatableMarkup of the submit button.

Re-testing #26 as it only disabled optimizations and not the whole Opcache.

@alexpott: Could do a bit search on opcache.optimization_level to pinpoint which pass is responsible for https://bugs.php.net/bug.php?id=76937 ? Might help tracking it down.

Same as #40 but with Opcache and APC disabled.

The additional fail in CommentCSSTest from #42 is due to race condition with mkdir() in BrowserHtmlDebugTrait::initBrowserOutputFile().

Looks like we hit #25.1 again.
@tim.plunkett tracked it down to https://bugs.php.net/bug.php?id=77302:

[2019-01-22 19:57 UTC] dmitry@php.net
7.2 and below are affected by the same problem.
The old versions don't fail, but silently produce incorrect result (not the same as was serialized).

That would explain why in #31 both on 7.2 and 7.3 serialized strings looked the same.

We just fixed the serialization crash in Commerce by no longer using $this->logger in a serialized class: #3038430: Unable to checkout on php7.3.

If the logger was retrieved from LoggerChannelFactory, it can't be serialized, since it is invisible to DependencySerializationTrait.
Previously it would get silently corrupted, but PHP 7.3 changed that behavior.

The solution is to either store the factory service instead and retrieve the logger only when needed, or to define a channel-specific logger service, like core does:

  logger.channel.file:
    class: Drupal\Core\Logger\LoggerChannel
    factory: logger.factory:get
    arguments: ['file']

Also see https://www.drupal.org/project/entityqueue/issues/3043100 which points to https://github.com/php/php-src/commit/af324e24df85022314787f6dcf2ac811f5...

PHP bug https://bugs.php.net/bug.php?id=77302 is also rearing its head in the Oauth2 Server module, in #3049250: PHP 7.3 Session Handling Issue.

The problem there is basically that a request object can't survive serialization. This code produces an error:

  $request = \Drupal::request(); 
  $s = serialize($request);
  $u = unserialize($s);

Does the issue summary need to be updated for the object serialization problem?

After upgrading to php 7.3 all the custom AJAX callbacks in some custom forms were failing due to php serialisation error:

Notice: unserialize(): Error at offset 28221 of 41088 bytes in Drupal\Component\Serialization\PhpSerialize::decode() (line 21 of /var/www/html/docroot/core/lib/Drupal/Component/Serialization/PhpSerialize.php)

As a quick fix we are patching the /core/lib/Drupal/Core/Form/FormCache.php class setCache function

if ($data = $form_state->getCacheableArray()) {
      // Patch for fixing the known issue of PHP 7.3 unserialize error.
      <strong>unset($data['build_info']);</strong>
      $this->keyValueExpirableFactory->get('form_state')->setWithExpire($form_build_id, $data, $expire);
}

It though resolved the issue, we need to know the actual root cause and fix for it. Any help would be appreciated.

I bet it outdated!