Rudder

I'm experiencing some problems when loading https://RudderURL/rudder/secure/nodeManager/nodes due to what appears to be database performance issues.

There are some strange problems where if RudderSysEvents table has a result the query is returned in <1ms, but if there is NO result it's taking ~2500ms!

Example where a node is returned:

rudder=> EXPLAIN ANALYZE VERBOSE SELECT executiondate, nodeid, ruleid, directiveid, serial, component, keyValue, executionTimeStamp, eventtype, policy, msg FROM RudderSysEvents WHERE 1 = 1 AND nodeid = '71059a73-5599-4050-ac1c-a53e948b01e5' ORDER BY executionTimeStamp DESC LIMIT 1;
                                                                            QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..8.59 rows=1 width=180) (actual time=0.726..0.726 rows=1 loops=1)
   Output: executiondate, nodeid, ruleid, directiveid, serial, component, keyvalue, executiontimestamp, eventtype, policy, msg
   ->  Index Scan Backward using executiontimestamp_idx on ruddersysevents  (cost=0.00..494356.36 rows=57554 width=180) (actual time=0.724..0.724 rows=1 loops=1)
         Output: executiondate, nodeid, ruleid, directiveid, serial, component, keyvalue, executiontimestamp, eventtype, policy, msg
         Filter: (nodeid = '71059a73-5599-4050-ac1c-a53e948b01e5'::text)
 Total runtime: 0.774 ms
(6 rows)

This returns 1 result and takes just around 0.5-0.8ms to load each time.

rudder=> EXPLAIN ANALYZE VERBOSE SELECT executiondate, nodeid, ruleid, directiveid, serial, component, keyValue, executionTimeStamp, eventtype, policy, msg FROM RudderSysEvents WHERE 1 = 1 AND nodeid = '96098873-b38b-4342-bc6a-80bf1d03db1b' ORDER BY executionTimeStamp DESC LIMIT 1;
                                                                               QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..30.15 rows=1 width=180) (actual time=2276.480..2276.480 rows=0 loops=1)
   Output: executiondate, nodeid, ruleid, directiveid, serial, component, keyvalue, executiontimestamp, eventtype, policy, msg
   ->  Index Scan Backward using executiontimestamp_idx on ruddersysevents  (cost=0.00..494356.36 rows=16398 width=180) (actual time=2276.478..2276.478 rows=0 loops=1)
         Output: executiondate, nodeid, ruleid, directiveid, serial, component, keyvalue, executiontimestamp, eventtype, policy, msg
         Filter: (nodeid = '96098873-b38b-4342-bc6a-80bf1d03db1b'::text)
 Total runtime: 2276.531 ms
(6 rows)

This returns zero results, and takes a long time to load (up to 2500ms).

Indexes are enabled and the server has a lot of RAM (around 8GB for Postgres, plenty more available).

We have almost 400 nodes registered in Rudder 2.7.1 (most agents are still 2.7.0) so far and run this on CentOS 6 x86_64 with Postgres 8.4.13 (CentOS version).

The impact of this is a very slow loading node list, but I'm not sure of two things:

#Is this strange behaviour (it seems to me like it is) and do you have any idea why it occurs? Maybe it's a Postgres bug, or even normal behaviour?
#Why is our Rudder policy server running these queries on nodes which don't exist in RudderSysEvents table? This is a Rudder bug, intended behaviour?

Thanks very much for your help.