Re: rsyslog adding old entries again
Hi all,
I have now tried to use packetfence on CentOS, as they claim CentOS is
their best supported platform. Now rsyslog logging works as expected:
- shutdown rsyslog
- delete files from the log directory
- start rsyslog
and only new/recent logs start appearing.
I have no idea why debian behaves as it does, but I'm happy to use
centos for this particular install.
Thanks again for your answers.
MJ
On 14-12-2019 9:58, Andrei POPESCU wrote:
On Sb, 14 dec 19, 10:28:29, Andrei POPESCU wrote:
On Vi, 13 dec 19, 20:47:49, mj wrote:
Hi Andrei,
So:
root@pf:~# ps aux | grep rsyslog
root 11250 0.8 3.3 872116 274200 ? Ssl 15:37 2:26
/usr/sbin/rsyslogd -n
root 23873 0.0 0.0 12780 968 pts/0S+ 20:25 0:00 grep rsyslog
root@pf:~# service rsyslog stop
root@pf:~# ps aux | grep rsyslog
root 23909 0.0 0.0 12780 1020 pts/0S+ 20:25 0:00 grep rsyslog
root@pf:~# rm -f /usr/local/pf/logs/*
root@pf9:~# lsof | grep /usr/local/pf/logs
snmptrapd 23941 root3w REG8,1
23 67605574 /usr/local/pf/logs/snmptrapd.log
and yes: the file snmptrapd.log is the exception, all other files (20, 25 of
them) are gone, remain gone, and are not listed in lsof as open.
Then, when starting rsyslog again, this time in debug mode ("rsyslogd -dn")
it shows that it IS in fact writing those logs:
[...]
As you can see from the lines above: these are old log lines from Dec 6.
On a quick look at the "queued" mode seems to be related. As I'm not
^^^
the manpage
Sorry, edited it out.
using rsyslog myself I can't help further.
Kind regards,
Andrei
Re: rsyslog adding old entries again
On Sb, 14 dec 19, 10:28:29, Andrei POPESCU wrote:
> On Vi, 13 dec 19, 20:47:49, mj wrote:
> > Hi Andrei,
> >
> > So:
> >
> > > root@pf:~# ps aux | grep rsyslog
> > > root 11250 0.8 3.3 872116 274200 ? Ssl 15:37 2:26
> > > /usr/sbin/rsyslogd -n
> > > root 23873 0.0 0.0 12780 968 pts/0S+ 20:25 0:00 grep
> > > rsyslog
> > > root@pf:~# service rsyslog stop
> > > root@pf:~# ps aux | grep rsyslog
> > > root 23909 0.0 0.0 12780 1020 pts/0S+ 20:25 0:00 grep
> > > rsyslog
> >
> > > root@pf:~# rm -f /usr/local/pf/logs/*
> > > root@pf9:~# lsof | grep /usr/local/pf/logs
> > > snmptrapd 23941 root3w REG8,1
> > > 23 67605574 /usr/local/pf/logs/snmptrapd.log
> >
> > and yes: the file snmptrapd.log is the exception, all other files (20, 25 of
> > them) are gone, remain gone, and are not listed in lsof as open.
> >
> > Then, when starting rsyslog again, this time in debug mode ("rsyslogd -dn")
> > it shows that it IS in fact writing those logs:
>
> [...]
>
> > As you can see from the lines above: these are old log lines from Dec 6.
>
> On a quick look at the "queued" mode seems to be related. As I'm not
^^^
the manpage
Sorry, edited it out.
> using rsyslog myself I can't help further.
Kind regards,
Andrei
--
http://wiki.debian.org/FAQsFromDebianUser
signature.asc
Description: PGP signature
Re: rsyslog adding old entries again
On Vi, 13 dec 19, 20:47:49, mj wrote:
> Hi Andrei,
>
> So:
>
> > root@pf:~# ps aux | grep rsyslog
> > root 11250 0.8 3.3 872116 274200 ? Ssl 15:37 2:26
> > /usr/sbin/rsyslogd -n
> > root 23873 0.0 0.0 12780 968 pts/0S+ 20:25 0:00 grep
> > rsyslog
> > root@pf:~# service rsyslog stop
> > root@pf:~# ps aux | grep rsyslog
> > root 23909 0.0 0.0 12780 1020 pts/0S+ 20:25 0:00 grep
> > rsyslog
>
> > root@pf:~# rm -f /usr/local/pf/logs/*
> > root@pf9:~# lsof | grep /usr/local/pf/logs
> > snmptrapd 23941 root3w REG8,1
> > 23 67605574 /usr/local/pf/logs/snmptrapd.log
>
> and yes: the file snmptrapd.log is the exception, all other files (20, 25 of
> them) are gone, remain gone, and are not listed in lsof as open.
>
> Then, when starting rsyslog again, this time in debug mode ("rsyslogd -dn")
> it shows that it IS in fact writing those logs:
[...]
> As you can see from the lines above: these are old log lines from Dec 6.
On a quick look at the "queued" mode seems to be related. As I'm not
using rsyslog myself I can't help further.
Kind regards,
Andrei
--
http://wiki.debian.org/FAQsFromDebianUser
signature.asc
Description: PGP signature
Re: rsyslog adding old entries again
On Fri, Dec 13, 2019 at 03:07:56PM -0500, Greg Wooledge wrote: > On Fri, Dec 13, 2019 at 08:47:49PM +0100, mj wrote: > > > root@pf:~# ps aux | grep rsyslog > > > root 11250 0.8 3.3 872116 274200 ? Ssl 15:37 2:26 > > > /usr/sbin/rsyslogd -n > > > root 23873 0.0 0.0 12780 968 pts/0S+ 20:25 0:00 grep > > > rsyslog > > > root@pf:~# service rsyslog stop > > > root@pf:~# ps aux | grep rsyslog > > > root 23909 0.0 0.0 12780 1020 pts/0S+ 20:25 0:00 grep > > > rsyslog > > > > > root@pf:~# rm -f /usr/local/pf/logs/* > > > root@pf9:~# lsof | grep /usr/local/pf/logs > > > snmptrapd 23941 root3w REG8,1 > > > 23 67605574 /usr/local/pf/logs/snmptrapd.log > > > > and yes: the file snmptrapd.log is the exception, all other files (20, 25 of > > them) are gone, remain gone, and are not listed in lsof as open. > > So, it sounds like you want to kill snmptrapd (instead of, or in addition > to, killing rsyslogd) before you unlink these log files. It seems that snmptrapd accepts a SIGHUP to close and re-open its output file (if it's set up to output to a file, that is). From its man page: -o FILE Log formatted incoming traps to FILE. Upon receipt of a SIGHUP, the daemon will close and re-open the log file. This feature is useful when rotating the log file with other utilities such as logrotate. This option is being deprecated, and '-Lf FILE' should be used instead. But it can be set up to log via syslog, so one just has to take care of syslog (which also takes a SIGHUP, afaik). Cheers -- "if all else fails, read the instructions" tomás signature.asc Description: Digital signature
Re: rsyslog adding old entries again
On Fri, Dec 13, 2019 at 08:47:49PM +0100, mj wrote: > > root@pf:~# ps aux | grep rsyslog > > root 11250 0.8 3.3 872116 274200 ? Ssl 15:37 2:26 > > /usr/sbin/rsyslogd -n > > root 23873 0.0 0.0 12780 968 pts/0S+ 20:25 0:00 grep > > rsyslog > > root@pf:~# service rsyslog stop > > root@pf:~# ps aux | grep rsyslog > > root 23909 0.0 0.0 12780 1020 pts/0S+ 20:25 0:00 grep > > rsyslog > > > root@pf:~# rm -f /usr/local/pf/logs/* > > root@pf9:~# lsof | grep /usr/local/pf/logs > > snmptrapd 23941 root3w REG8,1 > > 23 67605574 /usr/local/pf/logs/snmptrapd.log > > and yes: the file snmptrapd.log is the exception, all other files (20, 25 of > them) are gone, remain gone, and are not listed in lsof as open. So, it sounds like you want to kill snmptrapd (instead of, or in addition to, killing rsyslogd) before you unlink these log files. If this were a traditional daemon, I might give the alternative answer, "Or you could truncate the files instead of unlinking them." But it seems like snmptrapd is doing something *weird*, perhaps storing its own copy of the logs in memory, and rewriting them to files when it discovers that they are not on disk. So, for this particular case, truncating the log files may not work. But killing snmptrapd should.
Re: rsyslog adding old entries again
Hi Andrei,
So:
root@pf:~# ps aux | grep rsyslog
root 11250 0.8 3.3 872116 274200 ? Ssl 15:37 2:26
/usr/sbin/rsyslogd -n
root 23873 0.0 0.0 12780 968 pts/0S+ 20:25 0:00 grep rsyslog
root@pf:~# service rsyslog stop
root@pf:~# ps aux | grep rsyslog
root 23909 0.0 0.0 12780 1020 pts/0S+ 20:25 0:00 grep rsyslog
root@pf:~# rm -f /usr/local/pf/logs/*
root@pf9:~# lsof | grep /usr/local/pf/logs
snmptrapd 23941 root3w REG8,1
23 67605574 /usr/local/pf/logs/snmptrapd.log
and yes: the file snmptrapd.log is the exception, all other files (20,
25 of them) are gone, remain gone, and are not listed in lsof as open.
Then, when starting rsyslog again, this time in debug mode ("rsyslogd
-dn") it shows that it IS in fact writing those logs:
5849.717653159:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 383, strt data Dec 6 16:22:56 pf9 pfconfig: pfconfig(709)
ERROR: [mac:[undef]] Caught error DBI
connect('database=pf;host=localhost;port=3306'
5849.717657173:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 289, strt data Dec 6 16:22:56 pf9 pfconfig: pfconfig(709)
ERROR: [mac:[undef]] Couldn't connect to MySQL database to access L2. This is a
majo
5849.717661550:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 99, strt data Dec 6 16:22:56 pf9 pfconfig: Could not write
namespace FilterEngine::SwitchScopes() to L2 cache !
5849.717665624:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 170, strt data Dec 6 16:22:56 pf9 pfconfig: pfconfig(709)
ERROR: [mac:[undef]] Could not write namespace FilterEngine::SwitchScopes() to L2
ca
5849.717669576:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 383, strt data Dec 6 16:22:56 pf9 pfconfig: pfconfig(709)
ERROR: [mac:[undef]] Caught error DBI
connect('database=pf;host=localhost;port=3306'
5849.717697926:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 289, strt data Dec 6 16:22:56 pf9 pfconfig: pfconfig(709)
ERROR: [mac:[undef]] Couldn't connect to MySQL database to access L2. This is a
majo
5849.717702051:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fccf403be50, lenBuf 383, strt data Dec 6 16:22:56 pf9 pfconfig: pfconfig(709)
ERROR: [mac:[undef]] Caught error DBI
connect('database=pf;host=localhost;port=3306'
As you can see from the lines above: these are old log lines from Dec 6.
I also see non-packetfence lines, so this is not specific for the
packetfence install, sample:
5860.210336266:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fcd0c007dd0, lenBuf 95, strt data Dec 6 16:31:31 pf9 kernel: SGI XFS with
ACLs, security attributes, realtime, no debug enabled
5860.210339962:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fcd0c007dd0, lenBuf 63, strt data Dec 6 16:31:31 pf9 kernel: XFS (sda1):
Mounting V5 Filesystem
5860.210343827:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fcd0c007dd0, lenBuf 87, strt data Dec 6 16:31:31 pf9 kernel: usb 1-1: new
full-speed USB device number 2 using uhci_hcd
5860.210347393:main Q:Reg/w0 : omfile: write to stream, pData->pStrm
0x7fcd0c007dd0, lenBuf 77, strt data Dec 6 16:31:31 pf9 kernel: XFS (sda1):
Starting recovery (logdev: internal)
The date and time on the system is correct. The system has been rebooted
repeatedly.
Anyone who can explain?
MJ
Re: rsyslog adding old entries again
On Vi, 13 dec 19, 15:51:32, mj wrote: > > And what I do: > - service rsyslog stop > - rm -f /usr/local/pf/logs/* > - ls /usr/local/pf/logs/ to confirm that it *is* empty > - service rsyslog start > > and then all logfiles have reappeared (are regenerated?) in > /usr/local/pf/conf with timestamp NOW, filled with entries dating back to > dec 6. > > This is debian 9.11. Any other info that is required.? It's possible rsyslog or something else is keeping the files open. I would suggest to: 1. Ensure rsyslog is really stopped: a. If you have systemd check if there is also a .socket unit that must be stopped. b. Use 'ps' or similar to check for other instances or rsyslog. 2. Check if something else is keeping the files open, e.g. with 'lsof' Hope this helps, Andrei -- http://wiki.debian.org/FAQsFromDebianUser signature.asc Description: PGP signature
Re: rsyslog adding old entries again
Hi Tomás,
Thanks for your reply! More details, ok :-)
The relevant rsyslog configuration belongs to packetfence.org, and is:
$ModLoad imuxsock # provides support for local system logging (e.g. via logger
command)
$ModLoad imjournal # provides access to the systemd journal
# Disable rate-limiting of syslog
$SystemLogRateLimitInterval 0
$SystemLogRateLimitBurst 0
# Disable rate-limiting of journal messages
$imjournalRatelimitInterval 0
$imjournalRatelimitBurst 0
# Disable escaping of control characters (like the ones used by Data::Dumper)
$EscapeControlCharactersOnReceive off
# define the user and group of the file created
$FileGroup pf
# Allow the pf group to read log files
$umask 0027
# fingerbank.log
if $syslogtag contains "fingerbank" then {
-/usr/local/pf/logs/fingerbank.log
stop
}
# httpd.aaa.error
if $programname contains "httpd_aaa_err" then {
-/usr/local/pf/logs/httpd.aaa.error
stop
}
# pfdhcp.log
if $programname == "pfdhcp" then {
-/usr/local/pf/logs/pfdhcp.log
stop
}
(followed by many more similar lines)
And what I do:
- service rsyslog stop
- rm -f /usr/local/pf/logs/*
- ls /usr/local/pf/logs/ to confirm that it *is* empty
- service rsyslog start
and then all logfiles have reappeared (are regenerated?) in
/usr/local/pf/conf with timestamp NOW, filled with entries dating back
to dec 6.
This is debian 9.11. Any other info that is required.?
Thanks!
MJ
Re: rsyslog adding old entries again
On Fri, Dec 13, 2019 at 01:21:38PM +0100, mj wrote: > Hi, > > I'm sure this is a faq, but I cannot find the answer. :-( > > On debian 9, rsyslog with some rules to log to certain specific files. > > Now: when I: > - stop rsyslog > - delete those specific log files Which files do you delete? How do you do it? > - reboot my server > > I would expect to find only *new* and *recent* log lines in those files. > > However: old entries are appearing also, up to weeks ago. So it > seems rsyslog actually noticies that those entries are not in the > files, and adds them again. I don't think rsyslog is doing that :-) It might look /as if/ rsyslog did that. That's why I asked for some details. So the more details you provide, the easier to solve the puzzle. Cheers -- tomás signature.asc Description: Digital signature
rsyslog adding old entries again
Hi, I'm sure this is a faq, but I cannot find the answer. :-( On debian 9, rsyslog with some rules to log to certain specific files. Now: when I: - stop rsyslog - delete those specific log files - reboot my server I would expect to find only *new* and *recent* log lines in those files. However: old entries are appearing also, up to weeks ago. So it seems rsyslog actually noticies that those entries are not in the files, and adds them again. I don't want that :-) How is that behaviour configured, can I stop rsyslog from doing that? Or is there an other way to empty these log files, and start again from scratch, with only new entries? Again: really seems like a FAQ, but I can't find it... MJ
