Uncategorized

Logrotate lockup causing 100% CPU usage

Okay, I’ve been dealing with this problem FOREVER. On one box, my syslog-ng server, logrotate consumes 100% CPU for several hours, but will eventually finish. For this whole time, I’ve been thinking it’s a bad logrotate script, but I’ve never been able to isolate it. My recent attempt to isolate the problem, I used strace to see what was going on.


strace -o mytrace -fF /usr/sbin/logrotate -d /etc/logrotate.conf

I immediately saw it looping on /etc/localtime. Here is a partial output of my strace:

Okay, I’ve been dealing with this problem FOREVER. On one box, my syslog-ng server, logrotate consumes 100% CPU for several hours, but will eventually finish. For this whole time, I’ve been thinking it’s a bad logrotate script, but I’ve never been able to isolate it. My recent attempt to isolate the problem, I used strace to see what was going on.


strace -o mytrace -fF /usr/sbin/logrotate -d /etc/logrotate.conf

I immediately saw it looping on /etc/localtime. Here is a partial output of my strace:


8776 execve("/usr/sbin/logrotate", ["/usr/sbin/logrotate", "-d", "/etc/logrotate.conf"], [/* 45 vars */]) = 0
8776 brk(0) = 0x8054000
8776 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
8776 open("/etc/ld.so.cache", O_RDONLY) = 3
8776 fstat64(3, {st_mode=S_IFREG|0644, st_size=117732, ...}) = 0
8776 mmap2(NULL, 117732, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f1d000
8776 close(3) = 0
8776 open("/usr/lib/libpopt.so.0", O_RDONLY) = 3
8776 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0 \22\0\0004\0\0\0,"..., 512) = 512
8776 fstat64(3, {st_mode=S_IFREG|0755, st_size=43540, ...}) = 0
8776 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f1c000
8776 mmap2(NULL, 46156, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f10000
8776 mmap2(0xb7f1b000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa) = 0xb7f1b000
8776 close(3) = 0
8776 open("/lib/libc.so.6", O_RDONLY) = 3
8776 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0@a\1\0004\0\0\0\244"..., 512) = 512
8776 fstat64(3, {st_mode=S_IFREG|0755, st_size=1237276, ...}) = 0
8776 mmap2(NULL, 1242576, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7de0000
8776 mmap2(0xb7f0a000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12a) = 0xb7f0a000
8776 mmap2(0xb7f0d000, 9680, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f0d000
8776 close(3) = 0
8776 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7ddf000
8776 set_thread_area({entry_number:-1 -> 6, base_addr:0xb7ddf6c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1})
= 0
8776 mprotect(0xb7f0a000, 8192, PROT_READ) = 0
8776 mprotect(0xb7f54000, 4096, PROT_READ) = 0
8776 munmap(0xb7f1d000, 117732) = 0
8776 brk(0) = 0x8054000
8776 brk(0x8075000) = 0x8075000
8776 open("/etc/popt", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
8776 open("/root/.popt", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
8776 stat64("/etc/logrotate.conf", {st_mode=S_IFREG|0644, st_size=735, ...}) = 0
8776 open("/etc/logrotate.conf", O_RDONLY|O_LARGEFILE) = 3
8776 fstat64(3, {st_mode=S_IFREG|0644, st_size=735, ...}) = 0
8776 _llseek(3, 0, [735], SEEK_END) = 0
8776 _llseek(3, 0, [0], SEEK_SET) = 0
8776 read(3, "# $Header: /home/cvsroot/gentoo-x"..., 735) = 735
8776 close(3) = 0
8776 write(2, "reading config file /etc/logrotat"..., 40) = 40
8776 write(2, "including /etc/logrotate.d\n"..., 27) = 27
8776 stat64("/etc/logrotate.d", {st_mode=S_IFDIR|0755, st_size=48, ...}) = 0
8776 open(".", O_RDONLY|O_LARGEFILE) = 3
8776 open("/etc/logrotate.d", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 4
8776 fstat64(4, {st_mode=S_IFDIR|0755, st_size=48, ...}) = 0
8776 fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
8776 getdents64(4, /* 2 entries */, 4096) = 48
8776 getdents64(4, /* 0 entries */, 4096) = 0
8776 close(4) = 0
8776 time(NULL) = 1227019409
8776 stat64("/var/lib/logrotate.status", {st_mode=S_IFREG|0644, st_size=18735247, ...}) = 0
8776 open("/var/lib/logrotate.status", O_RDONLY|O_LARGEFILE) = 4
8776 fstat64(4, {st_mode=S_IFREG|0644, st_size=18735247, ...}) = 0
8776 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f39000
8776 read(4, "logrotate state -- version 2\n\"/va"..., 4096) = 4096
8776 open("/etc/localtime", O_RDONLY) = 5
8776 fstat64(5, {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 fstat64(5, {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f38000
8776 read(5, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0\0"..., 4096) = 2427
8776 close(5) = 0
8776 munmap(0xb7f38000, 4096) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0
8776 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2427, ...}) = 0

After some googling on ‘logrotate stat64(“/etc/localtime”,‘, I came across this fantastic thread. The problem was exactly like mine, except that I’m using Gentoo-Sources on that box, not hardened. They also originally thought it was grsec related, which I don’t use on this box. The last thread was the solution. The original poster found that he had a buggy 15M /var/lib/logrotate.status! Sure enough, I checked my box, and my file is 18Ms. I simply deleted the file, and things are back to normal.