GNOME Bugzilla – Bug 167198
clock-applet: excessive CPU usage due to constant polling for TZ changes
Last modified: 2005-02-13 08:42:36 UTC
Version details: gnome-panel 2.8.2-2 Distribution/Version: Debian unstable Problem behavior: clock-applet is the 7th worst CPU hog on my system. It has used more CPU time than kjournald, kswapd, the disk interrupt, metacity and xscreensaver combined. Expected behavior: clock-applet should use a negligible amount of CPU. Additional info: 2587 root 16 0 94012 23m 6172 R 26.8 5.4 290:44.36 XFree86 3957 rlrevell 15 0 27820 22m 8196 S 10.5 5.0 60:20.73 gtk-gnutella 6227 rlrevell 15 0 109m 37m 20m S 10.5 8.4 3:42.90 firefox-bin 6059 rlrevell 15 0 143m 61m 15m S 0.3 13.9 3:03.74 evolution 2 root 5 -10 0 0 0 S 0.7 0.0 3:01.45 ksoftirqd/0 1470 root -45 -5 0 0 0 S 0.7 0.0 2:53.46 IRQ 11 3039 rlrevell 15 0 18332 9348 7104 S 0.3 2.1 2:23.91 clock-applet <--** 6502 root 17 0 37596 35m 1256 S 0.0 8.0 1:03.75 dselect 680 root -48 -5 0 0 0 S 0.0 0.0 1:02.80 IRQ 15 698 root 15 0 0 0 0 S 0.0 0.0 0:16.78 kjournald 64 root 16 0 0 0 0 S 0.7 0.0 0:16.13 kswapd0 2990 rlrevell 15 0 11900 7840 6024 S 2.3 1.7 0:15.92 metacity 2970 rlrevell 15 0 3520 1684 1388 S 0.0 0.4 0:13.66 xscreensaver strace output reveals the problem: Process 3039 attached - interrupt to quit gettimeofday({1108240686, 948268}, NULL) = 0 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240686, 948691}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 800) = 0 gettimeofday({1108240687, 749728}, NULL) = 0 time([1108240687]) = 1108240687 time(NULL) = 1108240687 open("/usr/share/zoneinfo/Universal", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=56, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0"..., 4096) = 56 close(34) = 0 munmap(0xb731b000, 4096) = 0 time([1108240687]) = 1108240687 open("/etc/localtime", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0"..., 4096) = 1267 close(34) = 0 munmap(0xb731b000, 4096) = 0 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240687, 755393}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 0) = 0 write(3, "5\20\4\0l\254\201\1\37\0\200\1g\0\30\0;\3\5\0#\0\200\1"..., 356) = 356 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240687, 760021}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 990) = 0 gettimeofday({1108240688, 752320}, NULL) = 0 time([1108240688]) = 1108240688 time(NULL) = 1108240688 open("/usr/share/zoneinfo/Universal", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=56, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0"..., 4096) = 56 close(34) = 0 munmap(0xb731b000, 4096) = 0 time([1108240688]) = 1108240688 open("/etc/localtime", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0"..., 4096) = 1267 close(34) = 0 munmap(0xb731b000, 4096) = 0 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240688, 763126}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 0) = 0 write(3, "5\20\4\0n\254\201\1\37\0\200\1g\0\30\0;\3\5\0#\0\200\1"..., 356) = 356 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240688, 767356}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN, revents=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 985) = 1 ioctl(3, FIONREAD, [32]) = 0 read(3, "n\2\334Aw\21G\3\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0 "..., 32) = 32 gettimeofday({1108240689, 803363}, NULL) = 0 write(3, "\226\4\2\0\0\1\201\1", 8) = 8 read(3, "n\2\334A\355\21G\3\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 32) = 32 read(3, 0xbffff4a0, 32) = -1 EAGAIN (Resource temporarily unavailable) select(4, [3], NULL, NULL, NULL) = 1 (in [3]) read(3, "\1\1\335A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 32) = 32 time([1108240689]) = 1108240689 time(NULL) = 1108240689 open("/usr/share/zoneinfo/Universal", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=56, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0"..., 4096) = 56 close(34) = 0 munmap(0xb731b000, 4096) = 0 time([1108240689]) = 1108240689 open("/etc/localtime", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0"..., 4096) = 1267 close(34) = 0 munmap(0xb731b000, 4096) = 0 gettimeofday({1108240689, 927167}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 0) = 0 write(3, "\226\4\2\0\0\1\201\1", 8) = 8 read(3, 0xbffff4a0, 32) = -1 EAGAIN (Resource temporarily unavailable) select(4, [3], NULL, NULL, NULL) = 1 (in [3]) read(3, "\1\1\336A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 32) = 32 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240689, 974816}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 0) = 0 write(3, "5\20\4\0p\254\201\1\37\0\200\1g\0\30\0;\3\5\0#\0\200\1"..., 356) = 356 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240689, 977210}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 827) = 0 gettimeofday({1108240690, 811719}, NULL) = 0 time([1108240690]) = 1108240690 time(NULL) = 1108240690 open("/usr/share/zoneinfo/Universal", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=56, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0"..., 4096) = 56 close(34) = 0 munmap(0xb731b000, 4096) = 0 time([1108240690]) = 1108240690 open("/etc/localtime", O_RDONLY) = 34 fstat64(34, {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb731b000 read(34, "TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0"..., 4096) = 1267 close(34) = 0 munmap(0xb731b000, 4096) = 0 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240690, 817995}, NULL) = 0 poll([{fd=18, events=POLLIN}, {fd=3, events=POLLIN}, {fd=23, events=POLLIN|POLLPRI}, {fd=25, events=POLLIN}, {fd=27, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN|POLLPRI}, {fd=29, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=30, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=33, events=POLLIN|POLLPRI}], 11, 0) = 0 write(3, "5\20\4\0r\254\201\1\37\0\200\1g\0\30\0;\3\5\0#\0\200\1"..., 356) = 356 ioctl(3, FIONREAD, [0]) = 0 gettimeofday({1108240690, 822486}, NULL) = 0 So it's opening, reading, and closing /etc/localtime and /usr/share/zoneinfo/Universal every second to see if the time zone has changed. Horrible. I am pretty sure there are better ways to detect changes to a file than opening, reading, and closing it every second. At the very least you could stat() it and only read it if it's been touched. Also I don't see why the clock-applet should have to do *anything* every second if it's not configured to display the seconds.
The clock applet is not doing this. Maybe it's because of evolution-data-server...
So you are saying that even though process 3039 is the clock applet, and stracing process 3039 gives the above output, and top shows excessive CPU usage by the clock applet, that some other process is making all those system calls? Doesn't strace $PID trace all the system calls by $PID? Am I missing something?
OK, I killed all evolution related processes including evolution-data-server and evolution-alarm-notify. Exact same results. Sorry, but I think you are wrong. It's definitely the clock applet doing this. I suspect the "fix" for this bug introduced the problem: https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=104046 I also filed a Debian bug report: http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=292269
Sorry, you're right. clock-applet does not normally do this. The offending behavior is due to a Debian patch(!), specifically: debian/patches/04_clockapplet_reload_timezone.patch --- applets/clock/clock.c.orig 2004-12-08 18:52:20.000000000 +0100 +++ applets/clock/clock.c 2004-12-09 21:28:33.000000000 +0100 @@ -330,6 +330,14 @@ char date[256], hour[256]; char *utf8, *loc; + /* Setting "TZ" environment to another location say "" */ + setenv("TZ","",1); + time_t tmptime_t=time(NULL); /* These variables are not*/ + struct tm *tmtmp=localtime(&tmptime_t);/* using further */ + /* Resetting "TZ" to original location "/etc/localtime" + then only it can refresh according to the New timezone */ + setenv("TZ", "/etc/localtime", 1); + time (&cd->current_time); if (cd->gmt_time) God, what a horrible hack. And sure enough, this rubbish gets executed once per second. I am shocked that Debian would introduce something this bogus. Sorry for the spurious bug report. I will take it up with the Debian maintainers.
Thanks for looking at the problem in depth. I suppose Debian maintainers made the patch so the clock knows when the timezone changes. This is not the right fix. You should probably mention that newer glibc (2.3.3, I think) fix this behaviour for all programs...