Switching from cmd.php to Spine issue

[terziyski]

Hi,

recently I switched poller from cmd.php to spine.
In cacti log I noticed regular appearance of:
SPINE: Poller[0] WARNING: SS[0] The PHP Script Server did not respond in time and will therefore be restarted
SPINE: Poller[0] WARNING: SS[1] The PHP Script Server did not respond in time and will therefore be restarted
SPINE: Poller[0] WARNING: SS[2] The PHP Script Server did not respond in time and will therefore be restarted
SPINE: Poller[0] WARNING: SS[3] The PHP Script Server did not respond in time and will therefore be restarted

and

SPINE: Poller[0] ERROR: Spine Timed Out While Processing Hosts Internal

Also the traffic graphs of some devices have been changed strangely(fluctuations appearance).
Some help would be appreciated.
______________________________________
CactiEZ v0.6
Cacti 0.8.7e
Spine 0.8.7e - compiled from source
PA 2.6
Linux cacti 2.6.9-89.0.20.plus.c4smp #1 SMP Wed Feb 3 15:51:03 EST 2010 x86_64 x86_64 x86_64 GNU/Linux
4 processes
10 threads
4 script servers

[gandalf]

The error messages may result from scripts using insane or no timeout.

The peaks are looking like COUNTER wraps; but that's a guess

R.

[terziyski]

It looks like unsynchronized poller to me :

03/11/2010 02:41:05 AM - SYSTEM STATS: Time:63.8225 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 02:35:54 AM - SYSTEM STATS: Time:52.9065 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 02:33:33 AM - SYSTEM STATS: Time:211.0151 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13940
03/11/2010 02:28:31 AM - SYSTEM STATS: Time:209.1853 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 02:21:02 AM - SYSTEM STATS: Time:60.2212 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 02:16:04 AM - SYSTEM STATS: Time:62.0396 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 02:11:05 AM - SYSTEM STATS: Time:63.8765 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 02:07:42 AM - SYSTEM STATS: Time:160.7532 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13934
03/11/2010 02:05:04 AM - SYSTEM STATS: Time:302.6061 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:12701
03/11/2010 01:55:57 AM - SYSTEM STATS: Time:55.7601 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:50:51 AM - SYSTEM STATS: Time:50.1566 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:45:57 AM - SYSTEM STATS: Time:55.2127 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:40:55 AM - SYSTEM STATS: Time:53.2540 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:38:30 AM - SYSTEM STATS: Time:208.5150 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:34:05 AM - SYSTEM STATS: Time:243.6964 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:26:03 AM - SYSTEM STATS: Time:62.3058 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:23:32 AM - SYSTEM STATS: Time:210.6380 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 01:18:20 AM - SYSTEM STATS: Time:197.8756 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13941
03/11/2010 01:15:03 AM - SYSTEM STATS: Time:300.3505 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:11286
03/11/2010 01:12:28 AM - SYSTEM STATS: Time:445.9812 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13940
03/11/2010 01:06:19 AM - SYSTEM STATS: Time:377.0530 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:11746
03/11/2010 12:56:00 AM - SYSTEM STATS: Time:58.6068 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:51:11 AM - SYSTEM STATS: Time:68.8053 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13934
03/11/2010 12:48:33 AM - SYSTEM STATS: Time:212.5754 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:41:05 AM - SYSTEM STATS: Time:63.0127 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13940
03/11/2010 12:36:01 AM - SYSTEM STATS: Time:59.0108 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13940
03/11/2010 12:31:23 AM - SYSTEM STATS: Time:80.9538 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:28:30 AM - SYSTEM STATS: Time:209.0122 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:21:07 AM - SYSTEM STATS: Time:66.0224 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:18:31 AM - SYSTEM STATS: Time:209.6573 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:13:31 AM - SYSTEM STATS: Time:210.2556 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:06:02 AM - SYSTEM STATS: Time:60.4288 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/11/2010 12:01:28 AM - SYSTEM STATS: Time:86.9550 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:56:06 PM - SYSTEM STATS: Time:64.5597 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:50:54 PM - SYSTEM STATS: Time:53.4783 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:45:52 PM - SYSTEM STATS: Time:50.8855 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:40:57 PM - SYSTEM STATS: Time:56.0039 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:36:09 PM - SYSTEM STATS: Time:67.1584 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13940
03/10/2010 11:33:30 PM - SYSTEM STATS: Time:208.6803 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:26:05 PM - SYSTEM STATS: Time:63.6506 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:20:57 PM - SYSTEM STATS: Time:55.0242 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:16:08 PM - SYSTEM STATS: Time:66.0116 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13940
03/10/2010 11:13:31 PM - SYSTEM STATS: Time:209.9653 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:05:54 PM - SYSTEM STATS: Time:52.7683 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 11:01:20 PM - SYSTEM STATS: Time:78.4082 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 10:56:03 PM - SYSTEM STATS: Time:60.7846 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 10:51:02 PM - SYSTEM STATS: Time:61.3638 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13944
03/10/2010 10:45:59 PM - SYSTEM STATS: Time:58.2736 Method:spine Processes:4 Threads:10 Hosts:671 HostsPerProcess:168 DataSources:26355 RRDsProcessed:13926

I think maybe because the intervals between different polls are not equal causing fluctuations to be observed.

[terziyski]

I found a PHP Script Server (ss_cisco_cpu_usage.php) with timeout=host_timeout*1000 milliseconds (php-snmp timeout is in microseconds), which was disturbing the SPINE poller times. After commenting out this line of the script, SPINE started to poll on equal intervals and everything is normal.
Thanks R.