Occasional crash in s6-rc-init / s6rc_servicedir_manage()

From: Rasmus Villemoes <rasmus.villemoes_at_prevas.dk>
Date: Tue, 26 Sep 2017 13:50:20 +0200

I've at least twice have s6-rc-init crash due to an assert fail in
glibc. On the first occasion, I got

*** Error in `s6-rc-init': free(): invalid next size (fast): 0x0057e080 ***
Aborted

while the second time, where I was monitoring with strace, I got

*** Error in `s6-rc-init': realloc(): invalid pointer: 0x009c9090 ***
Aborted

I'm not sure they're from the same bug. From the strace, I know that the
second one happened in the loop in s6rc_servicedir_manage() [so it is
not related to the rm_rf use-after-free bug, because that's much earlier
in s6-rc-init], after the two internal and 1.5 of the "user-defined"
services have been handled (empty lines added to delineate each pass
through the loop):

mkdir("/run/rc/servicedirs/s6rc-oneshot-runner/supervise", 0700) = 0
open("/run/rc/servicedirs/s6rc-oneshot-runner/supervise/lock",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 7
fcntl64(7, F_GETFD) = 0
fcntl64(7, F_SETFD, FD_CLOEXEC) = 0
flock(7, LOCK_EX) = 0
open("/run/rc/servicedirs/s6rc-oneshot-runner/supervise/control",
O_WRONLY|O_NONBLOCK) = -1 ENOENT (No such file or directory)
open("/run/rc/servicedirs/s6rc-oneshot-runner/down",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 8
utimensat(8, NULL, NULL, 0) = 0
close(8) = 0
umask(000) = 022
mkdir("/run/rc/servicedirs/s6rc-oneshot-runner/event", 0700) = 0
umask(022) = 000
chown32("/run/rc/servicedirs/s6rc-oneshot-runner/event", -1, 0) = 0
chmod("/run/rc/servicedirs/s6rc-oneshot-runner/event", 03730) = 0
ppoll([{fd=4, events=POLLOUT}], 1, NULL, NULL, 8) = 1 ([{fd=4,
revents=POLLOUT}])
sendmsg(4, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="\0\0\0?\0\0", iov_len=6},
{iov_base="\0\0L\0\0\0\0\0\0\0-\0\0\0\1/run/rc/servicedi"...,
iov_len=63}], msg_iovlen=2, msg_controllen=0, msg_flags=0},
MSG_NOSIGNAL) = 69
recvmsg(4, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="\0\0\0\1\0\0\0", iov_len=2026}, {iov_base="",
iov_len=21}], msg_iovlen=2, msg_controllen=0,
msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_WAITALL|MSG_CMSG_CLOEXEC) = 7
recvmsg(4, {msg_namelen=0}, MSG_DONTWAIT|MSG_WAITALL|MSG_CMSG_CLOEXEC) =
-1 EAGAIN (Resource temporarily unavailable)
close(7) = 0
symlink("/run/rc/servicedirs/s6rc-oneshot-runner",
"/run/rc/scandir/s6rc-oneshot-runner") = 0

mkdir("/run/rc/servicedirs/s6rc-fdholder/supervise", 0700) = 0
open("/run/rc/servicedirs/s6rc-fdholder/supervise/lock",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 7
fcntl64(7, F_GETFD) = 0
fcntl64(7, F_SETFD, FD_CLOEXEC) = 0
flock(7, LOCK_EX) = 0
open("/run/rc/servicedirs/s6rc-fdholder/supervise/control",
O_WRONLY|O_NONBLOCK) = -1 ENOENT (No such file or directory)
open("/run/rc/servicedirs/s6rc-fdholder/down",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 8
utimensat(8, NULL, NULL, 0) = 0
close(8) = 0
umask(000) = 022
mkdir("/run/rc/servicedirs/s6rc-fdholder/event", 0700) = 0
umask(022) = 000
chown32("/run/rc/servicedirs/s6rc-fdholder/event", -1, 0) = 0
chmod("/run/rc/servicedirs/s6rc-fdholder/event", 03730) = 0
ppoll([{fd=4, events=POLLOUT}], 1, NULL, NULL, 8) = 1 ([{fd=4,
revents=POLLOUT}])
sendmsg(4, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="\0\0\0009\0\0", iov_len=6},
{iov_base="\0\1L\0\0\0\0\0\0\0'\0\0\0\1/run/rc/servicedi"...,
iov_len=57}], msg_iovlen=2, msg_controllen=0, msg_flags=0},
MSG_NOSIGNAL) = 63
recvmsg(4, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="\0\0\0\1\0\0\0", iov_len=2019}, {iov_base="",
iov_len=28}], msg_iovlen=2, msg_controllen=0,
msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_WAITALL|MSG_CMSG_CLOEXEC) = 7
recvmsg(4, {msg_namelen=0}, MSG_DONTWAIT|MSG_WAITALL|MSG_CMSG_CLOEXEC) =
-1 EAGAIN (Resource temporarily unavailable)
close(7) = 0
symlink("/run/rc/servicedirs/s6rc-fdholder",
"/run/rc/scandir/s6rc-fdholder") = 0

