[Bug build/30157] New: parallel "make check" randomly skips tests

[Bug build/30157] New: parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

            Bug ID: 30157
           Summary: parallel "make check" randomly skips tests
           Product: glibc
           Version: unspecified
            Status: UNCONFIRMED
          Severity: normal
          Priority: P2
         Component: build
          Assignee: unassigned at sourceware dot org
          Reporter: vincent-srcware at vinc17 dot net
                CC: carlos at redhat dot com
  Target Milestone: ---

I did several "make check" yesterday (2023-02-22), and I did another one today
(2023-02-23), and I can notice that some *.out files have not been rebuilt, so
if they were incorrect in the past, they are still incorrect, and at the end of
the tests, "make check" considers the associated tests as failing:

[...]
-rw-r--r-- 1     50 2023-02-23 13:10:44 elf/tst-glibc-hwcaps.out
-rw-r--r-- 1     43 2023-02-23 13:10:44 elf/tst-glibc-hwcaps-2.out
-rw-r--r-- 1     68 2023-02-23 13:10:45 elf/tst-glibc-hwcaps-2-cache.out
-rw-r--r-- 1     75 2023-02-23 13:10:45 elf/tst-glibc-hwcaps-cache.out
-rw-r--r-- 1      0 2023-02-22 17:12:19 elf/tst-glibc-hwcaps-mask.out
-rw-r--r-- 1      0 2023-02-22 17:12:19 elf/tst-glibc-hwcaps-prepend.out
-rw-r--r-- 1     25 2023-02-23 13:10:45 elf/tst-glibc-hwcaps-prepend-cache.out
-rw-r--r-- 1     12 2023-02-23 13:10:44 elf/tst-global1.out
-rw-r--r-- 1     16 2023-02-23 13:10:44 elf/tst-global2.out
-rw-r--r-- 1      5 2023-02-23 13:10:44 elf/tst-gnu2-tls1.out
-rw-r--r-- 1    583 2023-02-22 17:12:20 elf/tst-ifunc-fault-bindnow.out
-rw-r--r-- 1    583 2023-02-22 17:12:20 elf/tst-ifunc-fault-lazy.out
-rw-r--r-- 1      0 2023-02-23 13:10:44 elf/tst-ifunc-isa-1.out
-rw-r--r-- 1      0 2023-02-23 13:10:43 elf/tst-ifunc-isa-1-static.out
[...]

Note: "make" is actually a shell wrapper that adds the appropriate -j option
for parallelization (here -j12 as I have 12 cores) and colorizes the output.

Yesterday, I initially did a "make check" where LD_PRELOAD was set to some
library in the environment (as this is the case by default on my Debian
account), and got 8 failures. Some of these failures were due to the
LD_PRELOAD, so I tried again with LD_PRELOAD unset, but I got the same
failures; however, I noticed that the corresponding *.out files had not been
regenerated by the tests (their timestamp remained the same as before this new
test).

Today I did a "make check" again with LD_PRELOAD unset, and this time I got
only 5 failures. 3 of them are unrelated to LD_PRELOAD. But
elf/tst-ifunc-fault-bindnow and elf/tst-ifunc-fault-lazy are due to LD_PRELOAD,
and the timestamp of their .out files corresponds to the time when I did the
"make check" with LD_PRELOAD set. I suppose that 3 tests that now succeed have
been redone, so that their .out files have been rebuilt and are now correct.

I suspect that the random behavior is due to the parallelized make.

Possibly related to bug 22346 about another parallel "make check" issue. In the
summary of bug 29596 (for check-sim, now fixed): "unexpectedly passes without
actually testing", which is more or less what happens here, except that this is
for me: unexpectedly fails without actually testing.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #1 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
Oops, bugs 22346 and 29596 are for different products (Bugzilla is confusing
about its possible duplicates). However, if the code is similar, this could
also be an explanation.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #2 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
I forgot to say that this was on git master checked out yesterday, more
precisely, commit 8b014a1b1f7aee1e3348db108aeea396359d481e.

