GNU bug report logs - #68808
subsecond mtime discovery code insufficient

Previous Next

To reply to this bug, email your comments to 68808 AT debbugs.gnu.org.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: bug-automake <at> gnu.org, JohnsonE <at> usc.edu
Subject: subsecond mtime discovery code insufficient
Date: Mon, 29 Jan 2024 16:00:36 -0700

Hi Erik - following up on your final comment in #68119:

    P.P.S. It still needs
            export am_cv_sleep_fractional_seconds=false
    to correctly run the tests on macOS.  Without that, 75-90 tests fail.

Maybe we can try to figure out why the code that tries to automatically
discern whether subsecond mtimes are supported is insufficient? It seems
there is something different about the mac filesystem (or something). So
I suspect there will be problems on other systems, too.

If there are any test(s) which more or less consistently fail without
the override the sleep_fractional_seconds, maybe we can discern why
those tests are failing. I am dearly hoping not to have inspect every
single test and scatter $sleep commands everywhere.

Meanwhile, the code that tries to figure out if subsecond mtimes are
supported is in m4/sanity.m4, function
_AM_FILESYSTEM_TIMESTAMP_RESOLUTION.  It essentially writes to three
files and sleeps for the trial resolution between them, starting at a
hundredth of a second. Then, if ls -t sorts in the right order, it
assumes that resolution is ok.

For one thing, just to get a grip on reality, maybe you could try
running those commands by hand and see what the result is.  I'm guessing
the Mac (and its sleep command?) do support subsecond mtimes in reality.

  am_try_res=.001
  echo alpha > conftest.ts1
  sleep $am_try_res
  echo beta > conftest.ts2
  sleep $am_try_res
  echo gamma > conftest.ts3
  ls -t conftest.ts?

The result should be conftest.ts3 first, then ts2, then ts1.

But, looking at that code, I belatedly see that shell arrays are being
used. At least I think so. It wouldn't surprise me if the mac /bin/sh
doesn't support arrays. But that should result in assuming subsecond
mtimes are not supported when they are, instead of the reverse. Anyway,
I don't think we can assume arrays, so I'll have to think about that.

But the important thing is why so many tests fail on your system when
subsecond mtimes are enabled (and succeed when not). --thanks, karl.

Message #8 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: "Zack Weinberg" <zack <at> owlfolio.org>
To: "Karl Berry" <karl <at> freefriends.org>, 68808 <at> debbugs.gnu.org,
 JohnsonE <at> usc.edu
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Mon, 29 Jan 2024 19:24:11 -0500

On Mon, Jan 29, 2024, at 6:00 PM, Karl Berry wrote:
> But, looking at that code, I belatedly see that shell arrays are being
> used. At least I think so.

It is absolutely not *supposed* to be using shell arrays. If it is, that was a mistake on my part.

zw

Message #11 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Erik A Johnson <JohnsonE <at> usc.edu>
To: Karl Berry <karl <at> freefriends.org>
Cc: "68808 <at> debbugs.gnu.org" <68808 <at> debbugs.gnu.org>
Subject: Re: subsecond mtime discovery code insufficient
Date: Tue, 30 Jan 2024 12:08:16 +0000

	I'm guessing the Mac (and its sleep command?) do support subsecond mtimes in reality.

echo a > 1 && echo b > 2 && echo c > 3 && ls -t [123]
consistently gives me the correct order (3 2 1).
The macOS version of stat has a mtime_nsec field that is fully populated and the file modification times differ by about a half of a millisecond.

	But, looking at that code, I belatedly see that shell arrays are being
	used. At least I think so. It wouldn't surprise me if the mac /bin/sh
	doesn't support arrays. But that should result in assuming subsecond
	mtimes are not supported when they are, instead of the reverse. Anyway,
	I don't think we can assume arrays, so I'll have to think about that.

On macOS, /bin/sh is actually /bin/bash executing in POSIX mode.  I _think_ it has arrays but I could check if you have some code you want me to run.

Message #14 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Erik A Johnson <JohnsonE <at> usc.edu>
To: Karl Berry <karl <at> freefriends.org>
Cc: "68808 <at> debbugs.gnu.org" <68808 <at> debbugs.gnu.org>
Subject: Re: subsecond mtime discovery code insufficient
Date: Tue, 30 Jan 2024 12:46:22 +0000

