| View previous topic :: View next topic |
| Author |
Message |
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
 Posted: Mon Nov 04, 2019 7:38 pm Post subject: syslog-ng stops logging even though it is still running |
 |
|
Hello there,
I'm seeing a strange problem on one of my servers where syslog-ng is still running, but it stops logging at the same time (but intermittently):
| Code: |
# pwd && ls -lh | grep '04:02'
/var/log
drwxr-x--- 2 apache apache 4.0K Nov 3 04:02 apache2
-rw------- 1 root root 0 Nov 3 04:02 auth.log
-rw------- 1 root root 573K Oct 14 04:02 auth.log-20191014.gz
-rw------- 1 root root 548K Oct 21 04:02 auth.log-20191021.gz
-rw------- 1 root root 561K Oct 28 04:02 auth.log-20191028.gz
-rw------- 1 root root 3.3M Nov 3 04:02 auth.log-20191103.gz
drwxr-xr-x 2 clamav clamav 20K Nov 3 04:02 clamav
-rw------- 1 root root 0 Nov 3 04:02 cron.log
-rw------- 1 root root 2.8K Oct 14 04:02 cron.log-20191014.gz
-rw------- 1 root root 2.7K Oct 21 04:02 cron.log-20191021.gz
-rw------- 1 root root 2.8K Oct 28 04:02 cron.log-20191028.gz
-rw------- 1 root root 6.5K Nov 3 04:02 cron.log-20191103.gz
-rw------- 1 root root 0 Nov 3 04:02 daemon.log
-rw------- 1 root root 0 Nov 3 04:02 mail.log
-rw------- 1 root root 2.9M Oct 14 04:02 mail.log-20191014.gz
-rw------- 1 root root 5.2M Oct 21 04:02 mail.log-20191021.gz
-rw------- 1 root root 3.8M Oct 28 04:02 mail.log-20191028.gz
-rw------- 1 root root 24M Nov 3 04:02 mail.log-20191103.gz
-rw------- 1 root root 1.7K Oct 27 04:02 messages-20191027.gz
|
I'm guessing that it has something to do with log rotation, but I can't seem to find any reason why it doesn't happen every day. Possibly just a weekly rotation?
| Code: |
# /etc/init.d/syslog-ng status
* status: started
|
BUT, if I restart syslog-ng, it starts logging again:
| Code: |
# ls -lh mail.log
-rw------- 1 root root 7.8K Nov 4 14:37 mail.log
# ls -lh mail.log
-rw------- 1 root root 8.1K Nov 4 14:37 mail.log
# ls -lh mail.log
-rw------- 1 root root 8.5K Nov 4 14:37 mail.log
|
Any thoughts on where to look or is anyone else seeing this problem with syslog-ng-3.24.1?
Thanks!
Cheers,
Nathan Zachary
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
 |