And for the context, see the thread:
  https://sourceware.org/pipermail/libc-alpha/2023-February/145790.html

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[sam at gentoo dot org]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

Sam James <sam at gentoo dot org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |sam at gentoo dot org

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[schwab@linux-m68k.org]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #3 from Andreas Schwab <schwab@linux-m68k.org> ---
The test runs follow the normal dependency rules.  If no source file has
changed, nothing is rebuild.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #4 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
(In reply to Andreas Schwab from comment #3)
> The test runs follow the normal dependency rules.  If no source file has
> changed, nothing is rebuild.

I agree that nothing should be rebuilt. But the tests should be run! (The .out
files are the results of the tests, so running a test will regenerate the
associated file.)

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #5 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
To give more details about which tests were run: in the "make check" output,
about "ifunc-":

env GCONV_PATH=/home/vlefevre/software/glibc-build/iconvdata
LOCPATH=/home/vlefevre/software/glibc-build/localedata LC_ALL=C  
/home/vlefevre/software/glibc-build/elf/tst-ifunc-isa-1-static  >
/home/vlefevre/software/glibc-build/elf/tst-ifunc-isa-1-static.out; \
../scripts/evaluate-test.sh elf/tst-ifunc-isa-1-static $? true false >
/home/vlefevre/software/glibc-build/elf/tst-ifunc-isa-1-static.test-result

and

env GCONV_PATH=/home/vlefevre/software/glibc-build/iconvdata
LOCPATH=/home/vlefevre/software/glibc-build/localedata LC_ALL=C
GLIBC_TUNABLES=glibc.cpu.hwcaps=-SSE4_2,-AVX,-AVX2,-AVX512F 
/home/vlefevre/software/glibc-build/elf/tst-ifunc-isa-2-static  >
/home/vlefevre/software/glibc-build/elf/tst-ifunc-isa-2-static.out; \
../scripts/evaluate-test.sh elf/tst-ifunc-isa-2-static $? true false >
/home/vlefevre/software/glibc-build/elf/tst-ifunc-isa-2-static.test-result

so that one can see that tst-ifunc-isa-1-static.out and
tst-ifunc-isa-2-static.out files are rebuilt as the corresponding tests are
run. But there is nothing for the tst-ifunc-fault-bindnow and
tst-ifunc-fault-lazy tests.

And near the end, one has:

../scripts/merge-test-results.sh -s /home/vlefevre/software/glibc-build/elf/
elf \
  [...] tst-gnu2-tls1 tst-ifunc-fault-bindnow tst-ifunc-fault-lazy
tst-ifunc-isa-1 tst-ifunc-isa-1-static tst-ifunc-isa-2 tst-ifunc-isa-2-static
tst-ifunc-textrel tst-initfinilazyfail [...]

Here, tst-ifunc-fault-bindnow and tst-ifunc-fault-lazy are included in the
merged results. So the results from an old "make check" are used.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[schwab@linux-m68k.org]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #6 from Andreas Schwab <schwab@linux-m68k.org> ---
Everything is dependency-driven, including test runs.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #7 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
(In reply to Andreas Schwab from comment #6)
> Everything is dependency-driven, including test runs.

This doesn't make sense and doesn't explain why some tests are run again, but
not other ones, and why this is random, i.e. with 3 consecutive "make check",
some tests may be skipped at the second run, but run again at the third run.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[carlos at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #8 from Carlos O'Donell <carlos at redhat dot com> ---
(In reply to Vincent Lefèvre from comment #7)
> (In reply to Andreas Schwab from comment #6)
> > Everything is dependency-driven, including test runs.
> 
> This doesn't make sense and doesn't explain why some tests are run again,
> but not other ones, and why this is random, i.e. with 3 consecutive "make
> check", some tests may be skipped at the second run, but run again at the
> third run.

I agree it doesn't answer your question, but it does set the expectation that
anything you find that is not driven by dependencies is a mistake (barring some
complexity around tests-container).

The standard set of glibc tests are entirely, from first principles,
dependency-driven. We sometimes have missing dependencies which result in odd
failures that we eventually track down, add the right dependency and the issue
is resolved. You may have found a test that is missing a dependency, but we
don't know that until someone reviews the exact tests and their dependencies.

Have you seen tests that were incorrectly executed based on their dependencies?

Note: I said "standard" earlier because the containerized tests build a rootfs
to use for isolation and those tests setup the container *once* and that is an
issue that could be improved.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #9 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
(In reply to Carlos O'Donell from comment #8)
> I agree it doesn't answer your question, but it does set the expectation
> that anything you find that is not driven by dependencies is a mistake
> (barring some complexity around tests-container).

Tests are there to find bugs, and bugs may depend on the run-time environment
in a broad sense (this may be environment variables, but also the current time,
the scheduling, in case of race conditions). So it does not make much sense to
say that if a test gave some result in some run, it will always give the same
result just because the source files have not changed.

> Have you seen tests that were incorrectly executed based on their
> dependencies?

Yes, for instance, with 3 "make check" without a change of the source files
(thus needing a build of everything only after the first one[*]), but
LD_PRELOAD was unset after the first one, elf/tst-audit23
* was executed after the first one (obviously) and failed due to the
LD_PRELOAD;
* was not executed after the second one;
* was executed after the third one (and no longer failed as LD_PRELOAD was no
longer set).

[*] unless there is a bug in the dependencies for the build.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #10 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
I've done another "make check". So now there are tests whose last execution is
* 2023-02-24 (today)
* 2023-02-23
* 2023-02-22 around 17:43
* 2023-02-22 around 17:12 (corresponding to the first "make check")

(No source files have been changed after the initial checkout.)

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[carlos at redhat dot com]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #11 from Carlos O'Donell <carlos at redhat dot com> ---
(In reply to Vincent Lefèvre from comment #9)
> (In reply to Carlos O'Donell from comment #8)
> > I agree it doesn't answer your question, but it does set the expectation
> > that anything you find that is not driven by dependencies is a mistake
> > (barring some complexity around tests-container).
> 
> Tests are there to find bugs, and bugs may depend on the run-time
> environment in a broad sense (this may be environment variables, but also
> the current time, the scheduling, in case of race conditions). So it does
> not make much sense to say that if a test gave some result in some run, it
> will always give the same result just because the source files have not
> changed.

Your are correct that the test results may vary depending on the system
configuration, but what you're asking for is outside the current assumptions of
the implementation. Describing the expectations highlights that the system is
behaving *as expected*, but what you are asking for is an enhancement to the
current build and test system.

The build and test system *expects* a correctly configured developer system and
optimizes for that to deduce developer iteration time to look at regression
test results.

If your system is incorrectly configured you may need to clean the whole build
and start again or `find . -name *.out | xargs rm` or something similar.

Could we do better? I expect we could.

> > Have you seen tests that were incorrectly executed based on their
> > dependencies?
> 
> Yes, for instance, with 3 "make check" without a change of the source files
> (thus needing a build of everything only after the first one[*]), but
> LD_PRELOAD was unset after the first one, elf/tst-audit23
> * was executed after the first one (obviously) and failed due to the
> LD_PRELOAD;
> * was not executed after the second one;
> * was executed after the third one (and no longer failed as LD_PRELOAD was
> no longer set).
> 
> [*] unless there is a bug in the dependencies for the build.

(In reply to Vincent Lefèvre from comment #10)
> I've done another "make check". So now there are tests whose last execution
> is
> * 2023-02-24 (today)
> * 2023-02-23
> * 2023-02-22 around 17:43
> * 2023-02-22 around 17:12 (corresponding to the first "make check")
> 
> (No source files have been changed after the initial checkout.)

Just to be clear, while you say "No source files have been changed", what is
actually important is *dependencies*.

In the case of tst-audit23 we have the following:

2283 $(objpfx)tst-audit23.out: $(objpfx)tst-auditmod23.so \
2284                           $(objpfx)tst-audit23mod.so

The tests need their output file (the *.out file) and this says that output
needs the two audit modules compiled, so they get built before the test is
built and run.

I would be curious to know if the *.out file was changed, or the *.so files
were changed, since they are are of the set of dependencies for the test.

-- 
You are receiving this mail because:
You are on the CC list for the bug.

[Bug build/30157] parallel "make check" randomly skips tests

[vincent-srcware at vinc17 dot net]

https://sourceware.org/bugzilla/show_bug.cgi?id=30157

--- Comment #12 from Vincent Lefèvre <vincent-srcware at vinc17 dot net> ---
(In reply to Carlos O'Donell from comment #11)
> (In reply to Vincent Lefèvre from comment #10)
> > I've done another "make check". So now there are tests whose last execution
> > is
> > * 2023-02-24 (today)
> > * 2023-02-23
> > * 2023-02-22 around 17:43
> > * 2023-02-22 around 17:12 (corresponding to the first "make check")
> > 
> > (No source files have been changed after the initial checkout.)
> 
> Just to be clear, while you say "No source files have been changed", what is
> actually important is *dependencies*.
> 
> In the case of tst-audit23 we have the following:
> 
> 2283 $(objpfx)tst-audit23.out: $(objpfx)tst-auditmod23.so \
> 2284                           $(objpfx)tst-audit23mod.so

The timestamps of these files:

-rwxr-xr-x 1 20080 2023-02-22 17:12:15 elf/tst-audit23mod.so*
-rwxr-xr-x 1 24632 2023-02-22 17:12:15 elf/tst-auditmod23.so*

(The timestamps of the elf/tst*.so files go from 2023-02-22 17:12:14 to
2023-02-22 17:12:23.)

So they still correspond to the first "make check".

> The tests need their output file (the *.out file) and this says that output
> needs the two audit modules compiled, so they get built before the test is
> built and run.
> 
> I would be curious to know if the *.out file was changed, or the *.so files
> were changed, since they are are of the set of dependencies for the test.

For the elf/*.out files:

cventin:...tware/glibc-build> ls -lgot **/elf/tst*.out
-rw-r--r-- 1     75 2023-02-23 15:32:36 elf/tst-glibc-hwcaps-cache.out
-rw-r--r-- 1     68 2023-02-23 15:32:36 elf/tst-glibc-hwcaps-2-cache.out
[...]
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-debug1.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit25a.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit25b.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit23.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit24a.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit24b.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit24c.out
-rw-r--r-- 1      0 2023-02-23 15:32:36 elf/tst-audit24d.out
-rw-r--r-- 1      9 2023-02-23 15:32:36 elf/tst-audit11.out
[...]
-rw-r--r-- 1      0 2023-02-23 15:32:35 elf/tst-dst-static.out
-rw-r--r-- 1     48 2023-02-22 17:12:25 elf/tst-dso-ordering9.out
-rw-r--r-- 1     48 2023-02-22 17:12:24 elf/tst-dso-ordering3.out
[...]
-rw-r--r-- 1      0 2023-02-22 17:12:18 elf/tst-relro-ldso.out
-rw-r--r-- 1      0 2023-02-22 17:12:14 elf/tst-glibcelf.out
-rw-r--r-- 1 160643 2023-02-22 17:12:12 elf/tst-ldconfig-p.out
-rw-r--r-- 1      0 2023-02-22 17:12:12 elf/tst-ldconfig-X.out

Since the tst*.out files were generated after their dependencies (built around
2023-02-22 17:12 in the first "make check"), I would have expected them not to
be rebuilt on 2023-02-23 (assuming that's how the glibc test rules work).

-- 
You are receiving this mail because:
You are on the CC list for the bug.