I found the problem!  The default GNU make on macOS (even Sonoma) is 3.81 from 2006!  The configure script for GNU make versions <4.0 did not have the right test for subsecond resolution in the macOS stat() function, so 3.81 was built with resolution only to the second, not subsecond, thus needing at least one second sleep.  (Why, then, does Apple continue to include 3.81 in the software 18 years later? Beyond me.)

Installing the most recent release of GNU make (4.4.1) fixes the problem.  Tests all run successfully.

Erik


----------------------------------------

Details ... With make 3.81, if I create a simple Makefile with

	foo: bar
		touch foo

then

	touch foo
	touch bar
	make

should make (touch) foo because bar is newer.  However, if these are done immediately after each other

	touch foo; touch bar; make

then, most of the time, make just responds with "make: `foo' is up to date."  The following

	n=0; while make | grep -q 'up to date'; do touch foo; touch bar; printf .; n=$(($n+1)); done; echo $n

varies from a handful of trials to several thousand trials before foo's mtime's integer is one less than bar's mtime's integer.

Message #17 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: "Zack Weinberg" <zack <at> owlfolio.org>
To: "Erik A Johnson" <JohnsonE <at> usc.edu>, "Karl Berry" <karl <at> freefriends.org>
Cc: "68808 <at> debbugs.gnu.org" <68808 <at> debbugs.gnu.org>
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Tue, 30 Jan 2024 09:06:12 -0500

On Tue, Jan 30, 2024, at 7:46 AM, Erik A Johnson wrote:
> I found the problem!  The default GNU make on macOS (even Sonoma) is
> 3.81 from 2006!  The configure script for GNU make versions <4.0 did
> not have the right test for subsecond resolution in the macOS stat()
> function, so 3.81 was built with resolution only to the second, not
> subsecond, thus needing at least one second sleep.

Okay, so that means the filesystem timestamp resolution test needs to
probe the behavior of `make` as well as all the other things it tests. I
will work on a patch for that as soon as I have a usable workstation
again, which will probably not be until next week at the earliest; if
anyone wants to beat me to it, feel free.

> (Why, then, does Apple continue to include 3.81 in the software 18
> years later? Beyond me.)

3.81 was the last version distributed under GPLv2; Apple won't touch
anything that's distributed under GPLv3.  Their copy of GNU M4 is also
vintage 2006, for the same reason.  I don't claim to understand why
their legal department thinks GPLv2 is fine but v3 has to be avoided,
but (like many other proprietary Unix vendors) they probably keep
shipping the old GNU tools instead of, like, switching to current BSD
tools, for the sake of compatibility with old scripts.

zw

Message #20 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Peter Johansson <trojkan <at> gmail.com>
To: Erik A Johnson <JohnsonE <at> usc.edu>, Karl Berry <karl <at> freefriends.org>
Cc: "68808 <at> debbugs.gnu.org" <68808 <at> debbugs.gnu.org>
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Wed, 31 Jan 2024 00:56:38 +1000

[Message part 1 (text/plain, inline)]

On 30/1/24 22:46, Erik A Johnson wrote:
> (Why, then, does Apple continue to include 3.81 in the software 18 years later? Beyond me.)

Probably because 3.81 was the last version released under GPLv2 or later 
and IIRC Apple avoids shipping things that are licensed with GPLv3.

Cheers,

Peter

[Message part 2 (text/html, inline)]

Message #23 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: zack <at> owlfolio.org
Cc: 68808 <at> debbugs.gnu.org
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Tue, 30 Jan 2024 16:32:04 -0700

(Off-topic for the original bug, but for the sake of public discussion ...)

Hi Zack,

    It is absolutely not *supposed* to be using shell arrays. 

I guess it's not an array. It's the square bracket syntax that confuses
me. A couple of examples from the fn in sanity.m4:

test "$[*]" != "X conftest.ts1 conftest.ts2" ||
..
test "$[]2" = conftest.ts3 &&
..
etc.

I've never seen anything like that before. Searching online, supposedly
$[...] means arithmetic expansion, but clearly that's not what is going
on here. I don't know what it means. Seems like just "$2" (for example)
is intended? I feel like I'm missing/forgetting something basic.

