bug#55706: 29.0.50; files test fails about 20% of the time

bug#55706: 29.0.50; files test fails about 20% of the time

[Lars Ingebrigtsen]

I can't reproduce this reliably, but in about 20% of the times I run
"make check", this test fails:

Test files-tests-file-name-non-special-file-in-directory-p condition:
    (ert-test-failed
     ((should
       (file-in-directory-p nospecial nospecial-tempdir))
      :form
      (file-in-directory-p "/:/tmp/files-testsuqfdq1.special" "/:/tmp/")
      :value nil))
   FAILED   52/112  files-tests-file-name-non-special-file-in-directory-p (0.001158 sec) at lisp/files-tests.el:692

Michael wrote the test, so I've added him to the CCs.


In GNU Emacs 29.0.50 (build 1, x86_64-pc-linux-gnu, GTK+ Version 3.24.33, cairo version 1.16.0)
 of 2022-05-17 built on xo
Repository revision: 803041e01474f2a522170c9f388068e8460be2ae
Repository branch: master
Windowing system distributor 'The X.Org Foundation', version 11.0.12101003
System Description: Debian GNU/Linux bookworm/sid


-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

bug#55706: 29.0.50; files test fails about 20% of the time

[Michael Albinus]

Lars Ingebrigtsen <larsi@gnus.org> writes:

Hi,

> I can't reproduce this reliably, but in about 20% of the times I run
> "make check", this test fails:
>
> Test files-tests-file-name-non-special-file-in-directory-p condition:
>     (ert-test-failed
>      ((should
>        (file-in-directory-p nospecial nospecial-tempdir))
>       :form
>       (file-in-directory-p "/:/tmp/files-testsuqfdq1.special" "/:/tmp/")
>       :value nil))
>    FAILED   52/112  files-tests-file-name-non-special-file-in-directory-p (0.001158 sec) at lisp/files-tests.el:692
>
> Michael wrote the test, so I've added him to the CCs.

Strange. I have applied 100 times "make -C test files-tests". It always
returns

--8<---------------cut here---------------start------------->8---
Ran 112 tests, 111 results as expected, 1 unexpected (2022-05-30 18:34:19+0200, 1.005432 sec)

1 unexpected results:
   PASSED  files-load-elc-gz-file
--8<---------------cut here---------------end--------------->8---

(This might also be worth to be investigated.) No error of
files-tests-file-name-non-special-file-in-directory-p.

Perhaps the parallel nature of the test runs make it happen? Does it
also fail occasionally when you call "make -j1 ..."?

Furthermore, (file-in-directory-p "/:/tmp/files-testsuqfdq1.special" "/:/tmp/")
should always return non-nil, unless the directory /tmp does not exist,
or is not accessible. Could this happen in your environment, temporarily?

Best regards, Michael.

bug#55706: 29.0.50; files test fails about 20% of the time

[Lars Ingebrigtsen]

Michael Albinus <michael.albinus@gmx.de> writes:

> Perhaps the parallel nature of the test runs make it happen? Does it
> also fail occasionally when you call "make -j1 ..."?

I have never seen it happen with a -j1, but I don't usually do that.

> Furthermore, (file-in-directory-p "/:/tmp/files-testsuqfdq1.special" "/:/tmp/")
> should always return non-nil, unless the directory /tmp does not exist,
> or is not accessible. Could this happen in your environment, temporarily?

No, it's just a standard Debian/bookworm machine with a normal /tmp.

I'll set it up to look over a -j1 to see whether it even fails when
doing that and report back.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

bug#55706: 29.0.50; files test fails about 20% of the time

[Lars Ingebrigtsen]

I've now run a number of

for i in `seq 1 40`; do make -j64 check; done > /tmp/j64.out 2>/tmp/j64.err

variations, and it varies how much it fails.  With -j4 and lower, it
never fails.  With j8 to j16 it fails about 1 in 10 times, and with -j32
it fails 40% of the time.  (Take numbers with a grain of salt.)

So there seems to be something racing with this test -- but only this
test.  Pretty bizarre.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

bug#55706: 29.0.50; files test fails about 20% of the time

[Michael Albinus]

Lars Ingebrigtsen <larsi@gnus.org> writes:

Hi,

