[rrd-developers] rrdcached client and unnecessary lstat syscalls

[Martin Sperl]

Hi!

I have made one observation when using rrdtool to update some rrdfiles 
that are updated via rrdcached in my C-Programm.

For an update that essentially would look like this on the command-line:
rrdtool update --daemon /socket \
   /home/msperl/xymon-4.3.4/testdata/servername/ifstat-lo/lo.rrd\
1312899067:5453845452:5372645:0:0:0:0:0:0:5453845452:5372645:0:0:0:0:0

I get an strace output of:
04:42:26.968621 read(3, "0 errors, enqueued 1 value(s).\n", 4096) = 31
04:42:26.968704 lstat("/home", {st_mode=S_IFDIR|0755, st_size=16384, 
...}) = 0
04:42:26.968755 lstat("/home/msperl", {st_mode=S_IFDIR|0755, 
st_size=4096, ...}) = 0
04:42:26.968805 lstat("/home/msperl/xymon-4.3.4", {st_mode=S_IFDIR|0755, 
st_size=4096, ...}) = 0
04:42:26.968857 lstat("/home/msperl/xymon-4.3.4/testdata", 
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
04:42:26.968910 lstat("/home/msperl/xymon-4.3.4/testdata/servername", 
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
04:42:26.968967 
lstat("/home/msperl/xymon-4.3.4/testdata/servername/ifstat-lo", 
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
04:42:26.969027 
lstat("/home/msperl/xymon-4.3.4/testdata/servername/ifstat-lo/lo.rrd", 
{st_mode=S_IFREG|0644, st_size=5755424, ...}) = 0
04:42:26.969092 write(3, "update 
/home/msperl/xymon-4.3.4/testdata/servername/ifstat-lo/lo.rrd 
1312899067:5453845452:5372645:0:0:0:0:0:0:5453845452:5372645:0:0:0:0:0\n", 
166) = 166
04:42:26.969159 read(3, "0 errors, enqueued 1 value(s).\n", 4096) = 31

So we see that for a simple update we spend about: 0.000388s on 
lstat-ing those directories (and that repeatedly!).
That is 72% of the time the whole processing loop takes (0.00538s)!

If I use the same code, but without the daemon configured, then I do not 
get this kind of behaviour.

This is obviously wasting CPU cycles unnecessarily.

Why do we need to do this in the first place? (it essentially seems to 
be the realpath c-library call that is triggering this in rrd_client.c 
line).

Is there a way to avoid this unnecessary overhead as when updating 1000s 
of files this adds up quickly to significant cost...
(Especially as it only seems to get enforced on the client)

Thanks,
             Martin

P.s: just using relative paths with sockets does (almost) the same thing:
getcwd("/home/msperl/xymon-4.3.4"..., 4096) = 25
lstat("/home/msperl/xymon-4.3.4/testdata", {st_mode=S_IFDIR|0755, 
st_size=4096, ...}) = 0
lstat("/home/msperl/xymon-4.3.4/testdata/servername", 
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/msperl/xymon-4.3.4/testdata/servername/ifstat-lo", 
{st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/msperl/xymon-4.3.4/testdata/servername/ifstat-lo/lo.rrd", 
{st_mode=S_IFREG|0644, st_size=5755424, ...}) = 0

I only see the workaround as using tcp connections instead of unix sockets:
05:28:52.962651 read(3, "0 errors, enqueued 1 value(s).\n", 4096) = 31
05:28:52.962732 write(3, "update ./testdata/servername/ifstat-lo/lo.rrd 
1312806435:5412637430:5334438:0:0:0:0:0:0:5412637430:5334438:0:0:0:0:0\n", 
143) = 143
05:28:52.962798 read(3, "0 errors, enqueued 1 value(s).\n", 4096) = 31
Here my whole update cycle takes now 0.000147 seconds instead of the 
0.000538 seconds, so it takes only 27% of the time for issuing the 
update when I use the network sockets!

So maybe we want to improve here...