Sorry I didn't read the code when you submitted it originally :(.

Thanks,
Karl

Message #26 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: "Zack Weinberg" <zack <at> owlfolio.org>
To: "Karl Berry" <karl <at> freefriends.org>
Cc: 68808 <at> debbugs.gnu.org
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Tue, 30 Jan 2024 18:34:16 -0500

On Tue, Jan 30, 2024, at 6:32 PM, Karl Berry wrote:
> test "$[*]" != "X conftest.ts1 conftest.ts2" ||
> ..
> test "$[]2" = conftest.ts3 &&
> ..
> etc.
>
> I've never seen anything like that before. 

Oh! Those square brackets are M4 quotes to prevent M4 from expanding $* and $2 itself.

zw

Message #29 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: zack <at> owlfolio.org
Cc: 68808 <at> debbugs.gnu.org
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Wed, 31 Jan 2024 15:10:33 -0700

    Those square brackets are M4 quotes to prevent M4 from expanding
    $* and $2 itself.

Ah, right. Of course. Good!

The $[*] especially confused me. Just looks so perfectly like an array
reference of some strange kind :). I think it would be a tiny bit
clearer to use $[]*? Or am I missing something again?

More importantly, as far as the make probing goes, I have some other
projects to attend to first. So most likely if you can get to it next
week (fingers crossed for your new machine), that will be sooner than
me. Thanks. -k

Message #32 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: 68808 <at> debbugs.gnu.org, JohnsonE <at> usc.edu
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Mon, 27 May 2024 13:34:54 -0600

Hi Erik and all - I (finally) made the change below to have automake
test for a make that doesn't support subsecond mtimes even when the rest
of the system is ok, as you noted happens with the make-3.81 shipped by
macOS.

I installed make-3.8.1 on my Rocky 9 system, but it did not cause the
lossage. So I'm not sure if there's an error in my test (wouldn't
surprise me) or if it's something about the mac system specifically.

As far as I could tell, the new code does succeed on Rocky 9. So I hope
it also succeeds on other current systems where the whole
subsecond-mtime thing is intended.

Erik, can you either apply this patch (and remake and run the tests), or
get the current automake dev sources and try it?

If anyone (Zack, Bogdan, Jim, ...) else could look at, and/or try, the
new code and see if any problems show up, that would be great.

I hope this works and we can start pushing towards the release. --thanks, karl.

