Possible problem with busybox

[inorton]

Hi, I have compiled the latest libfaketime (with set time support enabled) and have installed libfaketimeMT.so.1 in my /etc/ld.so.preload file. I have the following env vars set:

NO_FAKE_STAT=1
FAKETIME_NO_CACHE=1
FAKETIME_DONT_RESET=1
FAKETIME_TIMESTAMP_FILE=/faketime
FAKETIME_UPDATE_TIMESTAMP_FILE=1
FAKETIME_DONT_FAKE_MONOTONIC=1

And have a /faketime file that all users can read.
My libfaketime is compiled on debian buster with gcc 8.4.
I'm running busybox on this system (it is a docker container based on debian buster) and running simple file creation or update operations fail. eg:

/tmp # touch zerbra
touch: zerbra: Invalid argument

Using regular bash or python to read/write/create files works correctly.

I have strace in here and have some output if that helps (here /usr/bin/touch is a symlink to /bin/busybox):

execve("/usr/bin/touch", ["touch", "zebra"], 0x7ffd8aa9e758 /* 14 vars */) = 0
brk(NULL)                               = 0x55ee01843000
access("/etc/ld.so.preload", R_OK)      = 0
openat(AT_FDCWD, "/etc/ld.so.preload", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=28, ...}) = 0
mmap(NULL, 28, PROT_READ|PROT_WRITE, MAP_PRIVATE, 3, 0) = 0x7ff2bfa17000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/libfaketimeMT.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340)\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=76488, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff2bfa15000
mmap(NULL, 2195136, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf7fd000
mprotect(0x7ff2bf80c000, 2093056, PROT_NONE) = 0
mmap(0x7ff2bfa0b000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe000) = 0x7ff2bfa0b000
mmap(0x7ff2bfa0d000, 32448, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7ff2bfa0d000
close(3)                                = 0
munmap(0x7ff2bfa17000, 28)              = 0
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=18928, ...}) = 0
mmap(NULL, 18928, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ff2bf7f8000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240C\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=93000, ...}) = 0
mmap(NULL, 105088, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf7de000
mprotect(0x7ff2bf7e2000, 73728, PROT_NONE) = 0
mmap(0x7ff2bf7e2000, 53248, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0x7ff2bf7e2000
mmap(0x7ff2bf7ef000, 16384, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x11000) = 0x7ff2bf7ef000
mmap(0x7ff2bf7f4000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x7ff2bf7f4000
mmap(0x7ff2bf7f6000, 6784, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7ff2bf7f6000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260A\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1824496, ...}) = 0
mmap(NULL, 1837056, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf61d000
mprotect(0x7ff2bf63f000, 1658880, PROT_NONE) = 0
mmap(0x7ff2bf63f000, 1343488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7ff2bf63f000
mmap(0x7ff2bf787000, 311296, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16a000) = 0x7ff2bf787000
mmap(0x7ff2bf7d4000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b6000) = 0x7ff2bf7d4000
mmap(0x7ff2bf7da000, 14336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7ff2bf7da000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@l\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=146968, ...}) = 0
mmap(NULL, 132288, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf5fc000
mmap(0x7ff2bf602000, 61440, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7ff2bf602000
mmap(0x7ff2bf611000, 24576, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x7ff2bf611000
mmap(0x7ff2bf617000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a000) = 0x7ff2bf617000
mmap(0x7ff2bf619000, 13504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7ff2bf619000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\21\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14592, ...}) = 0
mmap(NULL, 16656, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf5f7000
mmap(0x7ff2bf5f8000, 4096, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0x7ff2bf5f8000
mmap(0x7ff2bf5f9000, 4096, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7ff2bf5f9000
mmap(0x7ff2bf5fa000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7ff2bf5fa000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\322\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1579448, ...}) = 0
mmap(NULL, 1581384, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf474000
mmap(0x7ff2bf481000, 651264, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xd000) = 0x7ff2bf481000
mmap(0x7ff2bf520000, 872448, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xac000) = 0x7ff2bf520000
mmap(0x7ff2bf5f5000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x180000) = 0x7ff2bf5f5000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260#\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=35808, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff2bf472000
mmap(NULL, 39904, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7ff2bf468000
mmap(0x7ff2bf46a000, 16384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7ff2bf46a000
mmap(0x7ff2bf46e000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7ff2bf46e000
mmap(0x7ff2bf470000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7ff2bf470000
close(3)                                = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff2bf465000
arch_prctl(ARCH_SET_FS, 0x7ff2bf465740) = 0
mprotect(0x7ff2bf7d4000, 16384, PROT_READ) = 0
mprotect(0x7ff2bf617000, 4096, PROT_READ) = 0
mprotect(0x7ff2bf470000, 4096, PROT_READ) = 0
mprotect(0x7ff2bf5f5000, 4096, PROT_READ) = 0
mprotect(0x7ff2bf5fa000, 4096, PROT_READ) = 0
mprotect(0x7ff2bf7f4000, 4096, PROT_READ) = 0
mprotect(0x7ff2bfa0b000, 4096, PROT_READ) = 0
mprotect(0x55ee0040f000, 16384, PROT_READ) = 0
mprotect(0x7ff2bfa3f000, 4096, PROT_READ) = 0
munmap(0x7ff2bf7f8000, 18928)           = 0
set_tid_address(0x7ff2bf465a10)         = 175
set_robust_list(0x7ff2bf465a20, 24)     = 0
rt_sigaction(SIGRTMIN, {sa_handler=0x7ff2bf6026b0, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x7ff2bf60e730}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0x7ff2bf602740, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0x7ff2bf60e730}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
futex(0x7ff2bf5fb0c8, FUTEX_WAKE_PRIVATE, 2147483647) = 0
brk(NULL)                               = 0x55ee01843000
brk(0x55ee01864000)                     = 0x55ee01864000
statfs("/dev/shm/", {f_type=TMPFS_MAGIC, f_bsize=4096, f_blocks=16384, f_bfree=16378, f_bavail=16378, f_files=4098658, f_ffree=4098651, f_fsid={val=[0, 0]}, f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST_NOSUID|ST_NODEV|ST_NOEXEC|ST_RELATIME}) = 0
futex(0x7ff2bf61c3b0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/dev/shm/sem.faketime_sem_143", O_RDWR|O_NOFOLLOW) = 3
fstat(3, {st_mode=S_IFREG|0600, st_size=32, ...}) = 0
mmap(NULL, 32, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7ff2bfa17000
close(3)                                = 0
munmap(0x7ff2bfa17000, 32)              = 0
openat(AT_FDCWD, "/dev/shm/sem.faketime_sem_143", O_RDWR|O_NOFOLLOW) = 3
fstat(3, {st_mode=S_IFREG|0600, st_size=32, ...}) = 0
mmap(NULL, 32, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7ff2bfa17000
close(3)                                = 0
openat(AT_FDCWD, "/dev/shm/faketime_shm_143", O_RDWR|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0600) = 3
mmap(NULL, 64, PROT_READ|PROT_WRITE, MAP_SHARED, 3, 0) = 0x7ff2bf7fc000
openat(AT_FDCWD, "/faketime", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
read(4, "", 4096)                       = 0
close(4)                                = 0
getuid()                                = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
openat(AT_FDCWD, "/faketime", O_RDONLY) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
read(4, "", 4096)                       = 0
close(4)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
utimes("zebra", [{tv_sec=0, tv_usec=1647597492}, {tv_sec=0, tv_usec=1647597492}]) = -1 EINVAL (Invalid argument)
write(2, "touch: zebra: Invalid argument\n", 31touch: zebra: Invalid argument
) = 31

[inorton]

Setting -UFAKE_FILE_TIMESTAMPS doesn't seem to help

[inorton]

It seems, that when run without libfaketime, busybox makes a different call to utimes()

stat("/etc/busybox.conf", 0x7ffd0151f838) = -1 ENOENT (No such file or directory)
getgid()                                = 10116
setgid(10116)                           = 0
setuid(10116)                           = 0
utimes("zebra", NULL)                       = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "zebra", O_RDWR|O_CREAT, 0666) = 3
close(3)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

With LD_PRELOAD set I see:

getgid()                                = 10116
setgid(10116)                           = 0
setuid(10116)                           = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
openat(AT_FDCWD, "(null)", O_RDONLY)    = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/inb/.faketimerc", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/faketimerc", O_RDONLY) = -1 ENOENT (No such file or directory)
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
utimes("zebra", [{tv_sec=1, tv_usec=139677214016545}, {tv_sec=1, tv_usec=139677214016545}]) = -1 EINVAL (Invalid argument)
write(2, "touch: zebra: Invalid argument\n", 31touch: zebra: Invalid argument
) = 31
munmap(0x7f0922c7c000, 8)               = 0
munmap(0x7f0922c7d000, 32)              = 0
exit_group(1)                           = ?
+++ exited with 1 +++

[inorton]

With a little printf debugging, (can't get gdb to catch this for some reason) I can see that libfaketime's utimes() function gets called with NULL for times. So this triggers the call to fake_gettimeofday() if fake_utime_disabled == 0. Which then calls the real utime() with the faked values.

[inorton]

It seems, that if I compile with -UFAKE_STAT and ensure FAKE_UTIME=y is set, then busybox works. I think this is similar to what is discussed in http://lists.busybox.net/pipermail/buildroot/2020-February/273864.html but I think the buildroot people got the compiler flags wrong.

I will put up a PR with my fix that allows for turning off FAKE_STAT

[wolfcw]

Thanks for tracing and fixing this!! Just merged your PR.