Problem/Motivation

Seen this several times recently, most recent: https://git.drupalcode.org/project/drupal/-/jobs/9726770

  Automated Cron (Drupal\Tests\automated_cron\Functional\AutomatedCron)
     ✘ Runs cron on http request
       ┐
       ├ Failed asserting that 1778239032 is null.
       │
       │ /builds/core/modules/automated_cron/tests/src/Functional/AutomatedCronTest.php:42
       ┴

Steps to reproduce

Proposed resolution

Remaining tasks

User interface changes

Introduced terminology

API changes

Data model changes

Release notes snippet

Issue fork drupal-3589156

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

About issue forks

Comments

catch created an issue. See original summary.

longwave’s picture

longwave
he/him
Primary language English
Location UK
commented

The failure is here:

    \Drupal::state()->delete('system.cron_last');

    $this->assertNull(\Drupal::state()->get('system.cron_last'));

I can only assume that the first page load of the functional test is still terminating, which includes running cron, and AutomatedCron::onTerminate() writes the timestamp exactly between the delete and get?

Maybe we should not install automated_cron via $modules but manually in the test, then we won't make any accidental HTTP requests that would cause the terminate event to fire? In fact, we might just be able to assert the null instead of setting it first?

longwave’s picture

longwave
he/him
Primary language English
Location UK
commented
Status: Active » Needs review

Also took the liberty to fix up the @legacy-covers annotation while we're here.

longwave opened merge request !15711

catch’s picture

catch
he/him
Primary language English
commented
Status: Needs review » Reviewed & tested by the community

That looks great to me.

mstrelan’s picture

mstrelan commented

I can only assume that the first page load of the functional test is still terminating

What is the first http request? I didn't think there were any before this point in the test.

longwave’s picture

longwave
he/him
Primary language English
Location UK
commented

@mstrelan BrowserTestBase::setup() calls ::initMink() which calls ::initFrontPage() to visit the homepage so cookies can be set. So I guess if cron is installed already, it runs on the terminate event of this homepage load?

longwave’s picture

longwave
he/him
Primary language English
Location UK
commented

Perhaps instead of loading the homepage we could visit a known image URL or similar, which might be slightly more performant in some tests where we don't need to load the homepage at all? Out of scope for here though, unless we want to try that instead of the suggested fix.

longwave’s picture

longwave
he/him
Primary language English
Location UK
commented
Related issues: +#3589236: Visit an image instead of the homepage in BrowserTestBase::initFrontPage()

Opened #3589236: Visit an image instead of the homepage in BrowserTestBase::initFrontPage()

mstrelan’s picture

mstrelan commented

Thanks that makes sense

  • catch committed 3826a181 on 11.x 
    fix: #3589156 [random test failure] AutomatedCronTest randomly fails

By...

  • catch committed b078dad5 on main 
    fix: #3589156 [random test failure] AutomatedCronTest randomly fails

By...
catch’s picture

catch
he/him
Primary language English
commented
Version: main » 11.x-dev
Status: Reviewed & tested by the community » Fixed

So I guess if cron is installed already, it runs on the terminate event of this homepage load?

Yeah this has to be exactly what's happening. I'd forgotten about the initial front page load for cookies but automated cron will definitely run on the first http request that gets made.

Going to go ahead and commit this even though I RTBCd it because @mstrelan's review ended up a +1. The change here is pretty minimal and we have a follow-up for the trickier bit.

Now that this issue is closed, review the contribution record.

As a contributor, attribute any organization that helped you, or if you volunteered your own time.

Maintainers, credit people who helped resolve this issue.

catch closed merge request !15711

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.