--- a/m4/sanity.m4
+++ b/m4/sanity.m4
@@ -24,7 +24,7 @@ AS_IF([sleep 0.001 2>/dev/null], [am_cv_sleep_fractional_seconds=true],
 # nanosecond, matching clock_gettime.  However, it is probably not
 # possible to delay execution of a shell script for less than one
 # millisecond, due to process creation overhead and scheduling
-# granularity, so we don't check for anything finer than that.
+# granularity, so we don't check for anything finer than that. (See below.)
 AC_DEFUN([_AM_FILESYSTEM_TIMESTAMP_RESOLUTION], [dnl
 AC_REQUIRE([_AM_SLEEP_FRACTIONAL_SECONDS])
 AC_CACHE_CHECK([filesystem timestamp resolution], am_cv_filesystem_timestamp_resolution, [dnl
@@ -34,6 +34,9 @@ am_cv_filesystem_timestamp_resolution=2
 # Only try to go finer than 1s if sleep can do it.
 am_try_resolutions=1
 if $am_cv_sleep_fractional_seconds; then
+  # Even a millisecond often causes a bunch of false positives,
+  # so just try a hundredth of a second. The time saved between .001 and
+  # .01 is not terribly consequential.
   am_try_resolutions="0.01 0.1 $am_try_resolutions"
 fi
 
@@ -48,12 +51,13 @@ rm -f conftest.ts?
 : > conftest.ts3
 
 # Make sure ls -t actually works.  Do 'set' in a subshell so we don't
-# clobber the current shell's arguments.
+# clobber the current shell's arguments. (Outer-level square brackets
+# are for m4; be careful, it's easy to get confused.)
 if (
      set X `[ls -t conftest.ts[12]]` &&
      {
-       test "$[*]" != "X conftest.ts1 conftest.ts2" ||
-       test "$[*]" != "X conftest.ts2 conftest.ts1";
+       test "$[]*" != "X conftest.ts1 conftest.ts2" ||
+       test "$[]*" != "X conftest.ts2 conftest.ts1";
      }
 ); then :; else
   # If neither matched, then we have a broken ls.  This can happen
@@ -64,7 +68,7 @@ if (
     ["Bad output from ls -t: \"`[ls -t conftest.ts[12]]`\""],
     [AS_MESSAGE_LOG_FD])
   AC_MSG_FAILURE([ls -t produces unexpected output.
-Make sure there is not a broken alias in your environment.])
+Make sure there is not a broken ls alias in your environment.])
 fi
 
 for am_try_res in $am_try_resolutions; do
@@ -84,11 +88,47 @@ for am_try_res in $am_try_resolutions; do
       test "$[]2" = conftest.ts3 &&
       test "$[]3" = conftest.ts2 &&
       test "$[]4" = conftest.ts1); then
-    am_cv_filesystem_timestamp_resolution=$am_try_res
-    break
+    #
+    # Ok, ls -t worked. We have one more thing to check: make.
+    # It can happen that everything else supports the subsecond mtimes,
+    # but make doesn't, notably on macOS, which ships make 3.81 from
+    # 2006 (the last one released under GPLv2). https://bugs.gnu.org/68808
+    # 
+    # So, first let's create a Makefile:
+    rm -f conftest.mk
+    echo 'conftest.ts1: conftest.ts2' >conftest.mk
+    echo '	touch conftest.ts2' >>conftest.mk
+    #
+    # Now, running
+    #   touch conftest.ts1; touch conftest.ts2; make
+    # should touch ts1 because ts2 is newer. This could happen by luck,
+    # but most often, it will fail if make's support is insufficient. So
+    # test for several consecutive successes.
+    # 
+    # (We reuse conftest.ts[12] because we still want to modify existing
+    # files, not create new ones, per above.)
+    n=0
+    make_ok=true
+    until test $n -eq 4; do
+      echo one > conftest.ts1
+      sleep $am_try_res
+      echo two > conftest.ts2 # ts2 should now be newer than ts1
+      if make -f conftest.mk | grep 'up to date' >/dev/null; then
+        make_ok=false
+        break # out of $n loop
+      fi
+      n=`expr $n + 1`
+    done
+    if $make_ok; then
+      # Everything we know to check worked out, so call this resolution good.
+      am_cv_filesystem_timestamp_resolution=$am_try_res
+      break # out of resolution loop
+    fi
+    # Otherwise, we'll go on to check the next resolution.
   fi
 done
 rm -f conftest.ts?
+# (end _am_filesystem_timestamp_resolution)
 ])])
 
 # AM_SANITY_CHECK

compile finished at Mon May 27 10:01:57 2024

Message #35 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Erik A Johnson <JohnsonE <at> usc.edu>
To: Karl Berry <karl <at> freefriends.org>
Cc: "68808 <at> debbugs.gnu.org" <68808 <at> debbugs.gnu.org>
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Mon, 27 May 2024 20:59:37 +0000

[Message part 1 (text/plain, inline)]

Thanks, Karl.  I wasn't sure what version was to be patched but it looks like the current git repository has those changes, so I tested that with the macOS make:
* fine on the tests that failed previously because of macOS default make having only second resolution
* color-tests2.sh and color-tests2-w.sh fail -- logs attached.

Erik



On May 27, 2024, at 12:34 PM, Karl Berry <karl <at> freefriends.org> wrote:

Hi Erik and all - I (finally) made the change below to have automake
test for a make that doesn't support subsecond mtimes even when the rest
of the system is ok, as you noted happens with the make-3.81 shipped by
macOS.

I installed make-3.8.1 on my Rocky 9 system, but it did not cause the
lossage. So I'm not sure if there's an error in my test (wouldn't
surprise me) or if it's something about the mac system specifically.

As far as I could tell, the new code does succeed on Rocky 9. So I hope
it also succeeds on other current systems where the whole
subsecond-mtime thing is intended.

Erik, can you either apply this patch (and remake and run the tests), or
get the current automake dev sources and try it?