mkdir("/run/rc/servicedirs/app-svscan/supervise", 0700) = 0
open("/run/rc/servicedirs/app-svscan/supervise/lock",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 7
fcntl64(7, F_GETFD) = 0
fcntl64(7, F_SETFD, FD_CLOEXEC) = 0
flock(7, LOCK_EX) = 0
open("/run/rc/servicedirs/app-svscan/supervise/control",
O_WRONLY|O_NONBLOCK) = -1 ENOENT (No such file or directory)
open("/run/rc/servicedirs/app-svscan/down", O_WRONLY|O_CREAT|O_NONBLOCK,
0666) = 8
utimensat(8, NULL, NULL, 0) = 0
close(8) = 0
umask(000) = 022
mkdir("/run/rc/servicedirs/app-svscan/event", 0700) = 0
umask(022) = 000
chown32("/run/rc/servicedirs/app-svscan/event", -1, 0) = 0
chmod("/run/rc/servicedirs/app-svscan/event", 03730) = 0
ppoll([{fd=4, events=POLLOUT}], 1, NULL, NULL, 8) = 1 ([{fd=4,
revents=POLLOUT}])
sendmsg(4, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="\0\0\0006\0\0", iov_len=6},
{iov_base="\0\2L\0\0\0\0\0\0\0$\0\0\0\1/run/rc/servicedi"...,
iov_len=54}], msg_iovlen=2, msg_controllen=0, msg_flags=0},
MSG_NOSIGNAL) = 60
recvmsg(4, {msg_name=NULL, msg_namelen=0,
msg_iov=[{iov_base="\0\0\0\1\0\0\0", iov_len=2012}, {iov_base="",
iov_len=35}], msg_iovlen=2, msg_controllen=0,
msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_WAITALL|MSG_CMSG_CLOEXEC) = 7
recvmsg(4, {msg_namelen=0}, MSG_DONTWAIT|MSG_WAITALL|MSG_CMSG_CLOEXEC) =
-1 EAGAIN (Resource temporarily unavailable)
close(7) = 0
symlink("/run/rc/servicedirs/app-svscan", "/run/rc/scandir/app-svscan") = 0

mkdir("/run/rc/servicedirs/app-svscan-log/supervise", 0700) = 0
open("/run/rc/servicedirs/app-svscan-log/supervise/lock",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 7
fcntl64(7, F_GETFD) = 0
fcntl64(7, F_SETFD, FD_CLOEXEC) = 0
flock(7, LOCK_EX) = 0
open("/run/rc/servicedirs/app-svscan-log/supervise/control",
O_WRONLY|O_NONBLOCK) = -1 ENOENT (No such file or directory)
open("/run/rc/servicedirs/app-svscan-log/down",
O_WRONLY|O_CREAT|O_NONBLOCK, 0666) = 8
utimensat(8, NULL, NULL, 0) = 0
close(8) = 0
umask(000) = 022
mkdir("/run/rc/servicedirs/app-svscan-log/event", 0700) = 0
umask(022) = 000
chown32("/run/rc/servicedirs/app-svscan-log/event", -1, 0) = 0
chmod("/run/rc/servicedirs/app-svscan-log/event", 03730) = 0

open("/dev/tty", O_RDWR|O_NOCTTY|O_NONBLOCK) = -1 ENXIO (No such device
or address)
writev(2, [{iov_base="*** Error in `", iov_len=14},
{iov_base="s6-rc-init", iov_len=10}, {iov_base="': ", iov_len=3},
{iov_base="realloc(): invalid pointer", iov_len=26}, {iov_base=": 0x",
iov_len=4}, {iov_base="009c9090", iov_len=8}, {iov_base=" ***\n",
iov_len=5}], 7*** Error in `s6-rc-init': realloc(): invalid pointer:
0x009c9090 ***
) = 70
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x76f69000
open("/lib/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file
or directory)
open("/usr/lib/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 8
read(8,
"\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0X\315\0\0004\0\0\0"...,
512) = 512
mmap2(NULL, 2097152, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE,
-1, 0) = 0x76b56000
munmap(0x76b56000, 696320) = 0
munmap(0x76d00000, 352256) = 0
mprotect(0x76c00000, 135168, PROT_READ|PROT_WRITE) = 0
fstat64(8, {st_mode=S_IFREG|0644, st_size=114332, ...}) = 0
mmap2(NULL, 178572, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 8,
0) = 0x76d2a000
mprotect(0x76d46000, 61440, PROT_NONE) = 0
mmap2(0x76d55000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 8, 0x1b000) = 0x76d55000
close(8) = 0
futex(0x76ece590, FUTEX_WAKE_PRIVATE, 2147483647) = 0
rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
getpid() = 312
gettid() = 312
tgkill(312, 312, SIGABRT) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=312, si_uid=0} ---
Aborted
/ # +++ killed by SIGABRT +++

For some reason I can't reproduce this anymore, but it seems that there
must be a bug lurking somewhere.

This is with linux kernel 4.1.37, glibc 2.24, and all the latest skaware
releases.

-- 
Rasmus Villemoes
Software Developer
Prevas A/S
Hedeager 1
DK-8200 Aarhus N
+45 51210274
rasmus.villemoes_at_prevas.dk
www.prevas.dk
Received on Tue Sep 26 2017 - 11:50:20 UTC

This archive was generated by hypermail 2.3.0 : Sun May 09 2021 - 19:38:49 UTC