Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

I found a bug with abnormal graphic capture #5800

Closed
maojianyou opened this issue Aug 12, 2024 · 15 comments
Closed

I found a bug with abnormal graphic capture #5800

maojianyou opened this issue Aug 12, 2024 · 15 comments
Labels
bug Undesired behaviour question A question not a bug

Comments

@maojianyou
Copy link

maojianyou commented Aug 12, 2024

1、basic environment:

Dependency Cacti 1.3.0-dev
Operating System CentOS7.9 kernel 3.10.0-1160.71.1.el7.x86_64
MySQL 8.0.38
PHP 8.2.22
RRDtool 1.8.0
Net-SNMP 5.7.3

2、Malfunction symptoms:

image
image

cacti.log
2024-08-13 09:40:01 - POLLER: Poller[Main Poller] PID[36565] WARNING: Data Template 'Interface - Traffic' is impacted by lack of complete information
2024-08-13 09:40:01 - POLLER: Poller[Main Poller] PID[36565] WARNING: There are 1 Data Sources not returning all data leaving rows in the poller output table. Details to follow.

/usr/local/spine/bin/spine
image

/data/logs/nginx/demo_error.log
2024/08/12 09:55:41 [error] 6261#6261: *877 FastCGI sent in stderr: "PHP message: PHP Warning: Undefined array key "tr_1" in /data/www/cacti/lib/html_form.php on line 1397" while reading response header from upstream

@maojianyou maojianyou added bug Undesired behaviour unverified Some days we don't have a clue labels Aug 12, 2024
@TheWitness
Copy link
Member

@maojianyou, the error on lib/html_form.php is not related to the issue. It could be simply a timeout, or you are capturing too many OID's to respond in time. You should adjust your devices snmp timeout or max oids to see if that helps.

@TheWitness
Copy link
Member

Oh, develop version. Comments on timeouts still apply.

@maojianyou
Copy link
Author

@maojianyou, the error on lib/html_form.php is not related to the issue. It could be simply a timeout, or you are capturing too many OID's to respond in time. You should adjust your devices snmp timeout or max oids to see if that helps.

However, in the same environment, when I downgraded Cacti from version 1.3.0 to 1.2.27 and PHP from 8.2 to 7.3, the issue did not occur. This leads me to suspect a potential compatibility issue between PHP 8.2 and the Cacti 1.3.0 code, rather than a network issue. The SNMP delay OID is set to 10, and the SNMP timeout is set to 2000, yet the same issue occurs. After downgrading, everything works fine, and there are no broken graphs. I mainly wanted to solve the issue of using the aggregate_max function to calculate the 95th percentile, assuming the new version would address it. I have resubmitted issue #5803 regarding the aggregation graph in version 1.2.27. If this version can solve the problem, then I won't need to use the Cacti 1.3.0 dev version.

@ISekan
Copy link

ISekan commented Aug 20, 2024

I have the same issue
cacti 1.2.25-1.2.27
PHP Version | 8.1.27
11.2.3-MariaDB
image

@TheWitness
Copy link
Member

Set the device as a debug device, and then use spine to poll as follows. Post the results.

./spine -R -V 3 -S -H host_id

Where host_id is the numeric id of the host.

@TheWitness TheWitness added question A question not a bug and removed unverified Some days we don't have a clue labels Aug 25, 2024
@maojianyou
Copy link
Author