If anyone (Zack, Bogdan, Jim, ...) else could look at, and/or try, the
new code and see if any problems show up, that would be great.

I hope this works and we can start pushing towards the release. --thanks, karl.

--- a/m4/sanity.m4
+++ b/m4/sanity.m4
@@ -24,7 +24,7 @@ AS_IF([sleep 0.001 2>/dev/null], [am_cv_sleep_fractional_seconds=true],
# nanosecond, matching clock_gettime.  However, it is probably not
# possible to delay execution of a shell script for less than one
# millisecond, due to process creation overhead and scheduling
-# granularity, so we don't check for anything finer than that.
+# granularity, so we don't check for anything finer than that. (See below.)
AC_DEFUN([_AM_FILESYSTEM_TIMESTAMP_RESOLUTION], [dnl
AC_REQUIRE([_AM_SLEEP_FRACTIONAL_SECONDS])
AC_CACHE_CHECK([filesystem timestamp resolution], am_cv_filesystem_timestamp_resolution, [dnl
@@ -34,6 +34,9 @@ am_cv_filesystem_timestamp_resolution=2
# Only try to go finer than 1s if sleep can do it.
am_try_resolutions=1
if $am_cv_sleep_fractional_seconds; then
+  # Even a millisecond often causes a bunch of false positives,
+  # so just try a hundredth of a second. The time saved between .001 and
+  # .01 is not terribly consequential.
  am_try_resolutions="0.01 0.1 $am_try_resolutions"
fi

@@ -48,12 +51,13 @@ rm -f conftest.ts?
: > conftest.ts3

# Make sure ls -t actually works.  Do 'set' in a subshell so we don't
-# clobber the current shell's arguments.
+# clobber the current shell's arguments. (Outer-level square brackets
+# are for m4; be careful, it's easy to get confused.)
if (
     set X `[ls -t conftest.ts[12]]` &&
     {
-       test "$[*]" != "X conftest.ts1 conftest.ts2" ||
-       test "$[*]" != "X conftest.ts2 conftest.ts1";
+       test "$[]*" != "X conftest.ts1 conftest.ts2" ||
+       test "$[]*" != "X conftest.ts2 conftest.ts1";
     }
); then :; else
  # If neither matched, then we have a broken ls.  This can happen
@@ -64,7 +68,7 @@ if (
    ["Bad output from ls -t: \"`[ls -t conftest.ts[12]]`\""],
    [AS_MESSAGE_LOG_FD])
  AC_MSG_FAILURE([ls -t produces unexpected output.
-Make sure there is not a broken alias in your environment.])
+Make sure there is not a broken ls alias in your environment.])
fi

for am_try_res in $am_try_resolutions; do
@@ -84,11 +88,47 @@ for am_try_res in $am_try_resolutions; do
      test "$[]2" = conftest.ts3 &&
      test "$[]3" = conftest.ts2 &&
      test "$[]4" = conftest.ts1); then
-    am_cv_filesystem_timestamp_resolution=$am_try_res
-    break
+    #
+    # Ok, ls -t worked. We have one more thing to check: make.
+    # It can happen that everything else supports the subsecond mtimes,
+    # but make doesn't, notably on macOS, which ships make 3.81 from
+    # 2006 (the last one released under GPLv2). https://urldefense.com/v3/__https://bugs.gnu.org/68808__;!!LIr3w8kk_Xxm!rq87CiefTKIMZV02HfASxRvKLnpaw6kZk70cv22sBPSJkGDk112T-JXYGUYvKK_BgnEp19HKx-M5RVFS$
+    #
+    # So, first let's create a Makefile:
+    rm -f conftest.mk
+    echo 'conftest.ts1: conftest.ts2' >conftest.mk
+    echo ' touch conftest.ts2' >>conftest.mk
+    #
+    # Now, running
+    #   touch conftest.ts1; touch conftest.ts2; make
+    # should touch ts1 because ts2 is newer. This could happen by luck,
+    # but most often, it will fail if make's support is insufficient. So
+    # test for several consecutive successes.
+    #
+    # (We reuse conftest.ts[12] because we still want to modify existing
+    # files, not create new ones, per above.)
+    n=0
+    make_ok=true
+    until test $n -eq 4; do
+      echo one > conftest.ts1
+      sleep $am_try_res
+      echo two > conftest.ts2 # ts2 should now be newer than ts1
+      if make -f conftest.mk | grep 'up to date' >/dev/null; then
+        make_ok=false
+        break # out of $n loop
+      fi
+      n=`expr $n + 1`
+    done
+    if $make_ok; then
+      # Everything we know to check worked out, so call this resolution good.
+      am_cv_filesystem_timestamp_resolution=$am_try_res
+      break # out of resolution loop
+    fi
+    # Otherwise, we'll go on to check the next resolution.
  fi
done
rm -f conftest.ts?
+# (end _am_filesystem_timestamp_resolution)
])])

