[random test failure] PackageUpdateTest::testPackageUpdate

It seems like this affects more than just PackageUpdateTest, all package_manage tests failed here https://git.drupalcode.org/issue/drupal-3513875/-/jobs/4770092

the PHPUnit Build and Nightwatch jobs are now the worst offenders for random fails. I remember @catch mentioning something in slack about the package_manager tests but I can't find it

Running this test locally always fails for me, but it fails asserting the expected versions. That means makePackageManagerTestApiRequest is passing.

I found it odd that the Error response: in the output is empty, thinking maybe an error was thrown and system.logging error_logging was set to hide instead of verbose, but that's not the case. I explicitly put some errors in \Drupal\package_manager_test_api\ApiController::run but I could always see the error response in the output.

I then thought maybe there is an OOM or timeout. I didn't have much luck down the OOM route, but I did find that if I add this line to makePackageManagerTestApiRequest it would fail, even after asserting the 200 status code.

$this->assertSame('Finish', $session->getPage()->getContent());

1) Drupal\Tests\package_manager\Build\PackageUpdateTest::testPackageUpdate
Failed asserting that two strings are identical.
--- Expected
+++ Actual
@@ @@
-'Finish'
+'<br />
+<b>Fatal error</b>:  Maximum execution time of 20 seconds exceeded in <b>/tmp/build_workspace_4d8944e5916659803141418ed3171c99nCcLIM/project/vendor/php-tuf/composer-stager/src/Internal/Finder/Service/FileFinder.php</b> on line <b>68</b><br />'

I'm not sure exactly how that helps, but hoping it can spark some ideas.

FWIW I can replicate the exact error by adding this to the start of \Drupal\package_manager_test_api\ApiController::run

http_response_code(500);
die();

Fatal errors can often be 200s, I think we have an issue somewhere.

The timeout is not good, probably reflects something that could happen during actual operation.

Do we know where the 20 seconds max execution time is coming from? Bit surprised it's not 30 seconds. We could increase that to see if it helps the random failures and open a separate issue for the timeout.

AFK now but there is a constant in one of the test base classes that's setting it to 20 seconds. I'm not sure if there is something else about my local that's causing it to time out though.

This test fails for me locally with:

1) Drupal\Tests\package_manager\Build\PackageUpdateTest::testPackageUpdate
Failed asserting that two strings are identical.
--- Expected
+++ Actual
@@ @@
-'1.1.0'
+'1.0.0'

/var/www/html/core/modules/package_manager/tests/src/Build/PackageUpdateTest.php:63

which looks unrelated to the random test failure but also means I can't get a green test run to then try to make it fail the same way from there. Also tried reducing TemplateProjectTestBase::MAX_EXECUTION_TIME to 1 and that doesn't change anything for me.

That's the same experience I had. Most likely it is timing out after 1 sec but still a 200. If you assert that the response is empty it will probably fail and show the timeout error.

Side note I wonder if we can get htmlOutput to work here.

Ahh thanks this is very confusing.

I change the max execution time to 30 and it passed locally, pushed an MR for this.

I think we need two spin-off issues:

1. We should try to optimise the test and/or package_manager so we don't need a 30 second timeout.

2. We should try to make sure that fatal errors result in a 500 instead of 200 so we don't get false negatives on 200 assertions.

https://git.drupalcode.org/project/drupal/-/jobs/4824652 is the repeat test class job running with that change, it's varying between 400-700 seconds to complete, so very slow indeed, but so far each iteration is passing.

1. We should try to optimise the test and/or package_manager so we don't need a 30 second timeout.

I must admit I haven't tried to grok everything this test is trying to achieve, but it feels like PackageUpdateTest::testPackageUpdate could use a mocked response from the controller, and the controller could be tested independently. But maybe that's losing end-to-end coverage that we're trying to test for.

2. We should try to make sure that fatal errors result in a 500 instead of 200 so we don't get false negatives on 200 assertions.

Another approach would be to return a success string from the controller and assert that we get that in the response. That would catch the OOM and PHP timeout issues we were seeing locally.

https://git.drupalcode.org/project/drupal/-/jobs/4824652 is the repeat test class job running with that change, it's varying between 400-700 seconds to complete, so very slow indeed, but so far each iteration is passing.

That job passed 96 times and failed 4 times. This time instead of there being no error response we have an error to look at which I've included below, I've replaced html encoded entities for readability. The TL;DR is the rsync command is sometimes timing out after 2 minutes. This timeout seems to come from \PhpTuf\ComposerStager\API\Process\Service\ProcessInterface::DEFAULT_TIMEOUT, although it looks like \Drupal\package_manager\StageBase::create should be passing its own default, which is 300, so I'm not sure what's going on there.

Error response: The website encountered an unexpected error. Try again later.Drupal\package_manager\Exception\StageException: Failed to run process: <em class="placeholder">The process "'/usr/bin/rsync' '--archive' '--checksum' '--delete-after' '--verbose' '--exclude=/PACKAGE_MANAGER_FAILURE.yml' '--exclude=/web/sites/simpletest' '--exclude=/vendor/.htaccess' '--exclude=/web/sites/default/files' '--exclude=/web/sites/default/files/.sqlite' '--exclude=/web/sites/default/files/.sqlite-shm' '--exclude=/web/sites/default/files/.sqlite-wal' '--exclude=/recipes' '--exclude=/web/sites/default/default.settings.php' '--exclude=/web/sites/default/default.services.yml' '--exclude=/web/sites/default/settings.php' '--exclude=/web/sites/default/settings.local.php' '--exclude=/web/sites/default/services.yml' '--exclude=/package_manager_test_event.log' '--exclude=/tmp/.package_managerd1e3013e-0986-48a6-993d-25ac3459c1b2/ccKD8PwqcDLB4Q2kf2hMBv1EFnJulEs6' 'tmp/build_workspace_29b4565cc0c9b8a68abd3d8a6d0e7b8fGPvmzn/project/' 'tmp/.package_managerd1e3013e-0986-48a6-993d-25ac3459c1b2/ccKD8PwqcDLB4Q2kf2hMBv1EFnJulEs6'"; exceeded the timeout of 120 seconds.</em> in Drupal\package_manager\StageBase->rethrowAsStageException() (line 371 of core/modules/package_manager/src/StageBase.php). Symfony\Component\Process\Process->wait() (Line: 252)
       ├ Symfony\Component\Process\Process->run(Object, Array) (Line: 269)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                
       ├ Symfony\Component\Process\Process->mustRun(Object) (Line: 105)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
       ├ PhpTuf\ComposerStager\Internal\Process\Service\Process->mustRun(Object) (Line: 81)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
       ├ PhpTuf\ComposerStager\Internal\Process\Service\AbstractProcessRunner->run(Array, Object, Array, Object) (Line: 121)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
       ├ PhpTuf\ComposerStager\Internal\FileSyncer\Service\FileSyncer->runCommand(Object, Object, Object, Object) (Line: 58)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
       ├ PhpTuf\ComposerStager\Internal\FileSyncer\Service\FileSyncer->sync(Object, Object, Object, Object, 300) (Line: 38)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
       ├ PhpTuf\ComposerStager\Internal\Core\Beginner->begin(Object, Object, Object, Object, 300) (Line: 43)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
       ├ Drupal\package_manager\LoggingBeginner->begin(Object, Object, Object, Object, 300) (Line: 354)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                   
       ├ Drupal\package_manager\StageBase->create() (Line: 111)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           
       ├ Drupal\package_manager_test_api\ApiController->createAndApplyStage(Object) (Line: 73)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
       ├ Drupal\package_manager_test_api\ApiController->run(Object)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
       ├ call_user_func_array(Array, Array) (Line: 123)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                      
       ├ Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->Drupal\Core\EventSubscriber\{closure}() (Line: 593)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
       ├ Drupal\Core\Render\Renderer->executeInRenderContext(Object, Object) (Line: 121)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
       ├ Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->wrapControllerExecutionInRenderContext(Array, Array) (Line: 97)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                           
       ├ Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->Drupal\Core\EventSubscriber\{closure}() (Line: 183)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
       ├ Symfony\Component\HttpKernel\HttpKernel->handleRaw(Object, 1) (Line: 76)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
       ├ Symfony\Component\HttpKernel\HttpKernel->handle(Object, 1, 1) (Line: 53)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                         
       ├ Drupal\Core\StackMiddleware\Session->handle(Object, 1, 1) (Line: 48)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                             
       ├ Drupal\Core\StackMiddleware\KernelPreHandle->handle(Object, 1, 1) (Line: 28)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
       ├ Drupal\Core\StackMiddleware\ContentLength->handle(Object, 1, 1) (Line: 32)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
       ├ Drupal\big_pipe\StackMiddleware\ContentLength->handle(Object, 1, 1) (Line: 116)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
       ├ Drupal\page_cache\StackMiddleware\PageCache->pass(Object, 1, 1) (Line: 90)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
       ├ Drupal\page_cache\StackMiddleware\PageCache->handle(Object, 1, 1) (Line: 48)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
       ├ Drupal\Core\StackMiddleware\ReverseProxyMiddleware->handle(Object, 1, 1) (Line: 51)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
       ├ Drupal\Core\StackMiddleware\NegotiationMiddleware->handle(Object, 1, 1) (Line: 53)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               
       ├ Drupal\Core\StackMiddleware\AjaxPageState->handle(Object, 1, 1) (Line: 51)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                       
       ├ Drupal\Core\StackMiddleware\StackedHttpKernel->handle(Object, 1, 1) (Line: 715)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                  
       ├ Drupal\Core\DrupalKernel->handle(Object) (Line: 19)                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              
       ├ require('/tmp/build_workspace_29b4565cc0c9b8a68abd3d8a6d0e7b8fGPvmzn/project/web/index.php') (Line: 71)

