Bug #96128
closedCleanerTaskTest->taskRemovesOnlyPagesLongerDeletedThanPeriod() fails in Core CI tests
100%
Description
CleanerTaskTest->taskRemovesOnlyPagesLongerDeletedThanPeriod() fails in Core CI tests, but not constantly.
It was unpossible to reproduce it locally at first, and a retry of failed Core CI tests went happy, even
if had to be rerun a several of times. At first it seemed that it was related with PHP8.1 and POSTGRES,
but further tests shows that involved dbms was irrelevant. As 'nighlty' core ci runs are only run scheduled
later then 01:00 it was not detected by them. Only commit core ci runs in that timeframe since 8.1.0RC6 hitted
this issue - and maybe was went under as a retry later on went green.
After investigation this issue deeper, it could be narrowed down to be an issue only between UTC 00:00 and 01:00,
which maded it inpossible at first to reproduce it the next day and why after some time test went magical green.
Even as it was first related to postgres, it could be proved that it was only related to PHP8.1.0RC6 and the
given timeframe.
Confirmed for: PHP8.1.0RC6 only, and only between 00:00 and 01:00 UTC for all dbms
Here are the result of the test runs/analysis. If you want to reproduce it yourself set your PC time
correspodingly. (Not only switch timezone, the UTC time in the and have to been changed).
POSTGRES ======== +------------+------------+-----+-----+------------+-------------+--------+ | DT-DATASET | DT-NOW | PER | P+1 | PERIOD-TS | PHP-VERSION | RESULT | +------------+------------+-----+-----+------------+-------------+--------+ | // before timeframe - CET 00:00-01:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638055076 | 425 | 426 | 1601248592 | 7.4 | ok | | 1601251200 | 1638055076 | 425 | 426 | 1601248676 | 8.0 | ok | | 1601251200 | 1638055119 | 425 | 426 | 1601248719 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ | // in 1h timeframe - CET 01:00-02:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638058750 | 426 | 427 | 1601165876 | 7.4 | ok | | 1601251200 | 1638058750 | 426 | 427 | 1601165950 | 8.0 | ok | | 1601251200 | 1638058779 | 425 | 426 | 1601252379 | 8.1 | failed | +------------+------------+-----+-----+------------+-------------+--------+ | // after timeframe - CET 02:00-03:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638065847 | 426 | 427 | 1601172956 | 7.4 | ok | | 1601251200 | 1638065847 | 426 | 427 | 1601173047 | 8.0 | ok | | 1601251200 | 1638065812 | 426 | 427 | 1601173012 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ MYSQL ===== +------------+------------+-----+-----+------------+-------------+--------+ | DT-DATASET | DT-NOW | PER | P+1 | PERIOD-TS | PHP-VERSION | RESULT | +------------+------------+-----+-----+------------+-------------+--------+ | // before timeframe - CET 00:00-01:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1637971200 | 425 | 426 | 1601249747 | 7.4 | ok | | 1601251200 | 1637971200 | 425 | 426 | 1601249790 | 8.0 | ok | | 1601251200 | 1637971200 | 425 | 426 | 1601249819 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ | // in 1h timeframe - CET 01:00-02:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638057600 | 426 | 427 | 1601166801 | 7.4 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601166762 | 8.0 | ok | | 1601251200 | 1638057600 | 425 | 426 | 1601253098 | 8.1 | failed | +------------+------------+-----+-----+------------+-------------+--------+ | // after timeframe - CET 02:00-03:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638057600 | 426 | 427 | 1601174245 | 7.4 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601174286 | 8.0 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601174472 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ MARIADB ======= +------------+------------+-----+-----+------------+-------------+--------+ | DT-DATASET | DT-NOW | PER | P+1 | PERIOD-TS | PHP-VERSION | RESULT | +------------+------------+-----+-----+------------+-------------+--------+ | // before timeframe - CET 00:00-01:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1637971200 | 425 | 426 | 1601248279 | 7.4 | ok | | 1601251200 | 1637971200 | 425 | 426 | 1601248402 | 8.0 | ok | | 1601251200 | 1637971200 | 425 | 426 | 1601248559 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ | // in 1h timeframe - CET 01:00-02:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638057600 | 426 | 427 | 1601165810 | 7.4 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601165848 | 8.0 | ok | | 1601251200 | 1638057600 | 425 | 426 | 1601252282 | 8.1 | failed | +------------+------------+-----+-----+------------+-------------+--------+ | // after timeframe - CET 02:00-03:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638057600 | 426 | 427 | 1601169589 | 7.4 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601169623 | 8.0 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601169677 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ SQLITE ====== +------------+------------+-----+-----+------------+-------------+--------+ | DT-DATASET | DT-NOW | PER | P+1 | PERIOD-TS | PHP-VERSION | RESULT | +------------+------------+-----+-----+------------+-------------+--------+ | // before timeframe - CET 00:00-01:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1637971200 | 425 | 426 | 1601248941 | 7.4 | ok | | 1601251200 | 1637971200 | 425 | 426 | 1601248976 | 8.0 | ok | | 1601251200 | 1637971200 | 425 | 426 | 1601249000 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+ | // in 1h timeframe - CET 01:00-02:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638057600 | 426 | 427 | 1601166238 | 7.4 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601166301 | 8.0 | ok | | 1601251200 | 1638057600 | 425 | 426 | 1601252734 | 8.1 | failed | +------------+------------+-----+-----+------------+-------------+--------+ | // after timeframe - CET 02:00-03:00 | +------------+------------+-----+-----+------------+-------------+--------+ | 1601251200 | 1638057600 | 426 | 427 | 1601170009 | 7.4 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601170067 | 8.0 | ok | | 1601251200 | 1638057600 | 426 | 427 | 1601170095 | 8.1 | ok | +------------+------------+-----+-----+------------+-------------+--------+
Further testing showed, that it fails only with PHP8.1.0RC6, which currently used for Core CI testing.
Prior version are working, and even PHP8.1.0 released version. As official php docker images are not
providing PHP8.1.0 release images, we are not able to update the images right now.
For evaulating with different PHP versions and to avoid switching PC local time, you can use following
PHP script. Just save it as cleaner-task-validate.php in a folder. Either use your local PHP8.1.0
versions (at best the 8.1.0 RELEASED version for the last one), you can use different alpine php 8.1
images for verifying it:
<?php
// script-name: cleaner-task-validate.php
// 1. docker run --rm -it -v "$PWD":/myapp -w /myapp php:8.1.0RC3-alpine php cleaner-task-validate.php
// 2. docker run --rm -it -v "$PWD":/myapp -w /myapp php:8.1.0RC6-alpine php cleaner-task-validate.php
// 3. local / ondrej php 8.1.0 release: php8.1 cleaner-task-validate.php
// 1. 8.1.0 RC3
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
// !!! ALL-VALUES SHOULD BE THE SAME !!!
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
//
// 2020-09-28 00:00:00 -> 2021-11-28 00:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 01:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 02:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 03:10:00 : DAYS: 426
// 2. 8.1.0 RC6
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
// !!! ALL-VALUES SHOULD BE THE SAME !!!
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
// 2020-09-28 00:00:00 -> 2021-11-28 00:10:00 : DAYS: 425
// 2020-09-28 00:00:00 -> 2021-11-28 01:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 02:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 03:10:00 : DAYS: 426
// 3. 8.1.0 (RELEASE - LOKAL)
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
// !!! ALL-VALUES SHOULD BE THE SAME !!!
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
// 2020-09-28 00:00:00 -> 2021-11-28 00:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 01:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 02:10:00 : DAYS: 426
// 2020-09-28 00:00:00 -> 2021-11-28 03:10:00 : DAYS: 426
date_default_timezone_set('UTC');
$a = date_create_immutable_from_format('Y-m-d', '2020-09-28')->setTime(0,0,0);
$b = (new DateTime('now'))->setTime(0,10,0);
$c = (new DateTime('now'))->setTime(1,10,0);
$d = (new DateTime('now'))->setTime(2,10,0);
$e = (new DateTime('now'))->setTime(3,10,0);
echo PHP_EOL;
echo "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!" . PHP_EOL;
echo "!!! ALL-VALUES SHOULD BE THE SAME !!!" . PHP_EOL;
echo "!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!" . PHP_EOL;
echo PHP_EOL;
echo $a->format('Y-m-d H:i:s') . ' -> ' . $b->format('Y-m-d H:i:s') . ' : DAYS: ' . (int)$a->diff($b)->format('%a') . PHP_EOL;
echo $a->format('Y-m-d H:i:s') . ' -> ' . $c->format('Y-m-d H:i:s') . ' : DAYS: ' . (int)$a->diff($c)->format('%a') . PHP_EOL;
echo $a->format('Y-m-d H:i:s') . ' -> ' . $d->format('Y-m-d H:i:s') . ' : DAYS: ' . (int)$a->diff($d)->format('%a') . PHP_EOL;
echo $a->format('Y-m-d H:i:s') . ' -> ' . $e->format('Y-m-d H:i:s') . ' : DAYS: ' . (int)$a->diff($e)->format('%a') . PHP_EOL;