spine -R -V 3 -S -H host_id
[root@localhost rra]# spine -R -V 3 -S -H 9
SPINE: Using spine config file [/etc/spine.conf]
Version 1.2.20 starting
Total[0.0170] Spine will support multithread device polling.
Total[0.0173] DEBUG: Initial Value of Available Threads is 1 (0 outstanding)
Total[0.0176] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.0188] Device[0] HT[1] Total Time: 0.00045 Seconds
Total[0.1183] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.1191] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.1228] Device[9] Checking for System Information Update
Total[0.1228] Device[9] Updating Full System Information Table
Total[0.1440] Device[9] HT[1] DQ[16] Extended Uptime Result: 139030194, Is Numeric: 1
Total[0.1440] Device[9] HT[1] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019400)
Total[0.1447] Device[9] HT[1] NOTE: There are '2' Polling Items for this Device
Total[0.1447] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.2735] Device[9] HT[1] DS[309] TT[128.79] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.117, value: 37898300629273839
Total[0.2736] Device[9] HT[1] DS[309] TT[128.81] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.117, value: 19068841571714127
Total[0.2740] Device[9] HT[1] Total Time: 0.16 Seconds
Total[0.3189] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.3199] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.3267] Device[9] HT[2] DQ[16] Extended Uptime Result: 139030194, Is Numeric: 1
Total[0.3267] Device[9] HT[2] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019400)
Total[0.3272] Device[9] HT[2] NOTE: There are '2' Polling Items for this Device
Total[0.3273] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.3360] Device[9] HT[2] DS[317] TT[8.69] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.71, value: 12944094704182298
Total[0.3360] Device[9] HT[2] DS[316] TT[8.71] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.22, value: 11927847282188125
Total[0.3361] Device[9] HT[2] Total Time: 0.017 Seconds
Total[0.4197] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.4205] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.4302] Device[9] HT[3] DQ[16] Extended Uptime Result: 139030194, Is Numeric: 1
Total[0.4302] Device[9] HT[3] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019400)
Total[0.4308] Device[9] HT[3] NOTE: There are '2' Polling Items for this Device
Total[0.4308] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.4375] Device[9] HT[3] DS[316] TT[6.62] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.22, value: 16645351256465570
Total[0.4375] Device[9] HT[3] DS[316] TT[6.64] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.22, value: 11927847282188125
Total[0.4375] Device[9] HT[3] Total Time: 0.017 Seconds
Total[0.5203] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.5215] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.5282] Device[9] HT[4] DQ[16] Extended Uptime Result: 139030195, Is Numeric: 1
Total[0.5282] Device[9] HT[4] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019500)
Total[0.5287] Device[9] HT[4] NOTE: There are '2' Polling Items for this Device
Total[0.5288] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.5513] Device[9] HT[4] DS[317] TT[22.52] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.71, value: 18065499896944601
Total[0.5513] Device[9] HT[4] DS[317] TT[22.54] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.71, value: 12944094704182298
Total[0.5514] Device[9] HT[4] Total Time: 0.03 Seconds
Total[0.6208] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.6213] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.6280] Device[9] HT[5] DQ[16] Extended Uptime Result: 139030195, Is Numeric: 1
Total[0.6280] Device[9] HT[5] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019500)
Total[0.6285] Device[9] HT[5] NOTE: There are '2' Polling Items for this Device
Total[0.6285] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.6339] Device[9] HT[5] DS[318] TT[5.33] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.72, value: 15115411616770677
Total[0.6339] Device[9] HT[5] DS[318] TT[5.37] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.72, value: 10649385177850263
Total[0.6340] Device[9] HT[5] Total Time: 0.013 Seconds
Total[0.7214] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.7224] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.7290] Device[9] HT[6] DQ[16] Extended Uptime Result: 139030195, Is Numeric: 1
Total[0.7291] Device[9] HT[6] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019500)
Total[0.7295] Device[9] HT[6] Total Time: 0.0075 Seconds
Total[0.8223] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.8230] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.8291] Device[9] HT[7] DQ[16] Extended Uptime Result: 139030195, Is Numeric: 1
Total[0.8291] Device[9] HT[7] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019500)
Total[0.8296] Device[9] HT[7] Total Time: 0.007 Seconds
Total[0.9228] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.9235] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.9310] Device[9] HT[8] DQ[16] Extended Uptime Result: 139030195, Is Numeric: 1
Total[0.9310] Device[9] HT[8] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019500)
Total[0.9315] Device[9] HT[8] Total Time: 0.0084 Seconds
Total[1.4231] Time: 1.4231 s, Threads: 1, Devices: 2

It seems like this node is experiencing an exception,But I don't know why this is happening。

Total[0.3189] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.3199] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.3267] Device[9] HT[2] DQ[16] Extended Uptime Result: 139030194, Is Numeric: 1
Total[0.3267] Device[9] HT[2] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13902992500 < output: 13903019400)
Total[0.3272] Device[9] HT[2] NOTE: There are '2' Polling Items for this Device
Total[0.3273] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.3360] Device[9] HT[2] DS[317] TT[8.69] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.71, value: 12944094704182298
Total[0.3360] Device[9] HT[2] DS[316] TT[8.71] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.22, value: 11927847282188125
Total[0.3361] Device[9] HT[2] Total Time: 0.017 Seconds
Total[0.4197] DEBUG: Available Threads is 0 (1 outstanding)

@TheWitness
Copy link
Member

Try it at -V 5 now. It looks almost like the uptime is 'stuck' on the router.

@TheWitness
Copy link
Member

The extended uptime should not be stuck. It has an overflow that is several years vs. the old 1/100th of a second uptime which overflows after ~497 days, but the per second uptime, just multiply that by 100. So, to get to that:

2x32 unsigned = 4294967296
4294967296 / 100 = Seconds till overflow = 42949672 seconds
42949672 / 86400 = Seconds per day = 497.102 days
497 / 365 = 1.36 years

Maybe your vendor's per second uptime is in fact based (poorly) on the SNMP uptime.

@maojianyou
Copy link
Author

Try it at -V 5 now. It looks almost like the uptime is 'stuck' on the router.

It seems the issue is here, but there must be a bug because I didn't encounter this problem when using version 0.8.7.
Total[0.2263] Device[9] HT[2] DQ[16] Extended Uptime Result: 139130452, Is Numeric: 1
Total[0.2263] Device[9] HT[2] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045200)
Total[0.2268] Device[9] HT[2] NOTE: There are '2' Polling Items for this Device
Total[0.2269] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.2346] Device[9] HT[2] DS[317] TT[7.70] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.71, value: 12955542890338503
Total[0.2346] Device[9] HT[2] DS[316] TT[7.75] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.22, value: 11939414632451758
Total[0.2348] DEBUG: Setting up writes to local database
Total[0.2348] Device[9] HT[2] Total Time: 0.015 Seconds

The interfaces I set up are all 64-bit