Pushed an update to assert the response content, and restore the previous execution time to see if that catches anything.

The 120 timeout is still curious. I can't get xdebug working inside the php local server so it's hard to step through. Looks like it would be passing 300 all the way down to \PhpTuf\ComposerStager\Internal\FileSyncer\Service\FileSyncer::sync which calls $this->environment->setTimeLimit($timeout); but I'm not sure that actually affects anything, e.g. in \PhpTuf\ComposerStager\Internal\FileSyncer\Service\FileSyncer::runCommand the timeout is not passed to $this->rsync->run so it looks like it would just fallback to 120.

Edit: I raised FileSyncer::sync doesn't pass timeout to through to AbstractProcessRunner::run against php-tuf/composer-stager.

The plot thickens. Looks like package manager has a bunch of special handling around composer patches. I've managed to run a test locally that will patch php-tuf/composer-stager to pass the timeout through to the rsync command. I tested it my setting the timeout to 1 second in ApiController::createAndApplyStage and it failed after 1 second instead of 120.

I have a repeat job running with the timeout set to 180 - https://git.drupalcode.org/issue/drupal-3497701/-/jobs/4832276. If that passes (maybe we run it a few times), then we can probably postpone this on https://github.com/php-tuf/composer-stager/pull/414

Now we have yet-another-timeout to investigate - installing standard profile times out after 300 seconds:

    Package Update (Drupal\Tests\package_manager\Build\PackageUpdate)
     ✘ Package update
       ┐
       ├ Symfony\Component\Process\Exception\ProcessTimedOutException: The process "/usr/local/bin/php ./core/scripts/drupal install standard --no-ansi" exceeded the timeout of 300 seconds.
       │
       │ /builds/issue/drupal-3497701/vendor/symfony/process/Process.php:1182
       │ /builds/issue/drupal-3497701/vendor/symfony/process/Process.php:451
       │ /builds/issue/drupal-3497701/vendor/symfony/process/Process.php:252
       │ /builds/issue/drupal-3497701/core/tests/Drupal/BuildTests/Framework/BuildTestBase.php:336
       │ /builds/issue/drupal-3497701/core/tests/Drupal/BuildTests/QuickStart/QuickStartTestBase.php:40
       │ /builds/issue/drupal-3497701/core/modules/package_manager/tests/src/Build/TemplateProjectTestBase.php:187
       │ /builds/issue/drupal-3497701/core/modules/package_manager/tests/src/Build/TemplateProjectTestBase.php:334
       │ /builds/issue/drupal-3497701/core/modules/package_manager/tests/src/Build/PackageUpdateTest.php:22
       ┴

The 50x run has passed 3 times in a row now:

https://git.drupalcode.org/issue/drupal-3497701/-/jobs/4854823
https://git.drupalcode.org/issue/drupal-3497701/-/jobs/4856362
https://git.drupalcode.org/issue/drupal-3497701/-/jobs/4864839

Postponing on https://github.com/php-tuf/composer-stager/pull/414 but we could also focus on speeding up the test instead of increasing the timeout.

Upstream PR is merged, just need a release then we can bump php-tuf/composer-stager. Or maybe we postpone again on #3519246: Update Composer dependencies for 11.2.0.

Upstream issue is fixed in composer-stager 2.0.1, opened #3521438: Bump php-tuf/composer-stager to 2.0.1.

Committed the update in the other issue.

Shouldn't this be in package_manager component?

I couldn't reproduce a failure on HEAD after repeating ~50 times (this could be bc of the upstream fix added), but the changes in the MR make sense and the 50x run passed, so lgtm.

I started tests for the other environments this fails for in the daily scheduled test runs.

[Daily] PHP 8.4 MySQL 8.4
[Daily] PHP 8.3 PostgreSQL 16
[Daily] PHP 8.3 SQLite 3.45

There are other failures on those test runs but none for a Build test.

Committed/pushed to 11.x and cherry-picked to 11.2.x, thanks!

This is still failing insanely often. I would say 80% of my MR pushes yesterday (and I did a lot) had a phpunit build failure with a very similar message, e.g https://git.drupalcode.org/issue/drupal-3346394/-/jobs/6063361

Should we reopen this or a new issue?

I've reopened #3508109: [random test failure] Package manager random build failures that was originally closed as a dupe, let's continue there.