eccerr0r
Watchman
Joined: 01 Jul 2004
Posts: 9691
Location: almost Mile High in the USA
|
| Posted: Mon Nov 04, 2019 9:27 pm Post subject: |
|
|
Looks like the result of app-admin/logrotate and crond (whatever flavor you're using) together ... if you don't have both of these installed, then I'd be concerned...
Also logrotate can choose not to rotate depending on filesize, so this might also be part of the mystery.
_________________
Intel Core i7 2700K/Radeon R7 250/24GB DDR3/256GB SSD
What am I supposed watching? |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Mon Nov 04, 2019 9:52 pm Post subject: |
|
|
It looks like this may have started during the switch from vixie-cron to cronie. I found where the time of 04:02 came in:
| Code: |
# grep '02 4' /etc/cron.d/dailyjobs
02 4 * * * root [ ! -f /etc/cron.hourly/0anacron ] && run-parts /etc/cron.daily
|
and my guess is that it is related to the logrotate portion under /etc/cron.daily/logrotate:
| Code: |
# cat /etc/cron.daily/logrotate
#!/bin/sh
/usr/bin/logrotate /etc/logrotate.conf
EXITVALUE=$?
if [ $EXITVALUE != 0 ]; then
/usr/bin/logger -t logrotate "ALERT exited abnormally with [$EXITVALUE]"
fi
exit $EXITVALUE
|
| Code: |
# grep 'ALERT exited' /var/log/messages
Nov 3 04:02:11 logrotate[18121]: ALERT exited abnormally with [1]
Nov 4 04:02:01 logrotate[18941]: ALERT exited abnormally with [1]
|
After doing some further digging, I found that I have logrotate set to rotate weekly, so that may explain why I don't see the problem daily. As such, I think that the problem may actually be related to logrotate and not directly with syslog-ng. Any ideas on where to look next to see what is actually failing?
Thanks for the pointers thus far!
Cheers,
Nathan Zachary
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
eccerr0r
Watchman
Joined: 01 Jul 2004
Posts: 9691
Location: almost Mile High in the USA
|
| Posted: Mon Nov 04, 2019 11:02 pm Post subject: |
|
|
Ideally the logger needs to be restarted after logrotate runs. I recall seeing this problem before but don't recall what I did to ultimately fix the problem. It seemed to have resolved itself, somehow automatically adding in a postrotate/endscript to restart the syslogd process.
What is your logrotate.conf contents now? I don't recall what I had hacked in mine, no idea how it differs from the Gentoo stock config. Have a feeling that syslog-ng should know when it needs to reopen FDs when logrotate runs. If you told syslog-ng to somehow hold FDs open, then this behavior would be easily explained.
_________________
Intel Core i7 2700K/Radeon R7 250/24GB DDR3/256GB SSD
What am I supposed watching? |
|
| Back to top |
|
|
freke
l33t
Joined: 23 Jan 2003
Posts: 980
Location: Somewhere in Denmark
|
| Posted: Tue Nov 05, 2019 2:22 pm Post subject: |
|
|
I have this:
mail /var/log # cat /etc/logrotate.d/syslog-ng | Code: | #
# Syslog-ng logrotate snippet for Gentoo Linux
# contributed by Michael Sterrett
#
/var/log/messages {
weekly
missingok
sharedscripts
postrotate
/etc/init.d/syslog-ng reload > /dev/null 2>&1 || true
endscript
} |
I *think* that it came with either syslog-ng or logrotate. |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Tue Nov 05, 2019 3:53 pm Post subject: |
|
|
I think failure to adapt to log rotation is changed syslog-ng behavior. I noticed this a few weeks ago and suspect it has been since syslog-ng-3.23.1-r1. The behavior does not occur on all log files. Portage's emerge.log is not affected, for example. On the other hand, auth.log (sshd), mail.log (postfix, exim) are definitely affected on my system.
I rotate auth.log montly. Aug 1-31 is there, Sept 1-30 is there (including up to 3:30 am Oct 1 when log was rotated), then a gap to Oct 19 when syslog-ng was restarted. Aug 17 syslog-ng was changed to 3.22.1 (which was bugy for other reasons), Sept 21 syslog-ng was changed to 3.23.1-r1
Restarting or reloading syslog-ng of course causes logging to resume. This can be done either with the init script (/etc/init.d/syslog-ng restart) or by sending a HUP signal to syslog-ng (pkill -HUP syslog-ng). I don't want to do that because it resets all the "malicious hit counts" on a dynamic firewall that is stopped and reloaded when syslog-ng is reloaded.
For what it's worth, the log info that is supposed to make it to mail.log and auth.log does make it to the dynamic firewall through all these updates and restarts. Here is the associated syslog-ng destination setting ...
| Code: |
destination watch-logs { program("/usr/local/sbin/watch-logs" ts_format(unix)); };
|
I just noticed that the troublesome/missing log entries might be associated with syslog-ng.conf "log" entries that have more than one destination. As mentioned above, the dynamic firewall final destination works, but file destinations "authlog", "mailwarn", and "iptables" stay zero size after logrotate, until syslog-ng is restarted or reloaded.
| Code: | log { source(src); filter(f_authpriv); filter(f_sshd_quiet); destination(authlog); destination(console_12); };
log { source(src); filter(f_mail); filter(f_warn); destination(mailwarn); destination(watch-logs); };
log { source(src); filter(f_iptables); rewrite(r_iptables); destination(iptables); destination(watch-logs); };
|
I was going to experiment with the logrotate "copytruncate" option, to see if syslog-ng continues to follow the rotated log file, but now that I noticed the "multiple destinations on one log line" config, I wonder if others have similar relationship between config and empty logs. |
|
| Back to top |
|
|
eccerr0r
Watchman
Joined: 01 Jul 2004
Posts: 9691
Location: almost Mile High in the USA
|
| Posted: Tue Nov 05, 2019 4:26 pm Post subject: |
|
|
^^ freke got it. I thought there needs to be that restart and forgot that logrotate.d also contains config files. This settles my mystery.
As I have not upgraded to 3.23 yet, perhaps 3.23 did not add the logrotate.d file necessary to ensure rotation restarts syslog-ng. Check to see if that file exists and contains the proper restart. Looks like 3.24.1 is now latest in portage.
BTW, emerge.log is not handled by syslog-ng, but it can be optionally handled by logrotate. I do not rotate this file, probably a bad idea to do so.
_________________
Intel Core i7 2700K/Radeon R7 250/24GB DDR3/256GB SSD
What am I supposed watching? |
|
| Back to top |
|
|
Anon-E-moose
Watchman
Joined: 23 May 2008
Posts: 6103
Location: Dallas area
|
| Posted: Tue Nov 05, 2019 4:36 pm Post subject: |
|
|
| eccerr0r wrote: | | BTW, emerge.log is not handled by syslog-ng, but it can be optionally handled by logrotate. I do not rotate this file, probably a bad idea to do so. |
I don't rotate it either, started May 20, 2008 only up to 19 meg. I leave it alone for historical sake.
As far as logrotate and syslog-ng, there should be a syslog-ng in /etc/logrotate.d (placed there by syslog-ng at least on the version I use)
The relevant part (on my system)
| Code: | "/var/log/messages" /var/log/firewall {
missingok
sharedscripts
postrotate
/etc/init.d/syslog-ng reload > /dev/null 2>&1 || true
endscript
} |
So it restarts after rotating all the syslog files
Edit to add: it doesn't restart as in kill the running binary, but a reload ie HUP, which reads the config files and effectively restarts it.
_________________
PRIME x570-pro, 3700x, 6.1 zen kernel
gcc 13, profile 17.0 (custom bare multilib), openrc, wayland
Last edited by Anon-E-moose on Tue Nov 05, 2019 9:45 pm; edited 1 time in total |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Tue Nov 05, 2019 9:20 pm Post subject: |
|
|
Following more log inspection and analysis, have identified an instance without multiple destinations in one syslog-ng config line, that fails to restart logging after a logrotate.
That instance is syslog-ng itself. The original source is internal to syslog, and reports start, stop, reload (receipt of HUP signal), and statistics.
| Code: | destination syslogng { file("/var/log/syslog"); };
filter f_syslog { facility(syslog); };
log { source(src); filter(f_syslog); destination(syslogng); };
|
It appears the failure to automatically resume logging after logrotate is related to how syslog-ng opens log files, and how it handles file changes introduced by logrotate. I'm quite sure something in syslog-ng changed between 3.22.1-r1 and 3.23.1, that affects how syslog-ng picks up after a logrotate. Still not wanting to reload my dynamic firewall, am continuing to seek a solution other than restart or reload (not the same thing) syslog-ng,
Said another way, I am quite sure this "new" behavior is not related to a change in logrotate or cronie.
Edited to remove remarks critical of using restart by init script - the logrotate snippet using /etc/init.d/syslog-ng does a config reload, not a syslog-ng restart.
Further edit - reading syslog-ng options, syslog-ng is happy to create its own log files, for example using a date/time code as part of filename. Am going to experiment with logrotate "nocreate" and "copytruncate" options. Some of my affected logs are rotated weekly, so it'll be awhile before this route is tested.
Note that both logrotate and syslog-ng allow specifying the owner and group on file creation.
Further-further edit: Built a test rig where syslog-ng sent iptables logs to a /var/log/test.log, and made a separate logrotate config to rotate that. This way it is possible to logrotate on command, and test the interaction between syslog-ng and logrotate.
Logrotate "nocreate" option is a bust. One rotation, and the var/log/test.log is not recreated until syslog-ng config is reloaded.
Logrotate "copytruncate" option seems to work. var/log/test.log is truncated to zero size, but syslog-ng does not lose track of where to put new entries. |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Wed Jan 08, 2020 10:34 pm Post subject: |
|
|
Thanks for the testing, cboldt! So I agree that something changed between syslog-ng-3.22.1 and 3.23.1, but I'm not sure what. I have looked through the changelogs, but I don't see anything overt that would cause this difference in behaviour.
Is the solution to use "copytruncate" with essentially any configuration utilising logrotate? That doesn't seem like the "right" solution, but if it works, it's better than having a manual syslog-ng restart via cron. 
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Wed Jan 08, 2020 10:39 pm Post subject: |
|
|
I don't know that this is the best solution, but the one that I'm going to test this weekend is changing "reload" to "restart" in the postrotate script under /etc/logrotate.d/syslog-ng:
| Code: |
# cat /etc/logrotate.d/syslog-ng
#
# Syslog-ng logrotate snippet for Gentoo Linux
# contributed by Michael Sterrett
#
## 20200108 - Changed postrotate script to "restart" from "reload"
/var/log/messages {
delaycompress
missingok
sharedscripts
postrotate
/etc/init.d/syslog-ng restart > /dev/null 2>&1 || true
endscript
}
|
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Thu Jan 09, 2020 12:35 pm Post subject: |
|
|
I use copytruncate for the log files filled by syslog-ng. Basically all the "destination" entries in syslog-ng.conf --- or in my case, in /etc/syslog-ng/syslog-local.conf which is referred to by syslog-ng.conf. That ends up being most but not all the logging.
Without copytruncate, I found syslog-ng "reload" or "restart" to work equally well as far as picking up logging after logrotate.
syslog-ng-3.22 is buggy for other reasons, but the "log dropping" behavior exists in 3.23, 3.24, and 3.25 so I keep using logrotate copytruncate method. That essentially keeps the same inode for the log file. |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Mon Jan 13, 2020 11:21 pm Post subject: |
|
|
So changing it from 'reload' to 'restart' didn't fix the problem (much like you had indicated). I've reverted that change, and added the 'copytruncate' directive to /etc/logrotate.conf for all destination logs mentioned in syslog-ng.conf:
| Code: |
# cat /etc/logrotate.conf
#
# Default logrotate(8) configuration file for Gentoo Linux.
# See "man logrotate" for details.
# rotate log files weekly.
weekly
#daily
# keep 4 weeks worth of backlogs.
rotate 4
# create new (empty) log files after rotating old ones.
create
# use date as a suffix of the rotated file.
dateext
# compress rotated log files.
compress
notifempty
nomail
noolddir
# packages can drop log rotation information into this directory.
include /etc/logrotate.d
# no packages own wtmp and btmp -- we'll rotate them here.
/var/log/wtmp {
monthly
create 0664 root utmp
minsize 1M
rotate 1
}
/var/log/btmp {
missingok
monthly
create 0600 root utmp
rotate 1
}
# system-specific logs may be also be configured here.
## 20200113 - Added 'copytruncate' to all these logs as logging stops every Monday morning during a logrotate
/var/log/auth.log {
copytruncate
weekly
rotate 4
create
dateext
compress
}
/var/log/cron.log {
copytruncate
weekly
rotate 4
create
dateext
compress
}
/var/log/daemon.log {
copytruncate
weekly
rotate 4
create
dateext
compress
}
/var/log/mail.log {
copytruncate
weekly
rotate 4
create
dateext
compress
}
/var/log/messages {
copytruncate
weekly
rotate 4
create
dateext
compress
}
|
We'll see if this works with my current configuration, but it still seems like a hackish workaround. Hopefully we can get a better understanding of what changed to cause this regression.
Cheers,
Nathan Zachary
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
cboldt
Veteran
Joined: 24 Aug 2005
Posts: 1046
|
| Posted: Tue Jan 14, 2020 1:05 pm Post subject: |
|
|
syslog-ng reload and restart both fixed the logging issue for me. Either one caues syslog-ng to work with the destinations as "new known" files.
Logrotate default method makes new files with new inodes, and that is why syslog-ng logging stops at log rotation other than by sysllog-ng.
I don't restart or reload systlog-ng after log rotation - i don't want to for unrelated reasons. I agree that use of copytruncate is a kludge, but it's one I don't mind living with |
|
| Back to top |
|
|
Tony0945
Watchman
Joined: 25 Jul 2006
Posts: 5127
Location: Illinois, USA
|
| Posted: Tue Jan 14, 2020 5:26 pm Post subject: |
|
|
| Perhaps it's better to migrate to metalog? syslog-ng seems had to work with. Is metalog any better? |
|
| Back to top |
|
|
|
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
|
Other Things Gentoo