[root@localhost ~]# spine -R -V 5 -S -H 9
SPINE: Using spine config file [/etc/spine.conf]
Total[0.0064] DEBUG: The path_php_server variable is /data/www/cacti/script_server.php
Total[0.0064] DEBUG: The path_cactilog variable is /data/www/cacti/log/cacti.log
Total[0.0064] DEBUG: The version variable is 8.0.38
Total[0.0064] DEBUG: The log_destination variable is 4 (STDOUT)
Total[0.0066] DEBUG: The path_php variable is /bin/php
Total[0.0068] DEBUG: The availability_method variable is 2
Total[0.0070] DEBUG: The ping_recovery_count variable is 3
Total[0.0072] DEBUG: The ping_failure_count variable is 2
Total[0.0074] DEBUG: The ping_method variable is 2
Total[0.0076] DEBUG: The ping_retries variable is 3
Total[0.0078] DEBUG: The ping_timeout variable is 2000
Total[0.0080] DEBUG: The snmp_retries variable is 3
Total[0.0082] DEBUG: The log_perror variable is 1
Total[0.0084] DEBUG: The log_pwarn variable is 0
Total[0.0086] DEBUG: The boost_redirect variable is 0
Total[0.0088] DEBUG: The boost_rrd_update_enable variable is 0
Total[0.0091] DEBUG: The log_pstats variable is 0
Total[0.0093] DEBUG: The threads variable is 1
Total[0.0095] DEBUG: The polling interval is 300 seconds
Total[0.0097] DEBUG: The number of concurrent processes is 1
Total[0.0099] DEBUG: The script timeout is 25
Total[0.0102] DEBUG: The selective_device_debug variable is 
Total[0.0104] DEBUG: The spine_log_level variable is 0
Total[0.0106] DEBUG: The number of php script servers to run is 1
Total[0.0108] DEBUG: The number of active data source profiles is 1
Total[0.0110] DEBUG: The number of snmp ports on the system is 1
Total[0.0113] DEBUG: Device List to be polled='9', TotalPHPScripts='0'
Total[0.0113] DEBUG: The PHP Script Server is Not Required
Total[0.0115] DEBUG: The Maximum SNMP OID Get Size is 10
Total[0.0120] DEBUG: Total Connections made 1
Total[0.0120] DEBUG: Creating Local Connection Pool of 1 threads.
Total[0.0120] DEBUG: Creating Local Connection 0.
Total[0.0125] DEBUG: Total Connections made 2
Total[0.0125] DEBUG: Version 1.2.20 starting
Total[0.0125] DEBUG: MySQL is Thread Safe!
Total[0.0125] DEBUG: Spine running as 0 UID, 0 EUID
Total[0.0125] DEBUG: Spine is running as root.
Total[0.0125] DEBUG: Spine has got ICMP
Total[0.0125] DEBUG: Initializing Net-SNMP API
Total[0.0126] DEBUG: Issues with SNMP Header Version information, assuming old version of Net-SNMP.
Total[0.0151] DEBUG: Initializing PHP Script Server(s)
Total[0.0178] Spine will support multithread device polling.
Total[0.0181] DEBUG: Initial Value of Available Threads is 1 (0 outstanding)
Total[0.0184] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.0185] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.0190] DEBUG: Device[0] HT[1] In Poller, About to Start Polling
Total[0.0190] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.0190] DEBUG: Checking Local Pool ID 0.
Total[0.0190] DEBUG: Allocating Local Pool ID 0.
Total[0.0195] Device[0] HT[1] Total Time: 0.00045 Seconds
Total[0.0198] DEBUG: Freeing Local Pool ID 0
Total[0.0198] DEBUG: Device[0] HT[1] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.1192] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.1192] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.1197] DEBUG: Device[9] HT[1] In Poller, About to Start Polling
Total[0.1197] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.1197] DEBUG: Checking Local Pool ID 0.
Total[0.1197] DEBUG: Allocating Local Pool ID 0.
Total[0.1202] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.1203] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.1203] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.1204] Device[9] DEBUG: Entering SNMP Ping
Total[0.1293] Device[9] SNMP Result: Device responded to SNMP
Total[0.1293] Device[9] Checking for System Information Update
Total[0.1293] Device[9] Updating Full System Information Table
Total[0.1465] DEBUG: Device[9] HT[1] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.1493] Device[9] HT[1] DQ[16] Extended Uptime Result: 139130452, Is Numeric: 1
Total[0.1493] Device[9] HT[1] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045200)
Total[0.1498] Device[9] HT[1] NOTE: There are '2' Polling Items for this Device
Total[0.1499] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.1948] Device[9] HT[1] DS[309] TT[44.93] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.117, value: 37942389095804970
Total[0.1948] Device[9] HT[1] DS[309] TT[44.96] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.117, value: 19080861332923941
Total[0.1950] DEBUG: Setting up writes to local database
Total[0.1951] Device[9] HT[1] Total Time: 0.075 Seconds
Total[0.1951] DEBUG: Freeing Local Pool ID 0
Total[0.1951] DEBUG: Device[9] HT[1] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.2196] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.2197] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.2199] DEBUG: Device[9] HT[2] In Poller, About to Start Polling
Total[0.2199] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.2199] DEBUG: Checking Local Pool ID 0.
Total[0.2199] DEBUG: Allocating Local Pool ID 0.
Total[0.2203] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.2203] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.2204] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.2204] Device[9] DEBUG: Entering SNMP Ping
Total[0.2235] DEBUG: Device[9] HT[2] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.2263] Device[9] HT[2] DQ[16] Extended Uptime Result: 139130452, Is Numeric: 1
Total[0.2263] Device[9] HT[2] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045200)
Total[0.2268] Device[9] HT[2] NOTE: There are '2' Polling Items for this Device
Total[0.2269] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.2346] Device[9] HT[2] DS[317] TT[7.70] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.71, value: 12955542890338503
Total[0.2346] Device[9] HT[2] DS[316] TT[7.75] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.22, value: 11939414632451758
Total[0.2348] DEBUG: Setting up writes to local database
Total[0.2348] Device[9] HT[2] Total Time: 0.015 Seconds
Total[0.2348] DEBUG: Freeing Local Pool ID 0
Total[0.2348] DEBUG: Device[9] HT[2] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.3202] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.3202] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.3206] DEBUG: Device[9] HT[3] In Poller, About to Start Polling
Total[0.3207] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.3207] DEBUG: Checking Local Pool ID 0.
Total[0.3207] DEBUG: Allocating Local Pool ID 0.
Total[0.3211] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.3211] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.3211] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.3212] Device[9] DEBUG: Entering SNMP Ping
Total[0.3243] DEBUG: Device[9] HT[3] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.3278] Device[9] HT[3] DQ[16] Extended Uptime Result: 139130453, Is Numeric: 1
Total[0.3278] Device[9] HT[3] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045300)
Total[0.3287] Device[9] HT[3] NOTE: There are '2' Polling Items for this Device
Total[0.3287] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.3421] Device[9] HT[3] DS[316] TT[13.33] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.22, value: 16664594218736519
Total[0.3421] Device[9] HT[3] DS[316] TT[13.35] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.22, value: 11939414632451758
Total[0.3422] DEBUG: Setting up writes to local database
Total[0.3422] Device[9] HT[3] Total Time: 0.022 Seconds
Total[0.3422] DEBUG: Freeing Local Pool ID 0
Total[0.3422] DEBUG: Device[9] HT[3] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.4206] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.4207] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.4208] DEBUG: Device[9] HT[4] In Poller, About to Start Polling
Total[0.4209] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.4209] DEBUG: Checking Local Pool ID 0.
Total[0.4209] DEBUG: Allocating Local Pool ID 0.
Total[0.4214] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.4214] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.4214] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.4215] Device[9] DEBUG: Entering SNMP Ping
Total[0.4245] DEBUG: Device[9] HT[4] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.4273] Device[9] HT[4] DQ[16] Extended Uptime Result: 139130453, Is Numeric: 1
Total[0.4273] Device[9] HT[4] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045300)
Total[0.4278] Device[9] HT[4] NOTE: There are '2' Polling Items for this Device
Total[0.4278] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.4331] Device[9] HT[4] DS[317] TT[5.25] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.71, value: 18084809579009829
Total[0.4331] Device[9] HT[4] DS[317] TT[5.27] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.71, value: 12955542890338503
Total[0.4331] DEBUG: Setting up writes to local database
Total[0.4332] Device[9] HT[4] Total Time: 0.012 Seconds
Total[0.4332] DEBUG: Freeing Local Pool ID 0
Total[0.4332] DEBUG: Device[9] HT[4] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.5212] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.5212] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.5220] DEBUG: Device[9] HT[5] In Poller, About to Start Polling
Total[0.5220] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.5220] DEBUG: Checking Local Pool ID 0.
Total[0.5221] DEBUG: Allocating Local Pool ID 0.
Total[0.5225] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.5225] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.5226] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.5226] Device[9] DEBUG: Entering SNMP Ping
Total[0.5255] DEBUG: Device[9] HT[5] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.5282] Device[9] HT[5] DQ[16] Extended Uptime Result: 139130453, Is Numeric: 1
Total[0.5283] Device[9] HT[5] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045300)
Total[0.5287] Device[9] HT[5] NOTE: There are '2' Polling Items for this Device
Total[0.5287] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.5359] Device[9] HT[5] DS[318] TT[7.09] SNMP: v2: 172.31.99.51, dsname: traffic_in, oid: .1.3.6.1.2.1.31.1.1.1.6.72, value: 15132602039082281
Total[0.5359] Device[9] HT[5] DS[318] TT[7.13] SNMP: v2: 172.31.99.51, dsname: traffic_out, oid: .1.3.6.1.2.1.31.1.1.1.10.72, value: 10658722289986491
Total[0.5359] DEBUG: Setting up writes to local database
Total[0.5359] Device[9] HT[5] Total Time: 0.014 Seconds
Total[0.5359] DEBUG: Freeing Local Pool ID 0
Total[0.5359] DEBUG: Device[9] HT[5] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.6216] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.6217] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.6219] DEBUG: Device[9] HT[6] In Poller, About to Start Polling
Total[0.6220] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.6220] DEBUG: Checking Local Pool ID 0.
Total[0.6220] DEBUG: Allocating Local Pool ID 0.
Total[0.6224] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.6224] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.6224] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.6225] Device[9] DEBUG: Entering SNMP Ping
Total[0.6256] DEBUG: Device[9] HT[6] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.6286] Device[9] HT[6] DQ[16] Extended Uptime Result: 139130453, Is Numeric: 1
Total[0.6286] Device[9] HT[6] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045300)
Total[0.6291] Device[9] HT[6] Total Time: 0.0071 Seconds
Total[0.6291] DEBUG: Freeing Local Pool ID 0
Total[0.6291] DEBUG: Device[9] HT[6] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.7221] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.7221] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.7223] DEBUG: Device[9] HT[7] In Poller, About to Start Polling
Total[0.7224] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.7224] DEBUG: Checking Local Pool ID 0.
Total[0.7224] DEBUG: Allocating Local Pool ID 0.
Total[0.7228] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.7228] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.7229] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.7229] Device[9] DEBUG: Entering SNMP Ping
Total[0.7259] DEBUG: Device[9] HT[7] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.7286] Device[9] HT[7] DQ[16] Extended Uptime Result: 139130453, Is Numeric: 1
Total[0.7286] Device[9] HT[7] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045300)
Total[0.7291] Device[9] HT[7] Total Time: 0.0067 Seconds
Total[0.7291] DEBUG: Freeing Local Pool ID 0
Total[0.7291] DEBUG: Device[9] HT[7] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[0.8226] DEBUG: Valid Thread to be Created (139736073746176)
Total[0.8226] DEBUG: Available Threads is 0 (1 outstanding)
Total[0.8226] WARNING: Device[9] polling sleeping while waiting for 1 Threads to End
Total[0.8233] DEBUG: Device[9] HT[8] In Poller, About to Start Polling
Total[0.8233] DEBUG: Traversing Local Connection Pool for free connection.
Total[0.8233] DEBUG: Checking Local Pool ID 0.
Total[0.8233] DEBUG: Allocating Local Pool ID 0.
Total[0.8241] get_namebyhost(172.31.99.51) - Allocating name_t
Total[0.8241] get_namebyhost(172.31.99.51) - No delimiter, assume full hostname
Total[0.8241] Device[9] INFO: SNMP Device '172.31.99.51:161' has a timeout of 2000000 (2000), with 3 retries
Total[0.8242] Device[9] DEBUG: Entering SNMP Ping
Total[0.8273] DEBUG: Device[9] HT[8] RECACHE: Processing 1 items in the auto reindex cache for '172.31.99.51'
Total[0.8301] Device[9] HT[8] DQ[16] Extended Uptime Result: 139130453, Is Numeric: 1
Total[0.8301] Device[9] HT[8] DQ[16] RECACHE OID: .1.3.6.1.2.1.1.3.0, (assert: 13913042400 < output: 13913045300)
Total[0.8307] Device[9] HT[8] Total Time: 0.0074 Seconds
Total[0.8307] DEBUG: Freeing Local Pool ID 0
Total[0.8307] DEBUG: Device[9] HT[8] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function
Total[1.3228] The final count of Threads is 0
Total[1.3229] INFO: Thread complete for Device[0] and 0 to 0 sources
Total[1.3229] INFO: Thread incomplete for Device[9] and 14 to 16 sources
Total[1.3229] DEBUG: Closing Local Connection Pool ID 0
Total[1.3230] DEBUG: Thread Cleanup Complete
Total[1.3230] DEBUG: PHP Script Server Pipes Closed
Total[1.3230] DEBUG: Allocated Variable Memory Freed
Total[1.3230] DEBUG: MYSQL Free & Close Completed
Total[1.3231] DEBUG: Net-SNMP Close Completed
Total[1.3231] Time: 1.3231 s, Threads: 1, Devices: 2

