[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Re: file born 30 seconds after its creation on ext4 - bug?



On Tue, Apr 26, 2022 at 8:45 AM Vincent Lefevre <vincent@vinc17.net> wrote:
On an ext4 filesystem, I got a file born 30 seconds after its
actual creation. Is this a bug?

Only experimentation can really back me up on this, but consider the following:

Every time you use the "|" operator or the ";" separator on a command-line,
new processes are being spawned. Which wait to be dispatched on a core.
But you are not serializing the dispatch of those processes, and especially with
16 fast cores, you can't predict their order of execution.
 
I know that such issues can be observed with NFS, but here this
is just a local ext4 filesystem.

Here are the details.

I started a shell script:

cventin:~> ps -p 667828 -o lstart,cmd
                 STARTED CMD
Tue Apr 26 14:43:15 2022 /bin/sh /home/vlefevre/wd/mpfr/tests/mpfrtests.sh

This script creates a file mpfrtests.cventin.lip.ens-lyon.fr.out
very early. But the first attempts to look at this file failed:

cventin:~/software/mpfr> tail -n 30 mpfrtests.*.out; ll mpfrtests.*.out
zsh: no match
zsh: no match
cventin:~/software/mpfr[1]> tail -n 30 mpfrtests.*.out; ll mpfrtests.*.out
zsh: no match
zsh: no match
cventin:~/software/mpfr[1]> lt|head                                   <14:43:42
total 7016
-rw-r--r--  1  188644 2022-04-26 14:43:42 config.log
-rw-r--r--  1    2861 2022-04-26 14:43:42 conftest.c
-rw-r--r--  1       0 2022-04-26 14:43:42 conftest.err
-rw-r--r--  1    1907 2022-04-26 14:43:42 confdefs.h
-rwxr-xr-x  1  632161 2022-04-26 14:43:16 configure.lineno*
drwxr-xr-x  2    4096 2022-04-26 14:43:11 doc/
drwxr-xr-x  3    4096 2022-04-26 14:43:11 tune/
-rwxr-xr-x  1   23568 2022-04-26 14:43:11 depcomp*
drwxr-xr-x  5   36864 2022-04-26 14:43:11 tests/
cventin:~/software/mpfr> lt|head                                      <14:43:47
total 6416
-rw-r--r--  1   19436 2022-04-26 14:43:47 config.log
-rw-r--r--  1     561 2022-04-26 14:43:47 conftest.c
-rw-r--r--  1       0 2022-04-26 14:43:47 conftest.err
-rw-r--r--  1    4138 2022-04-26 14:43:47 mpfrtests.cfgout
-rw-r--r--  1     500 2022-04-26 14:43:47 confdefs.h
-rwxr-xr-x  1  632161 2022-04-26 14:43:45 configure.lineno*
-rw-r--r--  1     878 2022-04-26 14:43:45 mpfrtests.cventin.lip.ens-lyon.fr.out
drwxr-xr-x  3    4096 2022-04-26 14:43:44 tune/
drwxr-xr-x  4   36864 2022-04-26 14:43:44 tests/

According to /usr/bin/stat, the file birth is

 Birth: 2022-04-26 14:43:45.537241731 +0200

thus 30 seconds after the script started!

Note that the configure.lineno file is created *after*
mpfrtests.cventin.lip.ens-lyon.fr.out, and one can see that
at 14:43:16, configure.lineno was already created.

This is a 12-core Debian/unstable machine with

Linux cventin 5.17.0-1-amd64 #1 SMP PREEMPT Debian 5.17.3-1 (2022-04-18) x86_64 GNU/Linux

--
Vincent Lefèvre <vincent@vinc17.net> - Web: <https://www.vinc17.net/>
100% accessible validated (X)HTML - Blog: <https://www.vinc17.net/blog/>
Work: CR INRIA - computer arithmetic / AriC project (LIP, ENS-Lyon)


Reply to: