Python 3.9 test_os started to fail on Fedora CI, whereas it passed previously.
I suspect that something on Fedora CI is plugged between Python and the kernel. Does it use something like sandboxing? Does it run in a container using seccomp to filter syscalls?
The error was seen on the Linux kernel 5.12.0-0.rc4.20210326gitdb24726bfefa.178.fc35.x86_64 with the glibc 2.33.9000. See debugtest of: https://osci-jenkins-1.ci.fedoraproject.org/job/fedora-ci/job/dist-git-pipeline/job/master/34693/testReport/(root)/tests/
The two Python test failures:
FAIL: test_fdatasync (test.test_os.TestInvalidFD) ---------------------------------------------------------------------- Traceback (most recent call last): ... AssertionError: <built-in function fdatasync> didn't raise an OSError with a bad file descriptor FAIL: test_fsync (test.test_os.TestInvalidFD) ---------------------------------------------------------------------- Traceback (most recent call last): ... AssertionError: <built-in function fsync> didn't raise an OSError with a bad file descriptor
The change is not a Python regression, Miro reproduced the issue on a PR which does not anything: https://src.fedoraproject.org/rpms/python3.9/pull-request/59 (previously, the whole tes suite passed successfully).
test_os tests that calling os.fsync() and os.fdatasync() on an invalid file descriptor (closed file descriptor) fails. Manual test:
vstinner@apu$ python3 Python 3.9.2 (default, Feb 20 2021, 00:00:00) # create an invalid file descriptor >>> import os >>> fd=os.open("/etc/issue", os.O_RDONLY) >>> os.close(fd) >>> os.fsync(fd) Traceback (most recent call last): ... OSError: [Errno 9] Bad file descriptor >>> os.fdatasync(fd) Traceback (most recent call last): ... OSError: [Errno 9] Bad file descriptor
Python is a thin wrapper to glibc functions which are thin wrapper to the Linux kernel fsync() and fdatasync() syscalls.
I failed to find a recent change in the Linux kernel which could explain the behavior, the syscall clearly returns EBADF if the file descriptor is invalid: https://github.com/torvalds/linux/blob/fcadab740480e0e0e9fa9bd272acd409884d431a/fs/sync.c#L221
More details at: https://src.fedoraproject.org/rpms/python3.9/pull-request/56
Note that this started to happen on all Fedora versions and only on Jenkins (i.e. not on Zuul). hence I suspect nothing has changed in the tested system, but rather the test infrastructure has changed somehow.
I can give you machine if you want to debug it. We recently moved from t2.small instances to t3.medium, what should be the default we want to use. But I am super suprised it would case such an issue:
https://aws.amazon.com/ec2/instance-types/
It should be all Intel based VMs :/
I tried on a random machine that is now in flight:
# rpm -q python3 kernel-core python3-3.9.2-1.fc35.x86_64 kernel-core-5.12.0-0.rc4.20210326gitdb24726bfefa.178.fc35.x86_64 kernel-core-5.12.0-0.rc6.184.fc35.x86_64 # python3 Python 3.9.2 (default, Feb 20 2021, 00:00:00) [GCC 11.0.0 20210210 (Red Hat 11.0.0-0)] on linux >>> import os >>> >>> fd=os.open("/etc/issue", os.O_RDONLY) >>> os.close(fd) >>> os.fsync(fd) >>> os.fdatasync(fd) >>>
And I see the problem ....
Spinning you up an machine and will contact you on IRC
This is likely caused by something like nosync or eatmydata. These things filter out fsync and fdatasync system calls to reduce build or testing time, using an LD_PRELOAD library.
nosync
eatmydata
fsync
fdatasync
LD_PRELOAD
Note that mock may inject nosync.so outside the regular RPM dependency management, as can be seen in bug 1837809 comment 13.
mock
nosync.so
You're right. I got access to two machines:
Machine B has a /usr/lib64/nosync.so library installed, but it's not installed by RPM!
# rpm -qf /usr/lib64/nosync.so file /usr/lib64/nosync.so is not owned by any package
Moreover, this library is preloaded by:
# cat /etc/ld.so.preload /usr/lib64/nosync.so
Notes:
/* Check if a file descriptor is valid or not. Return 0 if the file descriptor is invalid, return non-zero otherwise. */ static int is_valid_fd(int fd) { /* dup() is faster than fstat(): fstat() can require input/output operations, whereas dup() doesn't. There is a low risk of EMFILE/ENFILE at Python startup. Problem: dup() doesn't check if the file descriptor is valid on some platforms. bpo-30225: On macOS Tiger, when stdout is redirected to a pipe and the other side of the pipe is closed, dup(1) succeed, whereas fstat(1, &st) fails with EBADF. FreeBSD has similar issue (bpo-32849). Only use dup() on platforms where dup() is enough to detect invalid FD in corner cases: on Linux and Windows (bpo-32849). */ #if defined(__linux__) || defined(MS_WINDOWS) if (fd < 0) { return 0; } int fd2; _Py_BEGIN_SUPPRESS_IPH fd2 = dup(fd); if (fd2 >= 0) { close(fd2); } _Py_END_SUPPRESS_IPH return (fd2 >= 0); #else struct stat st; return (fstat(fd, &st) == 0); #endif }
Yeah, well, I feel embarrassed, sorry for taking your time. We added this workaround to speed up significantly installability test, but running it in general was not wise. I removed the workaround and we should make this workaround optional :/
Rerunning to confirm: https://osci-jenkins-1.ci.fedoraproject.org/job/fedora-ci/job/dist-git-pipeline/job/master/35227/console
/usr/lib64/nosync.so installs fsync(fd) functions which always return 0:
<fsync> xor %eax,%eax <fsync+2> ret
In C, it would be:
int fsync(int fd) { return 0; }
Fedora has a "nosync" package which comes from: https://github.com/kjn/nosync
It implements fsync() as: https://github.com/kjn/nosync/blob/master/fsync.c
I proposed https://github.com/kjn/nosync/pull/5 to check if the FD is valid in fsync() and fdatasync().
Oh, did not know there is a nosync package in Fedora, thanks. We can use that later on, but still we will make this feature a setting, rather then the default to mitigate any suprises like this one.
Oh, that's ok. It only took me between 1 and 2 hours to investigate the issue. I didn't waste a whole week. I learnt new exciting things and I proposed a fix ;-)
I didn't know nosync. There is also the "eat-my-data" project which is similar: https://github.com/geofft/eatmydata But this project doesn't check fsync(fd) file descriptor neither.
nosync comes from https://github.com/comps/anaconda-nosync
I know nosync from mock configuration but I didn't know it is preloaded.
FYI I found nosync loaded in the process memory when I inspected /proc//maps of a Python process. I didn't understand how fsync() implementation in gdb was just 2 x86 instructions (in short, "return 0"). It is not preloaded by an environment variable, but /etc/ld.so.preload configuration file (I also discovered this file :-)).