Problem/Motivation

Two of the RTBC issues I am following just got bumped to NW because MonthDatePluginTest failed:

Here is the test failure from the first one. The second is similar, but with a different pseudo-random string.

1) Drupal\Tests\views\Functional\Plugin\MonthDatePluginTest::testMonthDatePlugin
Behat\Mink\Exception\ResponseTextException: The text "ugxIiAQx" appears in the text of this page, but it should not.

/var/www/html/vendor/behat/mink/src/WebAssert.php:785
/var/www/html/vendor/behat/mink/src/WebAssert.php:279
/var/www/html/core/tests/Drupal/Tests/WebAssert.php:896
/var/www/html/core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php:81
/var/www/html/vendor/phpunit/phpunit/src/Framework/TestResult.php:703

ERRORS!
Tests: 1, Assertions: 3, Errors: 1.

Steps to reproduce

Run the MonthDatePluginTest when Sydney is not observing DST.

Proposed resolution

#4: Use dates that are not the first of the month, since time zone conversions can switch them to a different month.

#15: When creating nodes with specific timestamps, make those timestamps in UTC.

Remaining tasks

User interface changes

API changes

Data model changes

Release notes snippet

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

benjifisher created an issue. See original summary.

benjifisher’s picture

What timezone does the testbot live in? Did it just switch to DST?

benjifisher’s picture

benjifisher’s picture

Issue summary: View changes
Priority: Normal » Major
Status: Active » Needs review
FileSize
834 bytes

I think that @xjm once told me that issues like this should be considered Critical. Let's at least call this major.

I asked on Slack,

I wonder: what timezone does the testbot live in? Did it just switch to DST?

and @larowlan replied,

The TZ is Sydney, and yes just finished DST

so I think my guess is right. Changing the dates of the test nodes from 2020-10-01 and 2020-11-01 to 2020-10-05 and 2020-11-05 fixes the problem when I run the test locally. Patch attached.

benjifisher’s picture

In case anyone is curious about why timezones were my first guess. The name of the test is a hint. In addition, I used to be active on the Vim users' mailing list. Once or twice a year (I forget whether it was the start or end of DST or both) there would be a flurry of bug reports from Windows users.

benjifisher’s picture

benjifisher’s picture

I am crediting @mondrake because they added #3207083: [HEAD BROKEN] Drupal\Tests\views\Functional\Plugin\MonthDatePluginTest::testMonthDatePlugin started failing on DrupalCI a couple of hours before I added this issue.

benjifisher’s picture

benjifisher’s picture

Since this bug is time-sensitive, I want to get this on the record while I can reproduce the failing test. I can reproduce the problem locally, and my patch fixes it.

benji@pop-os:~/Sites/drupal$ git diff 9.2.x
diff --git a/core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php b/core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php
index 2f6712432a..fdd120390f 100644
--- a/core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php
+++ b/core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php
@@ -50,9 +50,9 @@ class MonthDatePluginTest extends ViewTestBase {
    */
   public function setUp($import_test_views = TRUE): void {
     parent::setUp($import_test_views);
-    $date1 = '2020-10-01 00:00:00';
+    $date1 = '2020-10-05 00:00:00';
     $this->node1 = $this->drupalCreateNode(['created' => strtotime($date1)]);
-    $date2 = '2020-11-01 00:00:00';
+    $date2 = '2020-11-05 00:00:00';
     $this->node2 = $this->drupalCreateNode(['created' => strtotime($date2)]);
   }
 
benji@pop-os:~/Sites/drupal$ lando phpunit core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php
PHPUnit 8.5.13 by Sebastian Bergmann and contributors.

Testing Drupal\Tests\views\Functional\Plugin\MonthDatePluginTest
.                                                                   1 / 1 (100%)

Time: 5.93 seconds, Memory: 6.00 MB

OK (1 test, 3 assertions)

HTML output was generated
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-30-46453418.html
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-31-46453418.html
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-32-46453418.html
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-33-46453418.html
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-34-46453418.html
benji@pop-os:~/Sites/drupal$ git checkout 9.2.x
Switched to branch '9.2.x'
Your branch is up to date with 'origin/9.2.x'.
benji@pop-os:~/Sites/drupal$ lando phpunit core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php
PHPUnit 8.5.13 by Sebastian Bergmann and contributors.

Testing Drupal\Tests\views\Functional\Plugin\MonthDatePluginTest
E                                                                   1 / 1 (100%)

Time: 5.72 seconds, Memory: 6.00 MB

There was 1 error:

1) Drupal\Tests\views\Functional\Plugin\MonthDatePluginTest::testMonthDatePlugin
Behat\Mink\Exception\ResponseTextException: The text "uDt53U1i" appears in the text of this page, but it should not.

/app/vendor/behat/mink/src/WebAssert.php:785
/app/vendor/behat/mink/src/WebAssert.php:279
/app/core/tests/Drupal/Tests/WebAssert.php:896
/app/core/modules/views/tests/src/Functional/Plugin/MonthDatePluginTest.php:81
/app/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

ERRORS!
Tests: 1, Assertions: 3, Errors: 1.

HTML output was generated
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-35-62502147.html
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-36-62502147.html
https://drupal.lndo.site//sites/simpletest/browser_output/Drupal_Tests_views_Functional_Plugin_MonthDatePluginTest-37-62502147.html
jhodgdon’s picture

Priority: Major » Critical
Status: Needs review » Reviewed & tested by the community

Another fail on #3087218: Help searches fail if site is not fully indexed, and users do not know why. This many fails once a year seems critical to me. I'm not sure it counts as "random", but it's definitely bad.

The analysis of the problem and the fix both make good sense. Let's get this in.

benjifisher’s picture

Priority: Critical » Major
Status: Reviewed & tested by the community » Needs review

Another one: #3173900: Refactor Olivero's JavaScript Drupal behaviors to use once().

I do not 100% understand how today's TZ shift affects dates from a few months ago, but I do know that if you shift 2020-11-01 00:00:00 by one hour in the wrong direction, then it will show up on the page for October, which is what happens in the test. Since the patch makes the test pass, I am about 99.99% confident that this is the right explanation.

nod_’s picture

larowlan’s picture

The test fails because the timestamp stored in the database should be calculated in UTC, not Australia/Sydney

See https://3v4l.org/Q8ajV

This is a more robust fix in my opinion

No interdiff.

larowlan’s picture

Issue tags: +Bug Smash Initiative
Spokje’s picture

Status: Needs review » Reviewed & tested by the community

- Root cause explained
- Green Test result

RTBC for me.

Kudos to @larowlan for finding the root cause and to @benjifisher for linking it to timezones! 🙏

Spokje’s picture

Priority: Major » Critical

Bumping this to Critical, because:

- Every Core issue that is tested will fail and not everybody will understand why and/or have seen this issue. This might/will cause a lot of duplicate issues to this one.
- Core issues on RTBC that are being retested as part of the "Retest every 2 days"-program will fail and loose their RTBC status to a Needs Work one. Even if the next round of retesting in 2 days will turn out fine after this issue is committed, I'm not sure the RTBC status will be re-set automagically.
On top of that: In this 2 day period, there will be a lot of issues that are actually RTBC (so most probably committable), not showing up in the overview with that status. So a lot of tested issues will be delayed in being committed.

All in all a lot of housekeeping work that nobody likes IMHO.

mondrake’s picture

Title: Random failure in MonthDatePluginTest » [HEAD BROKEN] Random failure in MonthDatePluginTest
mondrake’s picture

Title: [HEAD BROKEN] Random failure in MonthDatePluginTest » [HEAD BROKEN] Consistent failure in MonthDatePluginTest
Issue tags: -Random test failure

Not random...

  • catch committed fd3efb7 on 9.2.x
    Issue #3207086 by benjifisher, larowlan, mondrake, Spokje: [HEAD BROKEN...

  • catch committed 46f8a1b on 9.1.x
    Issue #3207086 by benjifisher, larowlan, mondrake, Spokje: [HEAD BROKEN...
catch’s picture

Version: 9.2.x-dev » 9.1.x-dev
Status: Reviewed & tested by the community » Fixed

Committed/pushed to 9.2.x and cherry-picked to 9.1.x, thanks! Nice one finding the real problem.

benjifisher’s picture

Version: 9.1.x-dev » 8.9.x-dev
Issue summary: View changes
Status: Fixed » Reviewed & tested by the community

Re #18: The issue was already promoted to Critical. I accidentally set it back to Major in #13.

I am updating the issue summary: the test failure is still reproducible even though we are past the DST change. I think that means the test (before this issue was fixed) would fail whenever Sydney is on Standard Time.

It looks as though #2969107: 500 error on passing invalid month to MonthDate view argument handler was committed to the 8.9.x branch. I think that means we should backport this issue, too. I tested locally with and without the patch from #14: the test fails without the patch.

benjifisher’s picture

Issue summary: View changes

Oops, my issue summary update was not quite right.

benjifisher’s picture

FileSize
93.11 KB

I am not sure that we have a complete understanding of the problem here.

The patch in #4 and the one in #15 both get the test to pass. One patch moves the dates to the 5'th of the month instead of the 1'st. The other patch has the effect of moving the times from 00:00:00 to 10:00:00 or 11:00:00 (ST/DST). Either change is enough to protect the timestamps from moving to the wrong month if the TZ calculation is off by 1 hour because of DST confusion.

This test started failing when Sydney switched from DST to ST. The problem is not that our timestamps are in the wrong timezone. The problem is that somewhere the DST adjustment is off.

Is the patch in #15 really better than the one in #4? It is if you think that the right thing to do is express all times in UTC. If that were the case, then I would expect

    $this->node3 = $this->drupalCreateNode([
      'created' => \DateTime::createFromFormat($format, '2020-09-30 23:59:59', $utc)->getTimestamp(),
    ]);

to reliably have its month set to September, not October. In other words, I would expect the test to pass with the attached patch (applied to 9.2.x, where this issue is already fixed). When I test locally, it fails.

I will not ask the testbot to try the attached patch, because I want to keep the status at RTBC for 8.9.x.

If I am right that we still have work to do, then I think we can do it in a non-critical follow-up issue.

Spokje’s picture

FileSize
1.94 KB

#24:

It looks as though #2969107: 500 error on passing invalid month to MonthDate view argument handler was committed to the 8.9.x branch. I think that means we should backport this issue, too. I tested locally with and without the patch from #14: the test fails without the patch.

(As usual) @benjifisher is spot on. D8.9.x tests are failing due to this, backport is needed.
Here's an example: https://www.drupal.org/pift-ci-job/2022042

#26:

There's definitely a problem there that needs a follow-up. Added a slightly smaller patch (@benjifisher seems to have left his drush reference in the patch), but for me it fails locally as well.

Currently the patch is tested against 9.2.x here: #3191612-12: [Ignore] In space (and/or this issue), no one can hear patches scream
I expect it to fail as well.

catch’s picture

Status: Reviewed & tested by the community » Fixed

OK I've cherry-picked back to 8.9.x, and opened a follow-up at #3207183: Views arguments do not apply DST adjustment correctly.

benjifisher’s picture

@Spokje:

Thanks for checking!

@benjifisher seems to have left his drush reference in the patch

I was not able to sleep last night. When I get out of bed because a question is nagging me and I just have to test it, I am more likely to make mistakes like that.

@catch: Thanks for creating the follow-up issue.

I am crediting @jhodgdon for reviewing the patch in #4.

Status: Fixed » Closed (fixed)

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

xjm’s picture