# AM_SANITY_CHECK

compile finished at Mon May 27 10:01:57 2024

[Message part 2 (text/html, inline)]

[color-tests2.log (application/octet-stream, attachment)]

[color-tests2-w.log (application/octet-stream, attachment)]

Message #38 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: JohnsonE <at> usc.edu
Cc: 68808 <at> debbugs.gnu.org
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Mon, 27 May 2024 15:06:29 -0600

    * fine on the tests that failed previously because of macOS default
      make having only second resolution

Great! Thanks much for the instant testing.

    * color-tests2.sh and color-tests2-w.sh fail -- logs attached.

I had tweaked some of the color stuff, so I must have messed up
somewhere. Will check. -k

Message #41 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: JohnsonE <at> usc.edu
Cc: 68808 <at> debbugs.gnu.org
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Wed, 29 May 2024 15:53:52 -0600

[Message part 1 (text/plain, inline)]

Hi Erik,

    * color-tests2.sh and color-tests2-w.sh fail -- logs attached.

Is this with the old make 3.81 from the system, or the new make you
compiled? What is in the "stdout" file in t/color-tests2.dir/stdout?
And, are these the only two tests that fail in the entire suite?

What I see in the log you sent is that color-tests2.log correctly runs 
  make  pass fail skip xpass xfail error
