Just this past week, we had a time change and that is when I started to notice higher than normal load averages on my Arch Linux box. I use Cacti to monitor the load averages and bandwidth of my Internet connection in order to get an idea of how much I actually download and upload each month. Earlier this year, I had to get a wireless Internet connection through Alltel and I wasn’t sure if they had a cap on bandwidth. There appears to be no 5GB cap on Alltel’s services since I average about 30GB of traffic monthly. Most other carriers seem to mention a 5GB cap for monthly bandwidth.
A few weeks ago this same issue happened and I ended up fixing it by generating a graph manually as root. This meant there was a permissions error somewhere but I never bothered to figure out exactly the cause of the issue. I figured it was just a fluke since my time got skewed by several hours because of the new rc.conf that was released a month or two ago. My system clock was set to local but the update caused it to get pushed ahead to GMT. This issue won’t be happening to you if you generate your graphs as root (same on you though). Take a look at your process list and see if you get anything that resembles what I have below.
http 14721 14019 34 09:14 ? 00:00:02 /usr/bin/rrdtool graph - --imgformat=PNG --start=-60 --end=-20 --title=Localhost - Load Average --rigid --base=1000 --height=120 --width=500 --alt-autoscale-max --lower-limit=0 --units-exponent=0 --vertical-label=processes in the run queue --slope-mode --font TITLE:12: --font AXIS:8: --font LEGEND:10: --font UNIT:8: DEF:a=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_1min:AVERAGE DEF:b=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_5min:AVERAGE DEF:c=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_15min:AVERAGE CDEF:cdefg=TIME,1257603260,GT,a,a,UN,0,a,IF,IF,TIME,1257603260,GT,b,b,UN,0,b,IF,IF,TIME,1257603260,GT,c,c,UN,0,c,IF,IF,+,+ AREA:a#EACC00FF:1 Minute Average GPRINT:a:LAST: Current\:%8.2lf\n AREA:b#EA8F00FF:5 Minute Average:STACK GPRINT:b:LAST: Current\:%8.2lf\n AREA:c#FF0000FF:15 Minute Average:STACK GPRINT:c:LAST:Current\:%8.2lf\n LINE1:cdefg#000000FF: http 14722 14021 33 09:14 ? 00:00:02 /usr/bin/rrdtool graph - --imgformat=PNG --start=-900 --end=-20 --title=Localhost - Load Average --rigid --base=1000 --height=120 --width=500 --alt-autoscale-max --lower-limit=0 --units-exponent=0 --vertical-label=processes in the run queue --slope-mode --font TITLE:12: --font AXIS:8: --font LEGEND:10: --font UNIT:8: DEF:a=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_1min:AVERAGE DEF:b=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_5min:AVERAGE DEF:c=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_15min:AVERAGE CDEF:cdefg=TIME,1257603260,GT,a,a,UN,0,a,IF,IF,TIME,1257603260,GT,b,b,UN,0,b,IF,IF,TIME,1257603260,GT,c,c,UN,0,c,IF,IF,+,+ AREA:a#EACC00FF:1 Minute Average GPRINT:a:LAST: Current\:%8.2lf\n AREA:b#EA8F00FF:5 Minute Average:STACK GPRINT:b:LAST: Current\:%8.2lf\n AREA:c#FF0000FF:15 Minute Average:STACK GPRINT:c:LAST:Current\:%8.2lf\n LINE1:cdefg#000000FF: http 14724 14715 32 09:14 ? 00:00:02 /usr/bin/rrdtool graph - --imgformat=PNG --start=-3600 --end=-20 --title=Localhost - Load Average --rigid --base=1000 --height=120 --width=500 --alt-autoscale-max --lower-limit=0 --units-exponent=0 --vertical-label=processes in the run queue --slope-mode --font TITLE:12: --font AXIS:8: --font LEGEND:10: --font UNIT:8: DEF:a=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_1min:AVERAGE DEF:b=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_5min:AVERAGE DEF:c=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_15min:AVERAGE CDEF:cdefg=TIME,1257603260,GT,a,a,UN,0,a,IF,IF,TIME,1257603260,GT,b,b,UN,0,b,IF,IF,TIME,1257603260,GT,c,c,UN,0,c,IF,IF,+,+ AREA:a#EACC00FF:1 Minute Average GPRINT:a:LAST: Current\:%8.2lf\n AREA:b#EA8F00FF:5 Minute Average:STACK GPRINT:b:LAST: Current\:%8.2lf\n AREA:c#FF0000FF:15 Minute Average:STACK GPRINT:c:LAST:Current\:%8.2lf\n LINE1:cdefg#000000FF: http 14726 14714 31 09:14 ? 00:00:02 /usr/bin/rrdtool graph - --imgformat=PNG --start=-1800 --end=-20 --title=Localhost - Load Average --rigid --base=1000 --height=120 --width=500 --alt-autoscale-max --lower-limit=0 --units-exponent=0 --vertical-label=processes in the run queue --slope-mode --font TITLE:12: --font AXIS:8: --font LEGEND:10: --font UNIT:8: DEF:a=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_1min:AVERAGE DEF:b=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_5min:AVERAGE DEF:c=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_15min:AVERAGE CDEF:cdefg=TIME,1257603260,GT,a,a,UN,0,a,IF,IF,TIME,1257603260,GT,b,b,UN,0,b,IF,IF,TIME,1257603260,GT,c,c,UN,0,c,IF,IF,+,+ AREA:a#EACC00FF:1 Minute Average GPRINT:a:LAST: Current\:%8.2lf\n AREA:b#EA8F00FF:5 Minute Average:STACK GPRINT:b:LAST: Current\:%8.2lf\n AREA:c#FF0000FF:15 Minute Average:STACK GPRINT:c:LAST:Current\:%8.2lf\n LINE1:cdefg#000000FF: http 14729 14716 32 09:14 ? 00:00:02 /usr/bin/rrdtool graph - --imgformat=PNG --start=-7200 --end=-20 --title=Localhost - Load Average --rigid --base=1000 --height=120 --width=500 --alt-autoscale-max --lower-limit=0 --units-exponent=0 --vertical-label=processes in the run queue --slope-mode --font TITLE:12: --font AXIS:8: --font LEGEND:10: --font UNIT:8: DEF:a=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_1min:AVERAGE DEF:b=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_5min:AVERAGE DEF:c=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_15min:AVERAGE CDEF:cdefg=TIME,1257603260,GT,a,a,UN,0,a,IF,IF,TIME,1257603260,GT,b,b,UN,0,b,IF,IF,TIME,1257603260,GT,c,c,UN,0,c,IF,IF,+,+ AREA:a#EACC00FF:1 Minute Average GPRINT:a:LAST: Current\:%8.2lf\n AREA:b#EA8F00FF:5 Minute Average:STACK GPRINT:b:LAST: Current\:%8.2lf\n AREA:c#FF0000FF:15 Minute Average:STACK GPRINT:c:LAST:Current\:%8.2lf\n LINE1:cdefg#000000FF: http 14730 14717 35 09:14 ? 00:00:02 /usr/bin/rrdtool graph - --imgformat=PNG --start=-300 --end=-20 --title=Localhost - Load Average --rigid --base=1000 --height=120 --width=500 --alt-autoscale-max --lower-limit=0 --units-exponent=0 --vertical-label=processes in the run queue --slope-mode --font TITLE:12: --font AXIS:8: --font LEGEND:10: --font UNIT:8: DEF:a=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_1min:AVERAGE DEF:b=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_5min:AVERAGE DEF:c=/srv/http/cacti/rra/localhost_load_1min_5.rrd:load_15min:AVERAGE CDEF:cdefg=TIME,1257603261,GT,a,a,UN,0,a,IF,IF,TIME,1257603261,GT,b,b,UN,0,b,IF,IF,TIME,1257603261,GT,c,c,UN,0,c,IF,IF,+,+ AREA:a#EACC00FF:1 Minute Average GPRINT:a:LAST: Current\:%8.2lf\n AREA:b#EA8F00FF:5 Minute Average:STACK GPRINT:b:LAST: Current\:%8.2lf\n AREA:c#FF0000FF:15 Minute Average:STACK GPRINT:c:LAST:Current\:%8.2lf\n LINE1:cdefg#000000FF:
Yikes! RRDtool is taking 2 seconds of CPU time to generate a PNG when it shouldn’t even be blinking an eye. Next I used strace to attach to the process and find out what it is doing.
munmap(0xb76f3000, 7396) = 0
stat64("/usr/share/fonts/100dpi/timR24-ISO8859-14.pcf.gz", {st_mode=S_IFREG|0644, st_size=6894, ...}) = 0
open("/usr/share/fonts/100dpi/timR24-ISO8859-14.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=6894, ...}) = 0
mmap2(NULL, 6894, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76f3000
close(4) = 0
munmap(0xb76f3000, 6894) = 0
stat64("/usr/share/fonts/100dpi/timR24-ISO8859-15.pcf.gz", {st_mode=S_IFREG|0644, st_size=7435, ...}) = 0
open("/usr/share/fonts/100dpi/timR24-ISO8859-15.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=7435, ...}) = 0
mmap2(NULL, 7435, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76f3000
close(4) = 0
munmap(0xb76f3000, 7435) = 0
stat64("/usr/share/fonts/100dpi/timR24-ISO8859-2.pcf.gz", {st_mode=S_IFREG|0644, st_size=6865, ...}) = 0
open("/usr/share/fonts/100dpi/timR24-ISO8859-2.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=6865, ...}) = 0
mmap2(NULL, 6865, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76f3000
close(4) = 0
munmap(0xb76f3000, 6865) = 0
stat64("/usr/share/fonts/100dpi/timR24-ISO8859-3.pcf.gz", {st_mode=S_IFREG|0644, st_size=6672, ...}) = 0
open("/usr/share/fonts/100dpi/timR24-ISO8859-3.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=6672, ...}) = 0
mmap2(NULL, 6672, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76f3000
close(4) = 0
munmap(0xb76f3000, 6672) = 0
stat64("/usr/share/fonts/100dpi/timR24-ISO8859-4.pcf.gz", {st_mode=S_IFREG|0644, st_size=6980, ...}) = 0
open("/usr/share/fonts/100dpi/timR24-ISO8859-4.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=6980, ...}) = 0
mmap2(NULL, 6980, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76f3000
close(4) = 0
munmap(0xb76f3000, 6980) = 0
stat64("/usr/share/fonts/100dpi/timR24-ISO8859-9.pcf.gz", {st_mode=S_IFREG|0644, st_size=7357, ...}) = 0
open("/usr/share/fonts/100dpi/timR24-ISO8859-9.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=7357, ...}) = 0
mmap2(NULL, 7357, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76f3000
close(4) = 0
munmap(0xb76f3000, 7357) = 0
stat64("/usr/share/fonts/100dpi/timR24.pcf.gz", {st_mode=S_IFREG|0644, st_size=27753, ...}) = 0
open("/usr/share/fonts/100dpi/timR24.pcf.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=27753, ...}) = 0
mmap2(NULL, 27753, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb76ee000
close(4) = 0
munmap(0xb76ee000, 27753) = 0
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f15000
access("/var/cache/fontconfig", W_OK) = -1 EACCES (Permission denied)
access("/var/cache/fontconfig", F_OK) = 0
access("//.fontconfig", W_OK) = -1 ENOENT (No such file or directory)
access("//.fontconfig", F_OK) = -1 ENOENT (No such file or directory)
access("/", F_OK) = 0
mkdir("//.fontconfig", 0777) = -1 EACCES (Permission denied)
close(3)
munmap(0xb6f14000, 453) = 0
stat64("/usr/share/fonts/encodings/large/jisx0208.1990-0.enc.gz", {st_mode=S_IFREG|0644, st_size=72764, ...}) = 0
open("/usr/share/fonts/encodings/large/jisx0208.1990-0.enc.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=72764, ...}) = 0
mmap2(NULL, 72764, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb6f03000
close(4) = 0
open("/usr/share/fonts/encodings/large/._jisx0208.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/%jisx0208.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.AppleDouble/jisx0208.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/jisx0208.1990-0.enc.gz/..namedfork/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/jisx0208.1990-0.enc.gz/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/resource.frk/jisx0208.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.resource/jisx0208.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
munmap(0xb6f03000, 72764) = 0
stat64("/usr/share/fonts/encodings/large/jisx0212.1990-0.enc.gz", {st_mode=S_IFREG|0644, st_size=23852, ...}) = 0
open("/usr/share/fonts/encodings/large/jisx0212.1990-0.enc.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=23852, ...}) = 0
mmap2(NULL, 23852, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb6f0f000
close(4) = 0
open("/usr/share/fonts/encodings/large/._jisx0212.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/%jisx0212.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.AppleDouble/jisx0212.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/jisx0212.1990-0.enc.gz/..namedfork/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/jisx0212.1990-0.enc.gz/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/resource.frk/jisx0212.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.resource/jisx0212.1990-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
munmap(0xb6f0f000, 23852) = 0
stat64("/usr/share/fonts/encodings/large/ksc5601.1987-0.enc.gz", {st_mode=S_IFREG|0644, st_size=34763, ...}) = 0
open("/usr/share/fonts/encodings/large/ksc5601.1987-0.enc.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=34763, ...}) = 0
mmap2(NULL, 34763, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb6f0c000
close(4) = 0
open("/usr/share/fonts/encodings/large/._ksc5601.1987-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/%ksc5601.1987-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.AppleDouble/ksc5601.1987-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/ksc5601.1987-0.enc.gz/..namedfork/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/ksc5601.1987-0.enc.gz/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/resource.frk/ksc5601.1987-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.resource/ksc5601.1987-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
munmap(0xb6f0c000, 34763) = 0
stat64("/usr/share/fonts/encodings/large/ksc5601.1992-3.enc.gz", {st_mode=S_IFREG|0644, st_size=32497, ...}) = 0
open("/usr/share/fonts/encodings/large/ksc5601.1992-3.enc.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=32497, ...}) = 0
mmap2(NULL, 32497, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb6f0d000
close(4) = 0
open("/usr/share/fonts/encodings/large/._ksc5601.1992-3.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/%ksc5601.1992-3.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.AppleDouble/ksc5601.1992-3.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/ksc5601.1992-3.enc.gz/..namedfork/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/ksc5601.1992-3.enc.gz/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/resource.frk/ksc5601.1992-3.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.resource/ksc5601.1992-3.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
munmap(0xb6f0d000, 32497) = 0
stat64("/usr/share/fonts/encodings/large/sun.unicode.india-0.enc.gz", {st_mode=S_IFREG|0644, st_size=938, ...}) = 0
open("/usr/share/fonts/encodings/large/sun.unicode.india-0.enc.gz", O_RDONLY) = 4
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=938, ...}) = 0
mmap2(NULL, 938, PROT_READ, MAP_PRIVATE, 4, 0) = 0xb6f14000
close(4) = 0
open("/usr/share/fonts/encodings/large/._sun.unicode.india-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/%sun.unicode.india-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.AppleDouble/sun.unicode.india-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/sun.unicode.india-0.enc.gz/..namedfork/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/sun.unicode.india-0.enc.gz/rsrc", O_RDONLY) = -1 ENOTDIR (Not a directory)
open("/usr/share/fonts/encodings/large/resource.frk/sun.unicode.india-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/fonts/encodings/large/.resource/sun.unicode.india-0.enc.gz", O_RDONLY) = -1 ENOENT (No such file or directory)
munmap(0xb6f14000, 938) = 0
access("/var/cache/fontconfig", W_OK) = -1 EACCES (Permission denied)
access("/var/cache/fontconfig", F_OK) = 0
access("//.fontconfig", W_OK) = -1 ENOENT (No such file or directory)
access("//.fontconfig", F_OK) = -1 ENOENT (No such file or directory)
access("/", F_OK) = 0
mkdir("//.fontconfig", 0777) = -1 EACCES (Permission denied)
close(3)
Yours will have more entries since I copied two sections and put them together. It appears that RRDtool is searching through the font directories and tries to update the font cache but can’t. It gives up eventually and finally opens a font to generate the graph. If we force an update of the font cache things go back to normal.
fc-cache -r -s -v
I’m not sure what exactly caused the font cache to become invalid in the first place. The time change might have just been a coincidence since no packages or fonts were updated during that time.
Thanks a lot! I just experienced the same problem and your solution worked like a charm!