Bug 284185 - net-mgmt/librenms: Template support in newsyslog config file causes rotation issues
Summary: net-mgmt/librenms: Template support in newsyslog config file causes rotation ...
Status: Open
Alias: None
Product: Ports & Packages
Classification: Unclassified
Component: Individual Port(s) (show other bugs)
Version: Latest
Hardware: Any Any
: --- Affects Only Me
Assignee: Dan Langille
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2025-01-20 07:17 UTC by Alexander Moisseev
Modified: 2025-01-22 16:08 UTC (History)
0 users

See Also:
bugzilla: maintainer-feedback? (dvl)


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Alexander Moisseev 2025-01-20 07:17:36 UTC
The installed librenms.conf file at /usr/local/etc/newsyslog.conf.d/ uses a wildcard pattern for log file rotation:  

/var/log/librenms/*.log        www:www          644  14    *    $D0   -     /var/run/librenms/librenms.pid


However, newsyslog on FreeBSD does not support wildcard patterns for log files. This causes log rotation to fail with the following message when running newsyslog -nvv:

/var/log/librenms/*.log <7>: does not exist, skipped.


While the lack of support for wildcard patterns is not explicitly stated in the newsyslog.conf(5) manual, the observed behavior and existing documentation indicate that explicit log file paths must be used.

Environment:
- FreeBSD 14.2-RELEASE
- net-mgmt/librenms-25.1.0,1
Comment 1 Dan Langille freebsd_committer freebsd_triage 2025-01-20 13:29:53 UTC
I think this is the lack of the G flag.

Let's look at my instance:

+#/var/log/librenms/librenms-service.log	www:www	         644  7	    *    $D0   J     /var/run/librenms/librenms.pid
[13:28 besser dvl /usr/local/etc/newsyslog.conf.d] % cat librenms.conf                           
# configuration file for newsyslog for librenms
#
# see newsyslog.conf(5) for details
#
# logfilename                  [owner:group]    mode count size when  flags [/pid_file]        [sig_num]
/var/log/librenms/*.log         www:www		644  14	   *	$D0    GB   


The B I have for convenience, so I don't get the 'rolled over messages' - but there's the G.  It is working:

[13:25 besser dvl /usr/local/etc/newsyslog.conf.d] % ls -l /var/log/librenms/*.log*
-rw-r--r--  1 www www      390 2025.01.20 00:00 /var/log/librenms/daily.log
-rw-r--r--  1 www www      469 2025.01.20 00:00 /var/log/librenms/daily.log.0
-rw-r--r--  1 www www      469 2025.01.19 00:00 /var/log/librenms/daily.log.1
-rw-r--r--  1 www www      410 2025.01.09 00:00 /var/log/librenms/daily.log.10
-rw-r--r--  1 www www      469 2025.01.08 00:00 /var/log/librenms/daily.log.11
-rw-r--r--  1 www www      469 2025.01.06 00:00 /var/log/librenms/daily.log.12
-rw-r--r--  1 www www      469 2025.01.05 00:00 /var/log/librenms/daily.log.13
-rw-r--r--  1 www www      469 2025.01.18 00:00 /var/log/librenms/daily.log.2
-rw-r--r--  1 www www      469 2025.01.17 00:00 /var/log/librenms/daily.log.3
-rw-r--r--  1 www www      426 2025.01.16 00:00 /var/log/librenms/daily.log.4
-rw-r--r--  1 www www      469 2025.01.15 00:00 /var/log/librenms/daily.log.5
-rw-r--r--  1 www www     1290 2025.01.14 00:00 /var/log/librenms/daily.log.6
-rw-r--r--  1 www www      505 2025.01.13 00:00 /var/log/librenms/daily.log.7
-rw-r--r--  1 www www      347 2025.01.12 00:00 /var/log/librenms/daily.log.8
-rw-r--r--  1 www www      528 2025.01.10 00:00 /var/log/librenms/daily.log.9
-rw-r--r--  1 www www  2242470 2025.01.20 13:27 /var/log/librenms/librenms-service.log
-rw-r--r--  1 www www  3984747 2025.01.20 00:00 /var/log/librenms/librenms-service.log.0
-rw-r--r--  1 www www  4067143 2025.01.19 00:00 /var/log/librenms/librenms-service.log.1
-rw-r--r--  1 www www  4079953 2025.01.09 00:00 /var/log/librenms/librenms-service.log.10
-rw-r--r--  1 www www  7400042 2025.01.08 00:00 /var/log/librenms/librenms-service.log.11
-rw-r--r--  1 www www  3685236 2025.01.06 00:00 /var/log/librenms/librenms-service.log.12
-rw-r--r--  1 www www  3982809 2025.01.05 00:00 /var/log/librenms/librenms-service.log.13
-rw-r--r--  1 www www  4006780 2025.01.18 00:00 /var/log/librenms/librenms-service.log.2
-rw-r--r--  1 www www  3987165 2025.01.17 00:00 /var/log/librenms/librenms-service.log.3
-rw-r--r--  1 www www  3980241 2025.01.16 00:00 /var/log/librenms/librenms-service.log.4
-rw-r--r--  1 www www  3990342 2025.01.15 00:00 /var/log/librenms/librenms-service.log.5
-rw-r--r--  1 www www  3844424 2025.01.14 00:00 /var/log/librenms/librenms-service.log.6
-rw-r--r--  1 www www  3631568 2025.01.13 00:00 /var/log/librenms/librenms-service.log.7
-rw-r--r--  1 www www  5230778 2025.01.12 00:00 /var/log/librenms/librenms-service.log.8
-rw-r--r--  1 www www  3963000 2025.01.10 00:00 /var/log/librenms/librenms-service.log.9
-rw-r--r--  1 www www  1119280 2025.01.20 13:27 /var/log/librenms/librenms.log
-rw-r--r--  1 www www  3809974 2025.01.20 00:00 /var/log/librenms/librenms.log.0
-rw-r--r--  1 www www  3808037 2025.01.19 00:00 /var/log/librenms/librenms.log.1
-rw-r--r--  1 www www 11467347 2025.01.09 00:00 /var/log/librenms/librenms.log.10
-rw-r--r--  1 www www  3870072 2025.01.08 00:00 /var/log/librenms/librenms.log.11
-rw-r--r--  1 www www  1309638 2025.01.06 00:00 /var/log/librenms/librenms.log.12
-rw-r--r--  1 www www  1422194 2025.01.05 00:00 /var/log/librenms/librenms.log.13
-rw-r--r--  1 www www  1648336 2025.01.18 00:00 /var/log/librenms/librenms.log.2
-rw-r--r--  1 www www  5641211 2025.01.17 00:00 /var/log/librenms/librenms.log.3
-rw-r--r--  1 www www  1419855 2025.01.16 00:00 /var/log/librenms/librenms.log.4
-rw-r--r--  1 www www  1421923 2025.01.15 00:00 /var/log/librenms/librenms.log.5
-rw-r--r--  1 www www  1371780 2025.01.14 00:00 /var/log/librenms/librenms.log.6
-rw-r--r--  1 www www  1290368 2025.01.13 00:00 /var/log/librenms/librenms.log.7
-rw-r--r--  1 www www  1863692 2025.01.12 00:00 /var/log/librenms/librenms.log.8
-rw-r--r--  1 www www 13084562 2025.01.10 00:00 /var/log/librenms/librenms.log.9
-rw-r--r--  1 www www        0 2025.01.20 00:00 /var/log/librenms/maintenance.log
-rw-r--r--  1 www www      192 2025.01.20 00:00 /var/log/librenms/maintenance.log.0
-rw-r--r--  1 www www        0 2025.01.19 00:00 /var/log/librenms/maintenance.log.1
-rw-r--r--  1 www www        0 2025.01.09 00:00 /var/log/librenms/maintenance.log.10
-rw-r--r--  1 www www        0 2025.01.08 00:00 /var/log/librenms/maintenance.log.11
-rw-r--r--  1 www www      192 2025.01.06 00:00 /var/log/librenms/maintenance.log.12
-rw-r--r--  1 www www        0 2025.01.05 00:00 /var/log/librenms/maintenance.log.13
-rw-r--r--  1 www www        0 2025.01.18 00:00 /var/log/librenms/maintenance.log.2
-rw-r--r--  1 www www        0 2025.01.17 00:00 /var/log/librenms/maintenance.log.3
-rw-r--r--  1 www www        0 2025.01.16 00:00 /var/log/librenms/maintenance.log.4
-rw-r--r--  1 www www        0 2025.01.15 00:00 /var/log/librenms/maintenance.log.5
-rw-r--r--  1 www www        0 2025.01.14 00:00 /var/log/librenms/maintenance.log.6
-rw-r--r--  1 www www      191 2025.01.13 00:00 /var/log/librenms/maintenance.log.7
-rw-r--r--  1 www www        0 2025.01.12 00:00 /var/log/librenms/maintenance.log.8
-rw-r--r--  1 www www        0 2025.01.10 00:00 /var/log/librenms/maintenance.log.9
-rw-r--r--  1 dvl www     3920 2024.05.21 11:55 /var/log/librenms/slibrenms.log.3q
Comment 2 Dan Langille freebsd_committer freebsd_triage 2025-01-20 13:32:12 UTC
In the man page (https://man.freebsd.org/cgi/man.cgi?query=newsyslog.conf&sektion=5&format=html) this is referred to as glob.
Comment 3 commit-hook freebsd_committer freebsd_triage 2025-01-20 13:34:19 UTC
A commit in branch main references this bug:

URL: https://cgit.FreeBSD.org/ports/commit/?id=52e96e45d4e480dff1744ebe5b24495529bcb89b

commit 52e96e45d4e480dff1744ebe5b24495529bcb89b
Author:     Dan Langille <dvl@FreeBSD.org>
AuthorDate: 2025-01-20 13:32:24 +0000
Commit:     Dan Langille <dvl@FreeBSD.org>
CommitDate: 2025-01-20 13:32:24 +0000

    net-mgmt/librenms: Fix the newsyslog example

    To repair your own, adjust ${PREFIX}/etc/newsyslog.conf.d/librenms

    PR:             284185

 net-mgmt/librenms/Makefile                    | 1 +
 net-mgmt/librenms/files/newsyslog.conf.sample | 2 +-
 2 files changed, 2 insertions(+), 1 deletion(-)
Comment 4 Dan Langille freebsd_committer freebsd_triage 2025-01-20 13:36:00 UTC
Hope that helps. Thank you for reporting this.
Comment 5 Alexander Moisseev 2025-01-22 06:49:00 UTC
Thank you for the update.

However, there is still an issue with librenms-service.log. The poller workers do not reopen the log file after rotation and continue writing to the old file descriptor (librenms-service.log.0).


For testing purposes on my system, I am using log rotation by size with the following configuration in /usr/local/etc/newsyslog.conf.d/librenms.conf:

# logfilename                   [owner:group]    mode count size when  flags [/pid_file] [sig_num]
/var/log/librenms/*.log         www:www          644  7     200  *     G


I also tried adding a PID file for newsyslog to send a SIGHUP signal, but it appears the workers do not handle SIGHUP correctly to reopen log files:

# logfilename                   [owner:group]    mode count size when  flags [/pid_file] [sig_num]
/var/log/librenms/*.log         www:www          644  7     200  *     G     /var/run/librenms/librenms.pid


A workaround could involve a script to restart the workers after log rotation, but this is not an ideal solution.
Comment 6 Dan Langille freebsd_committer freebsd_triage 2025-01-22 13:14:20 UTC
(In reply to Alexander Moisseev from comment #5)

So.. why does it not rotate for you but does rotate for me? See also paste in a previous comment showing these logs.

[13:03 besser dvl /var/log/librenms] % ls -l librenms-service.log*
-rw-r--r--  1 www www 2176423 2025.01.22 13:03 librenms-service.log
-rw-r--r--  1 www www 3986201 2025.01.22 00:00 librenms-service.log.0
-rw-r--r--  1 www www 3980607 2025.01.21 00:00 librenms-service.log.1
-rw-r--r--  1 www www 5230778 2025.01.12 00:00 librenms-service.log.10
-rw-r--r--  1 www www 3963000 2025.01.10 00:00 librenms-service.log.11
-rw-r--r--  1 www www 4079953 2025.01.09 00:00 librenms-service.log.12
-rw-r--r--  1 www www 7400042 2025.01.08 00:00 librenms-service.log.13
-rw-r--r--  1 www www 3984747 2025.01.20 00:00 librenms-service.log.2
-rw-r--r--  1 www www 4067143 2025.01.19 00:00 librenms-service.log.3
-rw-r--r--  1 www www 4006780 2025.01.18 00:00 librenms-service.log.4
-rw-r--r--  1 www www 3987165 2025.01.17 00:00 librenms-service.log.5
-rw-r--r--  1 www www 3980241 2025.01.16 00:00 librenms-service.log.6
-rw-r--r--  1 www www 3990342 2025.01.15 00:00 librenms-service.log.7
-rw-r--r--  1 www www 3844424 2025.01.14 00:00 librenms-service.log.8
-rw-r--r--  1 www www 3631568 2025.01.13 00:00 librenms-service.log.9

Looking over here, this is how I'm logging:

[13:06 besser dvl /usr/local/etc/syslog.d] % cat librenms.conf 
local3.*                                       /var/log/librenms/librenms-service.log

Right now, I do not recall where this local3 comes from, nor can I find it in the config.

I'll come back to this.
Comment 7 Dan Langille freebsd_committer freebsd_triage 2025-01-22 16:06:49 UTC
Logging to said file is usually controlled by line 34 here:

https://cgit.freebsd.org/ports/tree/net-mgmt/librenms/files/librenms.in#n34

which is this:

: ${librenms_daemonflags:="-o /var/log/$name/$name-service.log"}


In my installed, I havec this in /etc/rc.conf

[15:44 besser dvl /usr/local/etc/rc.d] % grep librenms /etc/rc.conf
librenms_enable="NO"
librenms_daemonflags="-T librenms -s info -l local3 --restart-delay 10"

I'm logging through local3 - and I suspect that's why this works for me. I'll bet I made that change because of the logging issue you're hitting.
Comment 8 Dan Langille freebsd_committer freebsd_triage 2025-01-22 16:08:58 UTC
(In reply to Dan Langille from comment #7)

Other points:

librenms_enable="NO" - my instance of LibreNMS runs in a jail - often the service starts up and produces many logging errors and does not po=ll. I suspect it's a race issue, but I've been unable to track it down.

My work-around: don't start it from rc.d (hence librenms_enable="NO"), instead, start LibreNMS from cron:

[16:05 besser dvl /usr/local/etc/cron.d] % cat librenms-reboot 
#minute	hour	mday	month	wday	who	command
# because librenms is not playing nicely on start of jail
@reboot                                 root    sleep 10 && service librenms onestart

Downside: If cron restart, librenms will also restart