@maojianyou
Copy link
Author

The extended uptime should not be stuck. It has an overflow that is several years vs. the old 1/100th of a second uptime which overflows after ~497 days, but the per second uptime, just multiply that by 100. So, to get to that:

2x32 unsigned = 4294967296 4294967296 / 100 = Seconds till overflow = 42949672 seconds 42949672 / 86400 = Seconds per day = 497.102 days 497 / 365 = 1.36 years

Maybe your vendor's per second uptime is in fact based (poorly) on the SNMP uptime.

I'm not quite sure why this bug exists. It definitely seems like a bug because this issue didn't occur with Cacti 0.8.7. When I debug the page, it reports a problem with Spine data collection. Since Cacti 0.8.7 uses cmd.php, could it be that there is a compatibility issue between the version of Spine and Cacti data collection, causing this problem?
image

image

image

@TheWitness
Copy link
Member

I hope to be back on 1.3 before too long.

@TheWitness
Copy link
Member

@maojianyou any updates?

@maojianyou
Copy link
Author

@maojianyou any updates?

There are no updates, and the new version has even more bugs.

@TheWitness
Copy link
Member

Best thing you can do is to create pull requests as you discover and resolve the issues. I'm just starting back into the 1.3 or develop branch.

@TheWitness
Copy link
Member

No feedback. Again, recommend the latest develop for testing

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Undesired behaviour question A question not a bug
Projects
None yet
Development

No branches or pull requests

3 participants