chiark / gitweb /
systemd-bootchart: Prevent closing random file descriptors
authorAlexander Sverdlin <alexander.sverdlin@gmail.com>
Sun, 29 Mar 2015 18:41:56 +0000 (20:41 +0200)
committerDaniel Mack <daniel@zonque.org>
Sun, 29 Mar 2015 23:08:05 +0000 (01:08 +0200)
commit9964a9eb7b18d6ad172a7921cf88efabde05d121
tree063667d969bef12bf77bd21f7690365531b771f1
parent333e07b793836442dc320c60d5ae66f95c4489e1
systemd-bootchart: Prevent closing random file descriptors

If the kernel has no CONFIG_SCHED_DEBUG option set, systemd-bootchart produces
empty .svg file. The reason for this is very fragile file descriptor logic in
log_sample() and main() (/* do some cleanup, close fd's */ block). There are
many places where file descriptors are closed on failure (missing SCHED_DEBUG
provokes it), but there are several problems with it:
 - following iterations in the loop see that the descriptor is non zero and do
   not open the corresponding file again;
 - "some cleanup" code closes already closed files and the descriptors are reused
   already, in particular for resulting .svg file;
 - static "vmstat" and "schedstat" variables in log_sample() made the situation
   even worse.

These are the strace fragments:

[...]
close(7)                                = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
pread(7, 0xbea60a2c, 4095, 0)           = -1 EBADF (Bad file descriptor)
close(7)                                = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
pread(7, 0xbea60a2c, 4095, 0)           = -1 EBADF (Bad file descriptor)
close(7)                                = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
getdents64(4, /* 0 entries */, 32768)   = 0
clock_gettime(CLOCK_MONOTONIC, {24, 783843501}) = 0
nanosleep({0, 5221792}, NULL)           = 0
clock_gettime(CLOCK_MONOTONIC, {24, 789726835}) = 0
lseek(4, 0, SEEK_SET)                   = 0
pread(5, "nr_free_pages 52309\nnr_alloc_bat"..., 4095, 0) = 685
pread(6, "version 15\ntimestamp 4294939775\n"..., 4095, 0) = 86
getdents64(4, /* 99 entries */, 32768)  = 2680
pread(7, 0xbea60a2c, 4095, 0)           = -1 EBADF (Bad file descriptor)
close(7)                                = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
pread(8, 0xbea60a2c, 4095, 0)           = -1 EBADF (Bad file descriptor)
close(8)                                = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
pread(9, 0xbea60a2c, 4095, 0)           = -1 EBADF (Bad file descriptor)
close(9)                                = -1 EBADF (Bad file descriptor)
[...]

where it obviously tries to close same and reused decriptors many times, also
passing return code "-1" instead of descriptor...

[...]
close(7)                                = -1 EBADF (Bad file descriptor)
close(-1)                               = -1 EBADF (Bad file descriptor)
pipe2([7, 8], O_CLOEXEC)                = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb6fd0068) = 192
close(8)                                = 0
fcntl64(7, F_SETFD, 0)                  = 0
fstat64(7, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6fd2000
read(7, "[    0.074507] calling  vfp_init"..., 4096) = 4096
[...]
read(7, "s)\n[    6.228910] UBIFS: reserve"..., 4096) = 4096
read(7, "trary Executable File Formats Fi"..., 4096) = 1616
read(7, "", 4096)                       = 0
close(7)                                = 0
wait4(192, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 192
src/bootchart/bootchart.c
src/bootchart/store.c