Re: rhel8 test failure confirmation?

Bogdan <[email protected]>, Sun Mar 05 2023 22:31:55 GMT+0100 (Central 
European Standard Time)
> Karl Berry <[email protected]>, Sat Mar 04 2023 00:00:56 GMT+0100 
> (Central European Standard Time)
>>      Note that 'config.h' is older (4 seconds) than './configure', 
>> which
>>      shouldn't be the case as it should get updated with new values.
>>
>> Indeed. That is the same sort of thing as I was observing with nodef.
>> But what (at any level) could be causing that to happen?
>> Files just aren't getting updated as they should be.
>>
>> I haven't yet tried older releases of automake to see if their tests
>> succeed on the systems that are failing now. That's next on my list.
> 
> [...]
> 
> 
>   Another tip, maybe: cache again. When I compare which files are 
> newer than the only trace file I get in the failing 'backcompat2' test 
> ('autom4te.cache/traces.0'), I see that 'configure.ac' is older than 
> this file in the succeeding run, but it's newer in the failing run. 
> This could explain why 'configure' doesn't get updated to put new 
> values in config.h (in my case) - 'autom4te' thinks it's up-to-date.
>   The root cause may be in 'autom4te', sub 'up_to_date':
> 
>    # The youngest of the cache files must be older than the oldest of
>    # the dependencies.
>    # FIXME: These timestamps have only 1-second resolution.
>    # Time::HiRes fixes this, but assumes Perl 5.8 or later.
> 
> (lines 913-916 in my version).
> 
>   Perhaps 'configure.ac' in the case that fails is created "not late 
> enough" (still within 1 second) when compared to the cache, and the 
> cached values are taken, generating the old version of 'configure' 
> which, in turn, generates old versions of the output files.
> 
>   Still a guess, but maybe a bit more probable now.
> 
>   Does it work when you add '-f' to '$AUTOCONF'? It does for me - 
> again, about 20 sequential runs of the same set of tests and about 5 
> parallel with 4 threads. Zero failures.
>   I'd probably get the same result if I did a 'rm -fr autom4te.cache' 
> before each '$AUTOCONF' invocation.
> 
>   If it does work for you, then maybe it would be better to add '-f' 
> to the 'AUTOCONF' variable where it's defined? Tests with a single 
> '$AUTOCONF' invocation won't notice (they will create their cache 
> anyway), while tests with multiple calls can maybe get fixed all at once.


[...]

   More input (or noise):

1) The t/backcompat2.sh test (the only test which fails for me) is a 
test which modifies configure.ac and calls $AUTOCONF several times.

2) Autom4te (part of Autoconf) has a 1-second resolution in checking 
if the input files are newer than the cache.

3) Thus, a sequence: 'autoconf' + quickly modify configure.ac + 
quickly run 'autoconf' may cause autom4te to use the old values from 
the cache instead of processing the new configure.ac. "Quickly" means 
within the same second.

4) I ran the provided list of tests (t/backcompat2.sh, 
t/backcompat3.sh, t/get-sysconf.sh, t/lex-depend.sh, t/nodef.sh, 
t/remake-aclocal-version-mismatch.sh, t/subdir-add2-pr46.sh, 
t/testsuite-summary-reference-log.sh) in batches of 20 or more runs.

5) With the tools as they are on my system, I got a failure in the 
t/backcompat2.sh test in the first batch (18th round, IIRC).

6) I modified my autom4te using the attached patch, which essentially 
makes the mentioned sub 'up_to_date' work as if the cache is out of 
date if its modtime (up to 1-second precision) is not only earlier, 
but also equal to the modtime of any dependencies (including 
configure.ac).

7) After modifying autom4te, I ran 120 rounds of the same set of tests 
in single-threaded mode, and additional 120 rounds in parallel mode 
(-j4). Total of 240 runs of all those 8 mentioned tests each. ZERO 
FAILURES.

8) I brought autom4te to its original state and started running the 
tests again. I got the first failure quite early (32nd run, IIRC).

   I believe that shortening the sleep in Automake in the suspected 
commit (720a1153134b833de9298927a432b4ea266216fb "m4: speed up 
filesystem modification checks") is not an error in Automake. It 
simply causes this issue in autom4te (not enough precision) to show up.

   I'm not 100% sure about my results and conclusions, because 
t/backcompat2.sh doesn't seem to be that quick in modifying 
configure.ac to cause a false cache hit in autom4te. But these results 
seem to confirm my previous results where using -f to bypass the cache 
helped.

   Another thing is that we have a bit of a special case here - quick 
modifications and reconfigurations. So, even though autom4te has a 
"FIXME" there, probably over 99% of users are not impacted. People 
usually modify configure.ac manually, then run autoconf manually 
(after 1 second) and then just ./configure.

   What can we do about this?

- have autom4te patched and wait for the fix to reach a release (and 
get installed on every possible end-user system?), and revert the 
sleep until this is done,

- revert the commit and increase the test time again,

- fix the randomly-failing tests by adding '-f' to second and next 
invocations of $AUTOCONF and leave the shorter sleep,

- fix all tests by adding '-f' to the declaration of $AUTOCONF and 
leave the shorter sleep. As I wrote - tests which run autoconf just 
once shouldn't notice and those running it multiple times should work 
in all cases. This may make some tests take longer, though, but maybe 
the shorter sleep will compensate for this,

- fix the randomly-failing tests (or maybe all tests running autoconf 
more than once, but there may be many) by adding 'rm -fr 
autom4te.cache' before the second and next invocations of $AUTOCONF 
and leave the shorter sleep,

- fix the randomly-failing tests by adding 'sleep 1' before the second 
and next invocations of $AUTOCONF and leave the shorter sleep.

   As a side note, I don't see an error in the new Automake code even 
though it doesn't seem to be fully deterministic. On my system, it 
shows the filesystem timestamp resolution being 0.1 one time and 0.2 
another time... Maybe some random boundary or a temporary slowdown (in 
general, 'stat' shows nanosecond precision).

P.S. The t/backcompat2.sh itself may show a method to make some other 
tests faster:

# A trick to make the test run muuuch faster, by avoiding repeated
# runs of aclocal (one order of magnitude improvement in speed!).
echo 'AC_INIT(x,0) AM_INIT_AUTOMAKE' > configure.ac


-- 
Regards - Bogdan ('bogdro') D.                 (GNU/Linux & FreeDOS)
X86 assembly (DOS, GNU/Linux):    http://bogdro.evai.pl/index-en.php
Soft(EN): http://bogdro.evai.pl/soft  http://bogdro.evai.pl/soft4asm
www.Xiph.org  www.TorProject.org  www.LibreOffice.org  www.GnuPG.org

--- /usr/bin/autom4te-orig	2023-03-27 13:41:04.456209706 +0200
+++ /usr/bin/autom4te	2023-03-29 18:07:26.635030065 +0200
@@ -926,7 +926,7 @@
   # We depend at least upon the arguments.
   foreach my $dep (@ARGV)
     {
-      if ($mtime < mtime ($dep))
+      if ($mtime <= mtime ($dep))
 	{
 	  verb "up_to_date ($file): outdated: $dep";
 	  return 0;
@@ -949,7 +949,7 @@
       # timestamp of that missing file was newer).
       return 0
 	if ! $dep;
-      if ($mtime < mtime ($dep))
+      if ($mtime <= mtime ($dep))
 	{
 	  verb "up_to_date ($file): outdated: $dep";
 	  return 0;