But then the test output only shows the PASS line:
..
make  check-TESTS
^[[0;32mPASS^[[m: pass
+ test_color
..
I believe that is doing "cat stdout", so everything else is missing,
even the Automake "Testsuite summary" footer.

I don't know why. It's as if the output from the parallel running of
make check overwrote itself, or maybe never ran. But this is not a
problem that's ever been reported before (and doesn't happen for me),
and I haven't knowingly changed anything here.

Thus I somewhat suspect this is some problem of make, and/or expect,
and/or something else. If it's something we can detect, we could skip
the test if we can't fix it. Help?

On my system, I see (I'll attach the whole log):
..
make  check-TESTS
make[1]: Entering directory '/u/karl/gnu/src/akarl/t/color-tests2.dir'
make[2]: Entering directory '/u/karl/gnu/src/akarl/t/color-tests2.dir'
^[[0;32mPASS^[[m: pass
^[[0;31mFAIL^[[m: fail
^[[1;34mSKIP^[[m: skip
^[[0;31mXPASS^[[m: xpass
^[[1;32mXFAIL^[[m: xfail
^[[0;35mERROR^[[m: error
^[[0;31m============================================================================^[[m
^[[0;31mTestsuite summary for color-tests2 1.0^[[m
..
+ test_color
..

(For the sake of this mail, I've removed ^M characters and replaced true
^[ ESC character with ASCII ^[.)

BTW, color-tests2-w is just a wrapper of color-tests2 to test VPATH, so
if we can solve color-tests2, its problems should go away too.

Thanks,
Karl

[color-tests2.log (application/octet-stream, attachment)]

Message #44 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Erik A Johnson <JohnsonE <at> usc.edu>
To: Karl Berry <karl <at> freefriends.org>
Cc: "68808 <at> debbugs.gnu.org" <68808 <at> debbugs.gnu.org>
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Thu, 30 May 2024 23:38:31 +0000

Hi, Karl.  As you suspected, this was an issue of making in parallel.  This was with the old make 3.81: my MAKEFLAGS is set to "-k -j12"; unsetting MAKEFLAGS and running works fine, with all tests passing.

Do color-tests2.sh and color-tests2-w.sh both write to the same directory and, thus, running in parallel may have caused them to be writing to the same file(s) at the same time?

With -j12 and the old make, it doesn't fail every time, just sometimes, so it's probably the luck of which tests are running in parallel when.

Should the color test be changed to not re-use the same directory or filenames? or that one test must come before the other?

Erik

P.S. For the original failing parallel make 3.81, the final stdout contents were:

	spawn make -e check
	make  pass fail skip xpass xfail error
	make[1]: Nothing to be done for `pass'.
	make[1]: Nothing to be done for `fail'.
	make[1]: Nothing to be done for `skip'.
	make[1]: Nothing to be done for `xpass'.
	make[1]: Nothing to be done for `xfail'.
	make[1]: Nothing to be done for `error'.
	make  check-TESTS
	^[[0;32mPASS^[[m: pass


> On May 29, 2024, at 2:53 PM, Karl Berry <karl <at> freefriends.org> wrote:
> 
> Hi Erik,
> 
>    * color-tests2.sh and color-tests2-w.sh fail -- logs attached.
> 
> Is this with the old make 3.81 from the system, or the new make you
> compiled? What is in the "stdout" file in t/color-tests2.dir/stdout?
> And, are these the only two tests that fail in the entire suite?
> 
> What I see in the log you sent is that color-tests2.log correctly runs 
>  make  pass fail skip xpass xfail error
> But then the test output only shows the PASS line:
> ..
> make  check-TESTS
> ^[[0;32mPASS^[[m: pass
> + test_color
> ..
> I believe that is doing "cat stdout", so everything else is missing,
> even the Automake "Testsuite summary" footer.
> 
> I don't know why. It's as if the output from the parallel running of
> make check overwrote itself, or maybe never ran. But this is not a
> problem that's ever been reported before (and doesn't happen for me),
> and I haven't knowingly changed anything here.
> 
> Thus I somewhat suspect this is some problem of make, and/or expect,
> and/or something else. If it's something we can detect, we could skip
> the test if we can't fix it. Help?
> 
> On my system, I see (I'll attach the whole log):
> ..
> make  check-TESTS
> make[1]: Entering directory '/u/karl/gnu/src/akarl/t/color-tests2.dir'
> make[2]: Entering directory '/u/karl/gnu/src/akarl/t/color-tests2.dir'
> ^[[0;32mPASS^[[m: pass
> ^[[0;31mFAIL^[[m: fail
> ^[[1;34mSKIP^[[m: skip
> ^[[0;31mXPASS^[[m: xpass
> ^[[1;32mXFAIL^[[m: xfail
> ^[[0;35mERROR^[[m: error
> ^[[0;31m============================================================================^[[m
> ^[[0;31mTestsuite summary for color-tests2 1.0^[[m
> ..
> + test_color
> ..
> 
> (For the sake of this mail, I've removed ^M characters and replaced true
> ^[ ESC character with ASCII ^[.)
> 
> BTW, color-tests2-w is just a wrapper of color-tests2 to test VPATH, so
> if we can solve color-tests2, its problems should go away too.
> 
> Thanks,
> Karl
> 
> <color-tests2.log>

Message #47 received at 68808 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: JohnsonE <at> usc.edu
Cc: 68808 <at> debbugs.gnu.org
Subject: Re: bug#68808: subsecond mtime discovery code insufficient
Date: Sat, 1 Jun 2024 11:47:54 -0600

    Do color-tests2.sh and color-tests2-w.sh both write to the same
    directory and, thus, running in parallel may have caused them to be
    writing to the same file(s) at the same time?

Every test runs in its own t/*.dir/ directory.  The ct2-w.sh test
sources the ct2.sh shell script, but it's still a separate test and they
shouldn't be able interfere with each other. I think.

    Should the color test be changed to not re-use the same directory or
    filenames? or that one test must come before the other?

The thing that confuses me is that if the problem was generically about
ct2 and ct2-w stepping on each other, or a test stepping on itself, it
should happen (sometimes) with any parallel make on any system. But no
one has ever reported it. This makes me think it is something about
make-3.81 (and/or, less likely, the mac), since that's what's different.

You don't see the ct2 failures when running with the new make that you
installed yourself, right? --thanks, karl.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.