| Re: [chrony-users] Fatal error : adjtimex() failed |
[ Thread Index |
Date Index
| More chrony.tuxfamily.org/chrony-users Archives
]
On 21/08/2012 20:33, Miroslav Lichvar wrote:
On Tue, Aug 21, 2012 at 06:05:46PM +0100, Tomalak Geret'kal wrote:
It's really just the adjtimex()/shmget() oddity I'm confused about
now. It really does seem to occur largely randomly and then vanish
when I replace the binary with a new build which differs only by
more verbose syslog output; to me, this screams UB in my build, but
yikes. My investigation continues...!
That sounds like a race condition. Does it work under strace?
Does flushing the kernel cache trigger it again?
echo 3 > /proc/sys/vm/drop_caches
Here's an strace of the adjtimex() problem occuring. In this
instance it was spontaneous after a reboot (rather than
triggered by flushing the kernel cache, which I haven't
tried yet).
It seems odd that chrony fails to open /var/run/chrony.pid
and fails to adjtimex(), presumably both through permissions
errors (though this is only made clear-ish for the latter).
There is *only* a root user on the device, and no selinux or
anything of that ilk. The intermittent nature of the fault
does not involve a change in user context. Still a race
condition?
Tom
execve("/usr/local/bin/chronyd", ["chronyd", "-d"], [/* 15 vars */]) = 0
brk(0) = 0x3d000
fcntl64(0, F_GETFD) = 0
fcntl64(1, F_GETFD) = 0
fcntl64(2, F_GETFD) = 0
access("/etc/suid-debug", F_OK) = -1 ENOENT (No such file or directory)
uname({sys="Linux", node="sw200319", ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4001d000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=1846, ...}) = 0
mmap2(NULL, 1846, PROT_READ, MAP_PRIVATE, 3, 0) = 0x4001e000
close(3) = 0
open("/lib/libm.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\2501\0\000"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=743679, ...}) = 0
mmap2(NULL, 704672, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x40026000
mprotect(0x400ca000, 28672, PROT_NONE) = 0
mmap2(0x400d1000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa3) = 0x400d1000
close(3) = 0
open("/lib/libgcc_s.so.1", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0x\'\0\000"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=69850, ...}) = 0
mmap2(NULL, 79676, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x400d3000
mprotect(0x400df000, 28672, PROT_NONE) = 0
mmap2(0x400e6000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb) = 0x400e6000
close(3) = 0
open("/lib/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\300Q\1\000"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1553002, ...}) = 0
mmap2(NULL, 1212984, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x400e7000
mprotect(0x40202000, 32768, PROT_NONE) = 0
mmap2(0x4020a000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x11b) = 0x4020a000
mmap2(0x4020d000, 8760, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x4020d000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4001f000
syscall_983045(0x4001f790, 0x4001fe60, 0x4002567c, 0x4001fe68, 0x40025050, 0x40025000, 0, 0xf0005, 0x50, 0x1, 0xffff5118, 0xbefb3ad4, 0, 0xbefb3950, 0x400114ec, 0x40001f78, 0x20000010, 0x4001f790, 0, 0, 0, 0xd5b8, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) = 0
mprotect(0x4020a000, 8192, PROT_READ) = 0
mprotect(0x400d1000, 4096, PROT_READ) = 0
mprotect(0x40024000, 4096, PROT_READ) = 0
munmap(0x4001e000, 1846) = 0
brk(0) = 0x3d000
brk(0x5e000) = 0x5e000
open("/etc/chrony.conf", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=210, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4001e000
read(3, "#config-sw4.2\nallow\nrefclock PPS"..., 4096) = 210
read(3, "", 4096) = 0
close(3) = 0
munmap(0x4001e000, 4096) = 0
getuid32() = 0
gettimeofday({1345715584, 490494}, NULL) = 0
open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "main.c:324:(main)[23-09:53:04] ", 31main.c:324:(main)[23-09:53:04] ) = 31
write(2, "chronyd version 1.26 starting\n", 30chronyd version 1.26 starting
) = 30
open("/var/run/chronyd.pid", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/var/run/chronyd.pid", O_WRONLY|O_CREAT|O_TRUNC, 0666) = -1 EACCES (Permission denied)
gettimeofday({1345715584, 511100}, NULL) = 0
open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "main.c:200:(write_lockfile)[23-0"..., 41main.c:200:(write_lockfile)[23-09:53:04] ) = 41
write(2, "could not open lockfile /var/run"..., 57could not open lockfile /var/run/chronyd.pid for writing
) = 57
gettimeofday({1345715584, 529791}, NULL) = 0
gettimeofday({1345715584, 531986}, NULL) = 0
gettimeofday({1345715584, 534202}, NULL) = 0
gettimeofday({1345715584, 536287}, NULL) = 0
gettimeofday({1345715584, 538328}, NULL) = 0
gettimeofday({1345715584, 540519}, NULL) = 0
gettimeofday({1345715584, 542738}, NULL) = 0
gettimeofday({1345715584, 544764}, NULL) = 0
gettimeofday({1345715584, 546871}, NULL) = 0
gettimeofday({1345715584, 549064}, NULL) = 0
gettimeofday({1345715584, 551284}, NULL) = 0
gettimeofday({1345715584, 554019}, NULL) = 0
gettimeofday({1345715584, 556422}, NULL) = 0
gettimeofday({1345715584, 558718}, NULL) = 0
gettimeofday({1345715584, 561227}, NULL) = 0
gettimeofday({1345715584, 563537}, NULL) = 0
gettimeofday({1345715584, 568116}, NULL) = 0
gettimeofday({1345715584, 570618}, NULL) = 0
gettimeofday({1345715584, 573098}, NULL) = 0
gettimeofday({1345715584, 580188}, NULL) = 0
gettimeofday({1345715584, 582496}, NULL) = 0
gettimeofday({1345715584, 584989}, NULL) = 0
gettimeofday({1345715584, 593506}, NULL) = 0
gettimeofday({1345715584, 601793}, NULL) = 0
gettimeofday({1345715584, 604065}, NULL) = 0
gettimeofday({1345715584, 610957}, NULL) = 0
gettimeofday({1345715584, 613487}, NULL) = 0
gettimeofday({1345715584, 620119}, NULL) = 0
gettimeofday({1345715584, 622452}, NULL) = 0
gettimeofday({1345715584, 624959}, NULL) = 0
gettimeofday({1345715584, 631545}, NULL) = 0
gettimeofday({1345715584, 633828}, NULL) = 0
gettimeofday({1345715584, 638444}, NULL) = 0
gettimeofday({1345715584, 641659}, NULL) = 0
gettimeofday({1345715584, 644084}, NULL) = 0
gettimeofday({1345715584, 651426}, NULL) = 0
gettimeofday({1345715584, 653729}, NULL) = 0
gettimeofday({1345715584, 658547}, NULL) = 0
gettimeofday({1345715584, 661051}, NULL) = 0
gettimeofday({1345715584, 663359}, NULL) = 0
gettimeofday({1345715584, 670568}, NULL) = 0
gettimeofday({1345715584, 673035}, NULL) = 0
gettimeofday({1345715584, 677895}, NULL) = 0
gettimeofday({1345715584, 680175}, NULL) = 0
gettimeofday({1345715584, 683301}, NULL) = 0
gettimeofday({1345715584, 690711}, NULL) = 0
gettimeofday({1345715584, 693226}, NULL) = 0
gettimeofday({1345715584, 816673}, NULL) = 0
gettimeofday({1345715584, 818715}, NULL) = 0
gettimeofday({1345715584, 820919}, NULL) = 0
gettimeofday({1345715584, 823142}, NULL) = 0
gettimeofday({1345715584, 825176}, NULL) = 0
gettimeofday({1345715584, 827280}, NULL) = 0
gettimeofday({1345715584, 829500}, NULL) = 0
gettimeofday({1345715584, 831725}, NULL) = 0
gettimeofday({1345715584, 834405}, NULL) = 0
gettimeofday({1345715584, 836502}, NULL) = 0
gettimeofday({1345715584, 838709}, NULL) = 0
gettimeofday({1345715584, 840929}, NULL) = 0
gettimeofday({1345715584, 842975}, NULL) = 0
gettimeofday({1345715584, 845020}, NULL) = 0
gettimeofday({1345715584, 847273}, NULL) = 0
gettimeofday({1345715584, 849493}, NULL) = 0
gettimeofday({1345715584, 851528}, NULL) = 0
gettimeofday({1345715584, 853578}, NULL) = 0
gettimeofday({1345715584, 855833}, NULL) = 0
gettimeofday({1345715584, 858754}, NULL) = 0
gettimeofday({1345715584, 860787}, NULL) = 0
gettimeofday({1345715584, 862836}, NULL) = 0
gettimeofday({1345715584, 865043}, NULL) = 0
gettimeofday({1345715584, 867306}, NULL) = 0
gettimeofday({1345715584, 869346}, NULL) = 0
gettimeofday({1345715584, 871402}, NULL) = 0
gettimeofday({1345715584, 873606}, NULL) = 0
gettimeofday({1345715584, 875877}, NULL) = 0
gettimeofday({1345715584, 877924}, NULL) = 0
gettimeofday({1345715584, 879976}, NULL) = 0
gettimeofday({1345715584, 882887}, NULL) = 0
gettimeofday({1345715584, 885110}, NULL) = 0
gettimeofday({1345715584, 887199}, NULL) = 0
gettimeofday({1345715584, 889240}, NULL) = 0
gettimeofday({1345715584, 891449}, NULL) = 0
gettimeofday({1345715584, 893671}, NULL) = 0
gettimeofday({1345715584, 895786}, NULL) = 0
gettimeofday({1345715584, 897833}, NULL) = 0
gettimeofday({1345715584, 900038}, NULL) = 0
gettimeofday({1345715584, 902263}, NULL) = 0
gettimeofday({1345715584, 904313}, NULL) = 0
gettimeofday({1345715584, 907112}, NULL) = 0
gettimeofday({1345715584, 913300}, NULL) = 0
gettimeofday({1345715584, 915561}, NULL) = 0
gettimeofday({1345715584, 917599}, NULL) = 0
gettimeofday({1345715584, 919634}, NULL) = 0
gettimeofday({1345715584, 921833}, NULL) = 0
gettimeofday({1345715584, 924043}, NULL) = 0
gettimeofday({1345715584, 926779}, NULL) = 0
gettimeofday({1345715584, 928834}, NULL) = 0
gettimeofday({1345715584, 931033}, NULL) = 0
gettimeofday({1345715584, 933244}, NULL) = 0
gettimeofday({1345715584, 935281}, NULL) = 0
gettimeofday({1345715584, 937373}, NULL) = 0
gettimeofday({1345715584, 939650}, NULL) = 0
uname({sys="Linux", node="sw200319", ...}) = 0
gettimeofday({1345715584, 949152}, NULL) = 0
open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "sys_linux.c:976:(get_version_spe"..., 60sys_linux.c:976:(get_version_specific_details)[23-09:53:04] ) = 60
write(2, "Linux kernel major=2 minor=6 pat"..., 38Linux kernel major=2 minor=6 patch=21
) = 38
gettimeofday({1345715584, 961102}, NULL) = 0
open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "sys_linux.c:1019:(get_version_sp"..., 61sys_linux.c:1019:(get_version_specific_details)[23-09:53:04] ) = 61
write(2, "hz=100 shift_hz=7 freq_scale=0.9"..., 98hz=100 shift_hz=7 freq_scale=0.99902439 nominal_tick=10000 slew_delta_tick=833 max_tick_bias=1000
) = 98
adjtimex(0xbefb3b80) = -1 EPERM (Operation not permitted)
gettimeofday({1345715584, 975010}, NULL) = 0
open("/etc/localtime", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "sys_linux.c:1039:(SYS_Linux_Init"..., 53sys_linux.c:1039:(SYS_Linux_Initialise)[23-09:53:04] ) = 53
write(2, "Fatal error : adjtimex() failed "..., 90Fatal error : adjtimex() failed at sys_linux.c:1039, errno: 2 (No such file or directory)
) = 90
exit_group(0) = ?
Process 5851 detached