admin/spine
1
0 Fork 0
mirror of https://github.com/Cacti/spine.git synced 2026-10-23 03:27:10 +09:00
Code Issues Packages Projects Releases Wiki Activity

fix: three long-standing reported logging issues (#554)

Browse Source 
Three small fixes for issues reported by users, the oldest open since
2018. Built and verified in a clean ubuntu:24.04 container at 39
warnings, matching develop.

**#552** — `die()` did not terminate its output, so consecutive fatal
messages ran together in `cacti_stderr.log`:

```
FATAL: Unable to read configuration file! (Spine init)FATAL: Unable to read configuration file! (Spine init)
```

Fix is the one-line change olafhering supplied in the report.

**#263** — twenty-five log sites emitted `DEBUG: Device[n] ...` while
the other hundred-plus use `Device[n] DEBUG: ...`, so a single poll
produced both orders. Four of them also printed `DEBUG` twice in one
line. All normalised to the majority form. Log text is otherwise
unchanged.

**#60** — Spine already reads the Cacti version into `set.cacti_version`
and knows its own from `VERSION`, but never compared them. It now warns
once at startup when the two are from different release lines. Only
major.minor is compared, so point-release drift stays quiet.

Closes #552
Closes #263
Closes #60

---------

Signed-off-by: Thomas Vincent <thomasvincent@gmail.com>
This commit is contained in:
Thomas Vincent authored and GitHub committed 2026-08-31 08:57:22 +01:00
1 parent 918c3756e4
commit 0c752cea9b
4 files changed
+43 -26
Download Patch File Download Diff File Expand all files Collapse all files

No files matched your search

ping.c
+8 -8
View File
@@ -163,7 +163,7 @@ int ping_snmp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Entering SNMP Ping", host->id));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Entering SNMP Ping", host->id));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Entering SNMP Ping", host->id));
}
if (host->snmp_session) {
@@ -283,7 +283,7 @@ int ping_icmp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Entering ICMP Ping", host->id));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Entering ICMP Ping", host->id));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Entering ICMP Ping", host->id));
}
/* get ICMP socket */
@@ -384,7 +384,7 @@ int ping_icmp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Attempting to ping %s, seq %d (Retry %d of %d)", host->id, host->hostname, icmp->icmp_seq, retry_count, host->ping_retries));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Attempting to ping %s, seq %d (Retry %d of %d)", host->id, host->hostname, icmp->icmp_seq, retry_count, host->ping_retries));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Attempting to ping %s, seq %d (Retry %d of %d)", host->id, host->hostname, icmp->icmp_seq, retry_count, host->ping_retries));
}
/* decrement the timeout value by the total time */
@@ -434,7 +434,7 @@ int ping_icmp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Received EINTR", host->id));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Received EINTR", host->id));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Received EINTR", host->id));
}
goto keep_listening;
@@ -490,7 +490,7 @@ int ping_icmp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Exceeded Device Timeout, Retrying", host->id));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Exceeded Device Timeout, Retrying", host->id));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Exceeded Device Timeout, Retrying", host->id));
}
}
@@ -579,7 +579,7 @@ int ping_udp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Entering UDP Ping", host->id));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Entering UDP Ping", host->id));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Entering UDP Ping", host->id));
}
/* set total time */
@@ -693,7 +693,7 @@ int ping_udp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: UDP Timeout, Try Count:%i, Time:%.4f ms", host->id, retry_count+1, (total_time)));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] UDP Timeout, Try Count:%i, Time:%.4f ms", host->id, retry_count+1, (total_time)));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: UDP Timeout, Try Count:%i, Time:%.4f ms", host->id, retry_count+1, (total_time)));
}
retry_count++;
@@ -741,7 +741,7 @@ int ping_tcp(host_t *host, ping_t *ping) {
if (is_debug_device(host->id)) {
SPINE_LOG(("Device[%i] DEBUG: Entering TCP Ping", host->id));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Entering TCP Ping", host->id));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Entering TCP Ping", host->id));
}
/* convert the host timeout to a double precision number in seconds */
poller.c
+15 -15
View File
@@ -37,7 +37,7 @@
void child_cleanup(void *arg) {
poller_thread_t poller_details = *(poller_thread_t*) arg;
SPINE_LOG_DEVDBG(("DEBUG: Device[%i] HT[%i] The Device Thread has cleaned up.", poller_details.host_id, poller_details.host_thread));
SPINE_LOG_DEVDBG(("Device[%i] HT[%i] DEBUG: The Device Thread has cleaned up.", poller_details.host_id, poller_details.host_thread));
child_cleanup_thread(arg);
}
@@ -102,9 +102,9 @@ void *child(void *arg) {
spine_sem_post(poller_details.thread_init_sem);
if (is_debug_device(host_id)) {
SPINE_LOG(("DEBUG: Device[%i] HT[%i] In Poller, About to Start Polling", host_id, host_thread));
SPINE_LOG(("Device[%i] HT[%i] DEBUG: In Poller, About to Start Polling", host_id, host_thread));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] HT[%i] In Poller, About to Start Polling", host_id, host_thread));
SPINE_LOG_DEBUG(("Device[%i] HT[%i] DEBUG: In Poller, About to Start Polling", host_id, host_thread));
}
poll_host(device_counter, host_id, host_thread, host_threads, host_data_ids, host_time, &host_errors, host_time_double);
@@ -902,9 +902,9 @@ void poll_host(int device_counter, int host_id, int host_thread, int host_thread
if (num_rows > 0) {
if (is_debug_device(host->id)) {
SPINE_LOG(("DEBUG: Device[%i] HT[%i] RECACHE: Processing %i items in the auto reindex cache for '%s'", host->id, host_thread, num_rows, host->hostname));
SPINE_LOG(("Device[%i] HT[%i] DEBUG: RECACHE: Processing %i items in the auto reindex cache for '%s'", host->id, host_thread, num_rows, host->hostname));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] HT[%i] RECACHE: Processing %i items in the auto reindex cache for '%s'", host->id, host_thread, num_rows, host->hostname));
SPINE_LOG_DEBUG(("Device[%i] HT[%i] DEBUG: RECACHE: Processing %i items in the auto reindex cache for '%s'", host->id, host_thread, num_rows, host->hostname));
}
// Cache uptime in case we need it again
@@ -2036,9 +2036,9 @@ void poll_host(int device_counter, int host_id, int host_thread, int host_thread
mysql_thread_end();
if (is_debug_device(host_id)) {
SPINE_LOG(("DEBUG: Device[%i] HT[%i] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function", host_id, host_thread));
SPINE_LOG(("Device[%i] HT[%i] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function", host_id, host_thread));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] HT[%i] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function", host_id, host_thread));
SPINE_LOG_DEBUG(("Device[%i] HT[%i] DEBUG: HOST COMPLETE: About to Exit Device Polling Thread Function", host_id, host_thread));
}
if (set.spine_log_level == 1) {
@@ -2335,15 +2335,15 @@ char *exec_poll(host_t *current_host, char *command, int id, const char *type) {
break;
} else if (sem_err == EAGAIN || sem_err == EWOULDBLOCK) {
if (is_debug_device(current_host->id)) {
SPINE_LOG(("DEBUG: Device[%i]: Pausing as unable to obtain a script execution lock", current_host->id));
SPINE_LOG(("Device[%i] DEBUG: Pausing as unable to obtain a script execution lock", current_host->id));
} else {
SPINE_LOG_DEVDBG(("DEBUG: Device[%i]: Pausing as unable to obtain a script execution lock", current_host->id));
SPINE_LOG_DEVDBG(("Device[%i] DEBUG: Pausing as unable to obtain a script execution lock", current_host->id));
}
} else {
if (is_debug_device(current_host->id)) {
SPINE_LOG(("DEBUG: Device[%i]: Pausing as error %d whilst obtaining a script execution lock", current_host->id, sem_err));
SPINE_LOG(("Device[%i] DEBUG: Pausing as error %d whilst obtaining a script execution lock", current_host->id, sem_err));
} else {
SPINE_LOG_DEVDBG(("DEBUG: Device[%i]: Pausing as error %d whilst obtaining a script execution lock", current_host->id, sem_err));
SPINE_LOG_DEVDBG(("Device[%i] DEBUG: Pausing as error %d whilst obtaining a script execution lock", current_host->id, sem_err));
}
}
usleep(10000);
@@ -2377,16 +2377,16 @@ char *exec_poll(host_t *current_host, char *command, int id, const char *type) {
fd = popen((char *)proc_command, "r");
cmd_fd = fileno(fd);
if (is_debug_device(current_host->id)) {
SPINE_LOG(("DEBUG: Device[%i] DEBUG: The POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
SPINE_LOG(("Device[%i] DEBUG: The POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] DEBUG: The POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: The POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
}
#else
cmd_fd = nft_popen(proc_command, "r");
if (is_debug_device(current_host->id)) {
SPINE_LOG(("DEBUG: Device[%i] DEBUG: The NIFTY POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
SPINE_LOG(("Device[%i] DEBUG: The NIFTY POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
} else {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] DEBUG: The NIFTY POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: The NIFTY POPEN returned the following File Descriptor %i", current_host->id, cmd_fd));
}
#endif
spine.c
+2 -2
View File
@@ -954,14 +954,14 @@ int main(int argc, char *argv[]) {
thread_status = pthread_create(&threads[device_counter], &attr, child, poller_details);
if (thread_status == 0) {
SPINE_LOG_DEBUG(("DEBUG: Device[%i] Valid Thread to be Created (%ld)", poller_details->host_id, (unsigned long int)threads[device_counter]));
SPINE_LOG_DEBUG(("Device[%i] DEBUG: Valid Thread to be Created (%ld)", poller_details->host_id, (unsigned long int)threads[device_counter]));
if (change_host) {
device_counter++;
}
spine_sem_getvalue(&available_threads, &a_threads_value);
SPINE_LOG_HIGH(("DEBUG: Device[%i] Available Threads is %i (%i outstanding)", poller_details->host_id, a_threads_value, set.threads - a_threads_value));
SPINE_LOG_HIGH(("Device[%i] DEBUG: Available Threads is %i (%i outstanding)", poller_details->host_id, a_threads_value, set.threads - a_threads_value));
spine_sem_post(&thread_init_sem);
util.c
+18 -1
View File
@@ -381,6 +381,23 @@ void read_config_options(void) {
/* log the path_webroot variable */
SPINE_LOG_DEBUG(("DEBUG: The binary Cacti version is %d", set.cacti_version));
/* Warn when Spine and Cacti come from different release lines. Point
* releases are expected to drift, so only major.minor is compared;
* cacti_version is encoded as major*1000 + minor*100 + point. */
if (set.cacti_version > 0) {
int spine_major = 0, spine_minor = 0, spine_point = 0;
if (sscanf(VERSION, "%d.%d.%d", &spine_major, &spine_minor, &spine_point) >= 2) {
int spine_line = (spine_major * 1000) + (spine_minor * 100);
int cacti_line = (set.cacti_version / 100) * 100;
if (spine_line != cacti_line) {
SPINE_LOG(("WARNING: Spine %s does not match the Cacti release line (Cacti reports %d.%d). Use the Spine built for this Cacti version.",
VERSION, set.cacti_version / 1000, (set.cacti_version / 100) % 10));
}
}
}
/* get logging level from database - overrides spine.conf */
if ((res = getsetting(&mysql, LOCAL, "log_verbosity")) != 0) {
const int n = atoi(res);
@@ -1219,7 +1236,7 @@ void die(const char *format, ...) {
snprintf(flogmessage, DBL_BUFSIZE, "%s (Spine init)", logmessage);
}
fprintf(stderr, "%s", flogmessage);
fprintf(stderr, "%s\n", flogmessage);
if (set.parent_fork == SPINE_PARENT) {
if (set.php_initialized) {