python / cpython

The Python programming language
https://www.python.org
Other
63.55k stars 30.45k forks source link

`test_strftime_y2k` fails on embedded Linux #123681

Open picnixz opened 2 months ago

picnixz commented 2 months ago

Bug report

Bug description:

This is an issue to track the progress of fixing the JIT. Branches that trigger the embedded Linux tests fail on test_strftime_y2k, e.g. https://github.com/python/cpython/actions/runs/10655985897/job/29534232332?pr=123546. As a side-effect this causes users getting notification that their JIT workflow failed.

Both the C and F specifiers are failing for this specific test:

``` test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) ... test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=1, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=1, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=48, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=48, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=70, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=70, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=999, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDate_Fast.test_strftime_y2k) (year=999, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) ... test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=1, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=1, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=48, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=48, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=70, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=70, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=999, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTime_Fast.test_strftime_y2k) (year=999, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) ... test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=1, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=1, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=48, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=48, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=70, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=70, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=999, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestDateTimeTZ_Fast.test_strftime_y2k) (year=999, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) ... test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=1, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=1, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=48, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=48, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=70, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=70, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=99, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=99, specifier='C') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=999, specifier='F') ... FAIL test_strftime_y2k (test.datetimetester.TestSubclassDateTime_Fast.test_strftime_y2k) (year=999, specifier='C') ... FAIL ```

A solution is to add this test to the ignored tests or to fix the detection algorithm.

cc @blhsing @serhiy-storchaka

CPython versions tested on:

CPython main branch

Operating systems tested on:

Other

Linked PRs

serhiy-storchaka commented 2 months ago

It seems that only tests for the C implementation fail.

We can try to move the detection from the compile time to the run time, like for Python implementation. But it is a puzzle why it does not work here.

picnixz commented 2 months ago

(Forget my comment that I deleted, I looked at the wrong commit).

I think we can improve the configure.ac detection by including the weird cases. Or maybe the test is broken because of this:

if _time.strftime('%F', (1900, 1, 1, 0, 0, 0, 0, 1, 0)) == '1900-01-01':
    specifiers += 'FC'

(Those are the two failing specifiers)

brandtbucher commented 2 months ago

This particular test failure could be a bit weird, since this CI job involves cross-compiling Python and then running the test suite under emulation. Not sure if it's a "real" issue, or if we should just skip the test (like we do for others).

picnixz commented 2 months ago

since this CI job involves cross-compiling Python and then running the test suite under emulation

Does it mean that the configure tests might not be correct (or inconsistent because they were done using cross-compilation?) If so, we can just outright ignore the test I guess?

serhiy-storchaka commented 2 months ago

If these configure tests are not correct, then other configure tests can be not correct too.

picnixz commented 2 months ago

Ha! I knew I should have looked more in detail the logs:

On aarch64-unknown-linux-gnu (failing tests), we have two different configure:

https://github.com/python/cpython/commit/e565b87d9dafe89bf262e3ab46edb9c9c8618b27/checks/29534232332/logs

2024-09-01T17:33:50.4537429Z checking whether year with century should be normalized for strftime... yes 2024-09-01T17:33:50.4888417Z checking whether C99-specific strftime specifiers are supported... yes

2024-09-01T17:35:47.4696152Z checking whether year with century should be normalized for strftime... yes 2024-09-01T17:35:47.4698164Z checking whether C99-specific strftime specifiers are supported... >> no <<

So it appears we have different ./configure. I don't know which one is actually being used at runtime in the emulated environment. Now, both '%F' and '%C' are C99-specific (https://en.cppreference.com/w/c/chrono/strftime) so the following

if _time.strftime('%F', (1900, 1, 1, 0, 0, 0, 0, 1, 0)) == '1900-01-01':
    specifiers += 'FC'

is perhaps a too broad check. Since specifiers 'F' and 'C' are used, we actually expect to support %F, but this contradicts the fact that "C99-specific strftime specifiers are supported" (at least for the second one which seems the most recent and probably the one being used under the hood). The configure check is:

if (strftime(full_date, sizeof(full_date), "%F", &date) && !strcmp(full_date, "1900-01-01")) {
    return 0;
}

In other words, either strftime(full_date, sizeof(full_date), "%F", &date) fails or full_date != 1900-01-01. So maybe %F does not fail. We can probably debug the tests to check whether it _time.strftime that bugs, or if it is the configure test that bugs. I don't know if it's possible for _time.strftime to support %F (which does not directly call strftime()) but at the same time fail the strftime(full_date, sizeof(full_date), "%F", &date) && !strcmp(full_date, "1900-01-01") test.


I'm tired so what I wrote here might be wrong but I'll try to investigate tomorrow.

blhsing commented 2 months ago

2024-09-08T16:49:27.5943515Z checking whether year with century should be normalized for strftime... yes 2024-09-08T16:49:27.6286869Z checking whether C99-specific strftime specifiers are supported... yes

2024-09-08T16:51:33.7240722Z checking whether year with century should be normalized for strftime... yes 2024-09-08T16:51:33.7242911Z checking whether C99-specific strftime specifiers are supported... >> no <<

Ahh how could I have not noticed the second configure in the logs! Was scratching my head over why the detection of C99 support got a yes (in the first configure) but the compiled code ended up not handling C99. It makes total sense now.

The real problem is simply that autoconf does not run the test for the AC_RUN_IFELSE macro at all when cross-compiling, but directly performs action-if-cross-compiling as specified, which I thought should be made a no (to be pessimistic) when it should really be a yes because we should make sure to handle %F and %C ourselves when we are unsure if the target platform can handle them.

picnixz commented 2 months ago

Ahh how could I have not noticed the second configure in the logs!

Well, isn't it trivial to spot it among 11985 lines 😄? Actually, I found the duplicate configure in the logs by a CTRL+F and... saw that I had two results.

blhsing commented 2 months ago

Ahh how could I have not noticed the second configure in the logs!

Well, isn't it trivial to spot it among 11985 lines 😄? Actually, I found the duplicate configure in the logs by a CTRL+F and... saw that I had two results.

I used Ctrl-F too, but the browser limits the search to only what's loaded in the memory, when the output of the second configure is hidden because it is loaded on demand by an AJAX call only if I scroll to it. I should've used the "Search Logs" text box in the page to perform the search for the keyword on the server side instead.

Thanks again!

picnixz commented 2 months ago

I used Ctrl-F too, but the browser limits the search to only what's loaded in the memory, when the output of the second configure is hidden because it is loaded on demand by an AJAX call only if I scroll to it. I should've used the "Search Logs" text box in the page to perform the search for the keyword on the server side instead.

Actually, the trick is to "view raw logs". You'll get the entire logs without buffering (easier to read IMO).

picnixz commented 1 month ago

FTR: https://github.com/python/cpython/pull/124466 was merged as a temporary workaround so we need to keep the issue opened even though the job looks successful (it's just that we skip it).