You are not logged in.

Pages: 1

#1 2017-11-03 10:28:52

Self-Perfection
Member
From: Russia
Registered: 2010-12-16
Posts: 8

Extremely slow `rrdtool graph` rendering under http user

Since recent update `rrdtool graph` takes 1000 times more CPU time under http user than under ordinary user:

$ time   /usr/bin/rrdtool graph - -a PNG   '-s' 'e-86400' 'DEF:avg_1d775834_raw=/var/lib/collectd/localhost.localdomain/users/users.rrd:value:AVERAGE'  'CDEF:avg_1d775834=avg_1d775834_raw,1,*' 'LINE1:avg_1d775834#0000f0:Users'   > graph.png

real    0m0,034s
user    0m0,024s
sys     0m0,010s
$ time sudo -u http  /usr/bin/rrdtool graph - -a PNG   '-s' 'e-86400' 'DEF:avg_1d775834_raw=/var/lib/collectd/localhost.localdomain/users/users.rrd:value:AVERAGE'  'CDEF:avg_1d775834=avg_1d775834_raw,1,*' 'LINE1:avg_1d775834#0000f0:Users'   > graph_http.png

real    0m28,893s
user    0m28,858s
sys     0m0,034s

Rendered graphs are visually indistinguishable.

I had similar issue about a year ago. My haphazard actions somehow resolved the issue the first time, but I have not figured out its cause. Now I'm firmly resolved to find it.

The issue seems to be related to font rendering. Here is comparison of data collected with `perf record`:
First normal run under ordinray user:

$ perf report --stdio -g none --sort comm,dso -i rrdtool_ordinary.data|cat
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 84  of event 'cycles:uppp'
# Event count (approx.): 81144529
#
# Overhead  Command  Shared Object            
# ........  .......  .........................
#
    40.09%  rrdtool  libfontconfig.so.1.10.1  
    13.31%  rrdtool  ld-2.26.so               
     9.36%  rrdtool  [kernel.vmlinux]         
     8.65%  rrdtool  libc-2.26.so             
     6.94%  rrdtool  libpng16.so.16.34.0      
     4.59%  rrdtool  libcairo.so.2.11508.0    
     3.98%  rrdtool  libexpat.so.1.6.6        
     3.44%  rrdtool  libz.so.1.2.11           
     2.30%  rrdtool  libfreetype.so.6.15.0    
     2.29%  rrdtool  libpango-1.0.so.0.4000.12
     2.28%  rrdtool  libpixman-1.so.0.34.0    
     1.60%  rrdtool  libstdc++.so.6.0.24      
     1.16%  rrdtool  libglib-2.0.so.0.5400.0

And for running as http user:

$ sudo -u http perf report --stdio -g none --sort comm,dso -i rrdtool_http.data
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 114K of event 'cycles:uppp'
# Event count (approx.): 110019933503
#
# Overhead  Command  Shared Object            
# ........  .......  .........................
#
    95.12%  rrdtool  libfreetype.so.6.15.0    
     3.43%  rrdtool  libc-2.26.so             
     1.15%  rrdtool  [kernel.vmlinux]         
     0.27%  rrdtool  libfontconfig.so.1.10.1  
     0.01%  rrdtool  ld-2.26.so               
     0.01%  rrdtool  libpng16.so.16.34.0      
     0.01%  rrdtool  libcairo.so.2.11508.0    
     0.00%  rrdtool  libz.so.1.2.11           
     0.00%  rrdtool  libexpat.so.1.6.6        
     0.00%  rrdtool  libharfbuzz.so.0.10600.3 
     0.00%  rrdtool  libpixman-1.so.0.34.0    
     0.00%  rrdtool  libpango-1.0.so.0.4000.12

There is strange issue with permissions. Comparing strace logs for running as ordinary user and http:

$ grep -ic permission ordinary.trace 
0
$ grep -i permission http.trace 
13:09:22.549772 openat(AT_FDCWD, "/var/cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDWR|O_CLOEXEC) = -1 EACCES (Permission denied)
13:09:22.664922 access("/var/cache/fontconfig", W_OK) = -1 EACCES (Permission denied)
13:09:22.665041 mkdir("/srv/http/.cache", 0755) = -1 EACCES (Permission denied)
13:09:22.665096 mkdir("/srv/http/.fontconfig", 0755) = -1 EACCES (Permission denied)
13:09:22.665678 openat(AT_FDCWD, "/var/cache/fontconfig//f2e43df3287529323e79e7929dc44cc9-le64.cache-7", O_RDWR|O_CLOEXEC) = -1 EACCES (Permission denied)
13:09:51.038227 access("/var/cache/fontconfig", W_OK) = -1 EACCES (Permission denied)
13:09:51.038349 mkdir("/srv/http/.cache", 0755) = -1 EACCES (Permission denied)
13:09:51.038406 mkdir("/srv/http/.fontconfig", 0755) = -1 EACCES (Permission denied)

So it tries to write to '491f45a0a771fef1c10b9b647a97fb82-le64.cache-7'. Hmm ok. And what does rrdtool graph do with this file when running under regular user?

$ grep -C 5 491f45a0a771fef1c10b9b647a97fb82 ordinary.trace 
13:09:09.072040 stat("/usr/share/fonts/encodings", {st_mode=S_IFDIR|0755, st_size=1294, ...}) = 0
13:09:09.072056 openat(AT_FDCWD, "/usr/share/fonts/encodings", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072085 openat(AT_FDCWD, "/var/cache/fontconfig//a1c95d6dfc9a7b34f44445cf81166004-le64.cache-7", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072130 stat("/usr/share/fonts/gsfonts", {st_mode=S_IFDIR|0755, st_size=1502, ...}) = 0
13:09:09.072145 openat(AT_FDCWD, "/usr/share/fonts/gsfonts", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072174 openat(AT_FDCWD, "/var/cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072264 openat(AT_FDCWD, "/home/self/.cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072326 stat("/usr/share/fonts/misc", {st_mode=S_IFDIR|0755, st_size=16282, ...}) = 0
13:09:09.072341 openat(AT_FDCWD, "/usr/share/fonts/misc", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072371 openat(AT_FDCWD, "/var/cache/fontconfig//8d4af663993b81a124ee82e610bb31f9-le64.cache-7", O_RDONLY|O_CLOEXEC) = 3
13:09:09.072445 stat("/usr/share/fonts/noto", {st_mode=S_IFDIR|0755, st_size=19470, ...}) = 0
13:09:09.072460 openat(AT_FDCWD, "/usr/share/fonts/noto", O_RDONLY|O_CLOEXEC) = 3

And for comparison:

$ grep -C 5 491f45a0a771fef1c10b9b647a97fb82 http.trace 
13:09:22.549489 stat("/usr/share/fonts/encodings", {st_mode=S_IFDIR|0755, st_size=1294, ...}) = 0
13:09:22.549506 openat(AT_FDCWD, "/usr/share/fonts/encodings", O_RDONLY|O_CLOEXEC) = 3
13:09:22.549535 openat(AT_FDCWD, "/var/cache/fontconfig//a1c95d6dfc9a7b34f44445cf81166004-le64.cache-7", O_RDONLY|O_CLOEXEC) = 3
13:09:22.549580 stat("/usr/share/fonts/gsfonts", {st_mode=S_IFDIR|0755, st_size=1502, ...}) = 0
13:09:22.549595 openat(AT_FDCWD, "/usr/share/fonts/gsfonts", O_RDONLY|O_CLOEXEC) = 3
13:09:22.549625 openat(AT_FDCWD, "/var/cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDONLY|O_CLOEXEC) = 3
13:09:22.549698 openat(AT_FDCWD, "/srv/http/.cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
13:09:22.549714 openat(AT_FDCWD, "/srv/http/.fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
13:09:22.549728 stat("/usr/share/fonts/gsfonts", {st_mode=S_IFDIR|0755, st_size=1502, ...}) = 0
13:09:22.549743 openat(AT_FDCWD, "/usr/share/fonts/gsfonts", O_RDONLY|O_CLOEXEC) = 3
13:09:22.549772 openat(AT_FDCWD, "/var/cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDWR|O_CLOEXEC) = -1 EACCES (Permission denied)
13:09:22.549787 openat(AT_FDCWD, "/srv/http/.cache/fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDWR|O_CLOEXEC) = -1 ENOENT (No such file or directory)
13:09:22.549802 openat(AT_FDCWD, "/srv/http/.fontconfig//491f45a0a771fef1c10b9b647a97fb82-le64.cache-7", O_RDWR|O_CLOEXEC) = -1 ENOENT (No such file or directory)
13:09:22.549816 open("/usr/share/fonts/gsfonts", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
13:09:22.549876 stat("/usr/share/fonts/gsfonts/C059-BdIta.otf", {st_mode=S_IFREG|0644, st_size=103444, ...}) = 0
13:09:22.549901 openat(AT_FDCWD, "/usr/share/fonts/gsfonts/C059-BdIta.otf", O_RDONLY) = 4
13:09:22.553670 stat("/usr/share/fonts/gsfonts/C059-Bold.otf", {st_mode=S_IFREG|0644, st_size=100692, ...}) = 0
13:09:22.553755 openat(AT_FDCWD, "/usr/share/fonts/gsfonts/C059-Bold.otf", O_RDONLY) = 4

And now I'm lost. Why do `rrdtool graph` tries to modify cache under http user? How do I fix this? Do I need writable cache dir for http user? I don't want to have writable dir under /srv/http - is there any other way?

Last edited by Self-Perfection (2018-06-19 14:49:49)

Offline

#2 2017-11-03 14:46:32

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 78,120

Re: Extremely slow `rrdtool graph` rendering under http user

Blind guess: Give the http user a home directory?

Edit: respectively allow it to write here:

13:09:51.038349 mkdir("/srv/http/.cache", 0755) = -1 EACCES (Permission denied)
13:09:51.038406 mkdir("/srv/http/.fontconfig", 0755) = -1 EACCES (Permission denied)

Last edited by seth (2017-11-03 14:47:47)

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

Offline

#3 2017-11-03 21:21:18

Self-Perfection
Member
From: Russia
Registered: 2010-12-16
Posts: 8

Re: Extremely slow `rrdtool graph` rendering under http user

OK, creating /srv/http/.cache/ writable for http user did the trick.

But I am still confused. Why files under /var/cache/fontconfig/ can't be used? I suppose the whole reason for `fontconfig.hook` running during system update is to prepare required cached info about fonts and store in under /var/cache/fontconfig/. Something feels not quite right.

Offline

#4 2017-11-04 07:44:38

seth
Member
From: Won't reply 2 private help req
Registered: 2012-09-03
Posts: 78,120

Re: Extremely slow `rrdtool graph` rendering under http user

local fonts, fonconfig settings. I guess your regular user has such as well? You can also look at the cached files written there - they're binary but contain meaningfull strings (font names, paths, etc.)

How to upload text · How to boot w/o GUI · Disable Windows Fast-Start! · Fix your xinitrc

Offline

#5 2017-11-05 11:20:36

Self-Perfection
Member
From: Russia
Registered: 2010-12-16
Posts: 8

Re: Extremely slow `rrdtool graph` rendering under http user

Well, regular user might have custom fonts or fontconfig settings, but http user does not seem to have these:

$ ls -ld /srv/http/.*
drwxr-xr-x 1 root root 364 2017-11-03 23:39 /srv/http/.
drwxr-xr-x 1 root root  32 2016-02-18 17:28 /srv/http/..
drwxr-xr-x 1 http http  20 2017-11-04 00:13 /srv/http/.cache
-rw-r--r-- 1 root root  13 2017-04-10 15:12 /srv/http/.rsync-filter

I've compared cache files generated by running `rrdtool graph` under http user with system cache files. These files are different in just a couple of bytes:

/srv/http/.cache/fontconfig$ for f in *cache*; do echo "$f"; diff <(xxd "$f") <(xxd /var/cache/fontconfig/"$f"); done
491f45a0a771fef1c10b9b647a97fb82-le64.cache-7
4c4
< 00000030: 9bd2 f359 0000 0000 94b2 d816 0000 0000  ...Y............
---
> 00000030: 18d1 f359 0000 0000 f05f 1305 0000 0000  ...Y....._......
f2e43df3287529323e79e7929dc44cc9-le64.cache-7
4c4
< 00000030: 9bd2 f359 0000 0000 dd19 fc01 0000 0000  ...Y............
---
> 00000030: fad1 f359 0000 0000 0d00 8d01 0000 0000  ...Y............

Offline

Pages: 1

Board footer

Powered by FluxBB