[collectd] Strange behaviour of collectd with rrdcached

[Sergey]

On Thursday 23 April 2015, Lindsay Holmwood wrote:

> If you strace -f the rrdcached process, you'll see a bunch of output that
> looks like this:

> [pid 27926] write(6, "-1 Permission denied\n", 21) = 21

I not see "Permission denied" error: data are collected. Only records
with violation of order are ignored. In my previous example:

update /var/lib/collectd/rrd/hostname/apcups/temperature.rrd 1429693516:32.800000
update /var/lib/collectd/rrd/hostname/apcups/temperature.rrd 1429693536:32.800000
update /var/lib/collectd/rrd/hostname/apcups/temperature.rrd 1429693527:32.800000 <--
update /var/lib/collectd/rrd/hostname/apcups/temperature.rrd 1429693546:32.800000
update /var/lib/collectd/rrd/hostname/apcups/temperature.rrd 1429693556:32.800000

Data with timestamps 1429693516,1429693536,1429693546 and 1429693556
was wrote, only 1429693527 was ignored. But a lot of them.

> My general process for debugging issues with collectd + rrdcached is:
> 
>  0. Crack out strace and see what's happening inside rrdcached. Use -s 256
> so you can see the full string rrdcached is pushing back to collectd.
>  1. Eliminate rrdcached, and replicate behaviour with the collectd + the
>  vanilla rrdtool plugin .
>  2. If you can't replicate, the problem is with rrdcached.

rrdtool plugin works, problem exist when rrdcached used.

>  3. Crack out strace and see what's happening inside rrdcached.
 	
nothing new:

[pid 10586] poll([{fd=3, events=POLLIN|POLLPRI}], 1, 500) = 1 ([{fd=3, revents=POLLIN}])
[pid 10586] read(3, "update /var/lib/collectd/rrd/hostname/cpu-0/cpu-user.rrd 1429861837:34507652\n", 8192) = 87
[pid 10586] write(3, "-1 illegal attempt to update using time 1429861837.000000 when last update time is 1429861847.000000 (minimum one second step)\n", 127) = 127

Attempt to write timestamp 1429861837 after 1429861847.

>  4. Connect to the socket rrdcached is listening on and poke at it with
> PENDING, FLUSH, STATS.

Hm...

rrdcached plugin: rrdc_update (/var/lib/collectd/rrd/hostname/cpu-0/cpu-user.rrd, [1429863777:37393813], 1) failed with status -1.

And timestamp 1429863777 missed in PENDING list:

1429863757:37393444
1429863767:37393508
1429863787:37394139
1429863797:37394476

What's next ? I guess the problem with rrdcached plugin, not with rrdcached

-- 
Regards, Sergey