> I've now run a number of
>
> for i in `seq 1 40`; do make -j64 check; done > /tmp/j64.out 2>/tmp/j64.err
>
> variations, and it varies how much it fails.  With -j4 and lower, it
> never fails.  With j8 to j16 it fails about 1 in 10 times, and with -j32
> it fails 40% of the time.  (Take numbers with a grain of salt.)
>
> So there seems to be something racing with this test -- but only this
> test.  Pretty bizarre.

Yep, bizarre. I have no idea what's up. Let's sleep about it ...

Best regards, Michael.

bug#55706: 29.0.50; files test fails about 20% of the time

[Michael Albinus]

Lars Ingebrigtsen <larsi@gnus.org> writes:

Hi Lars,

> I've now run a number of
>
> for i in `seq 1 40`; do make -j64 check; done > /tmp/j64.out 2>/tmp/j64.err
>
> variations, and it varies how much it fails.  With -j4 and lower, it
> never fails.  With j8 to j16 it fails about 1 in 10 times, and with -j32
> it fails 40% of the time.  (Take numbers with a grain of salt.)

I have less cores in my laptop, so I have applied your code with -j8. It
failed exactly one time. Not bad, so I'm able to reproduce it.

> So there seems to be something racing with this test -- but only this
> test.  Pretty bizarre.

I will instrument both the test function and file-in-directory-p in
order to get more information about the reason. Don't expect results
soon, these days I'm slow in working for Emacs.

Best regards, Michael.

bug#55706: 29.0.50; files test fails about 20% of the time

[Lars Ingebrigtsen]

Michael Albinus <michael.albinus@gmx.de> writes:

> I have less cores in my laptop, so I have applied your code with -j8. It
> failed exactly one time. Not bad, so I'm able to reproduce it.

I was beginning to wonder whether it was just a problem on my build
machine -- I couldn't reproduce it at all on my laptop (but the laptop
is really slow compared to the build machine).

>> So there seems to be something racing with this test -- but only this
>> test.  Pretty bizarre.
>
> I will instrument both the test function and file-in-directory-p in
> order to get more information about the reason. Don't expect results
> soon, these days I'm slow in working for Emacs.

No problem.  :-)

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

bug#55706: 29.0.50; files test fails about 20% of the time

[Michael Albinus]

Lars Ingebrigtsen <larsi@gnus.org> writes:

Hi Lars,

>> I have less cores in my laptop, so I have applied your code with -j8. It
>> failed exactly one time. Not bad, so I'm able to reproduce it.
>
> I was beginning to wonder whether it was just a problem on my build
> machine -- I couldn't reproduce it at all on my laptop (but the laptop
> is really slow compared to the build machine).

Finally, I could catch it. file-in-directory-p calls at the very end
(file-equal-p root dir), which is (file-equal-p "/tmp/" "/tmp/") in our
test case. In file-equal-p, the file attributes of file1 and file2 are
compared via equal, which means in the failing test

--8<---------------cut here---------------start------------->8---
(equal '(t 31 0 0 (25238 27804 344363 628000) (25238 27804 371363 598000) (25238 27804 371363 598000) 820 drwxrwxrwt t 1 37)
       '(t 31 0 0 (25238 27804 344363 628000) (25238 27804 372363 597000) (25238 27804 372363 597000) 800 drwxrwxrwt t 1 37)
--8<---------------cut here---------------end--------------->8---

As you can see, the file attributes of "/tmp" are not equal. This is,
because between the first and second call of file-attributes, "/tmp" has
been changed due to the other test jobs running in parallel.

I've fixed this by creating a subdirectory of "/tmp", using it as
temporary-file-directory. Pushed to master. Could you, pls, check
whether this works also on your build machine with -j64? For me it works
w/o any problem, even with an iteration of 100 over "make -j8 check".

Best regards, Michael.

bug#55706: 29.0.50; files test fails about 20% of the time

[Lars Ingebrigtsen]

Michael Albinus <michael.albinus@gmx.de> writes:

> As you can see, the file attributes of "/tmp" are not equal. This is,
> because between the first and second call of file-attributes, "/tmp" has
> been changed due to the other test jobs running in parallel.

Heh.

> I've fixed this by creating a subdirectory of "/tmp", using it as
> temporary-file-directory. Pushed to master. Could you, pls, check
> whether this works also on your build machine with -j64? For me it works
> w/o any problem, even with an iteration of 100 over "make -j8 check".

Thanks; I can confirm that the problem is gone on my main build machine
after running with -j64 dozens of time.

(Closing the bug report.)

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no