OK, I think we've identified the primary cause of our syslog message loss.
On our DB server, we have backups taken around 8pm which include a DB dump. In
addition to this, the DB server runs within a VM, mounts the Syslog database
over NFS, and between all of this we think its simply being overloaded when our
syslog server sends syslogs over to MariaDB.
I've upped the impstats to run 3 times over 10 minutes. I've included the
rsyslog-stats from last evening. In this, I've disabled our ELK Stack output,
so logs are only going to the local disk and our DB server.
Right after 8pm, I can see the main queue filling up and things stop
processing. I haven't added in the dynacache or output queues quite yet, right
now just getting some baseline measurements.
Levi Wilbert
HPC & Linux Systems Administrator
ARCC - Division of Research and Economic Development
Information Technology Ctr 226
1000 E. University Avenue, Laramie, WY 82071-200
________________________________
From: David Lang <da...@lang.hm>
Sent: Friday, February 7, 2025 4:27 PM
To: Levi Wilbert <lwilb...@uwyo.edu>
Cc: David Lang <da...@lang.hm>; Levi Wilbert via rsyslog
<rsyslog@lists.adiscon.com>
Subject: Re: [rsyslog] Rsyslog Losing Messages
Levi Wilbert wrote:
Awesome, thank you this is very helpful!
For the dynacache, we have around 600 or so hosts we collect logs from on this
particular server. I read this shouldn't practically be set above 1000 unless
it's for very particular situations, I'm thinking of starting it around 100-200
in that area, would you agree/disagree?
No, if you expect to be writing to 600 files during one rotation cycle, you need
to have the cache size >= 600
strawman example, if you get 600 hosts sending you one message per
minute (and assume in the same orderand have your cache size set to 599.
the first 599 messages that arrive will open a file and write one message to it.
Then the message from host 600 arrives. Rsyslog will flush the buffer and close
the file for host 1, open the file for host 600, write the log to the buffer.
Then the next message from host 1 arrives. Rsyslog will flush the buffer and
close the file for hsot 2, hoepn the file for host 1, write the log to the
buffer.
and continue to have to flush, close, and open the files for every log message
that arrives.
(now, in practice, the logs don't arrive exactly in the same order from every
host perfectly interleaved, but this is a simplified, worst case example)
you should ALWAYS have the dynafilecachesize larger than the number of files you
expect to be writing to. HAving the number be higher just means you have more
files open (make sure you have your max file limits set large enough, for many
distros 1000 files is the default limit, which is why it's mentioned in the
docs)
Just to clarify some on the output of rsyslog-stats, is the 'enqueued' counter
on the 'main Q' the number of messages that have been queued and then dequeued
(i.e., sent to their out/handled)? And within the same lines, the 'size' is
the current queue size?
it's the number added to the queue, enqueued - size is the number that have been
processed. You can set it to zero all stats each time it reports, or leave
things like enqueued, processed, etc as running totals (there is a race
condition with zeroing the stats in a multi-threaded environment that can cause
them to be slightly off, but I tend to zero them as it's easier to understand.
David Lang
I'm doing further testing by disabling our outputs temporarily, to what is
causing the blocking. I'll update as discover more!
Levi Wilbert
HPC & Linux Systems Administrator
ARCC - Division of Research and Economic Development
Information Technology Ctr 226
1000 E. University Avenue, Laramie, WY 82071-200
________________________________
From: David Lang <da...@lang.hm>
Sent: Wednesday, February 5, 2025 3:25 PM
To: Levi Wilbert <lwilb...@uwyo.edu>
Cc: David Lang <da...@lang.hm>; Levi Wilbert via rsyslog
<rsyslog@lists.adiscon.com>
Subject: Re: [rsyslog] Rsyslog Losing Messages
Ok, one thing I see is that you have a dynafilecachesize that's too small
Tue Feb 4 22:10:36 2025: dynafile cache host_messages: origin=omfile
requests=4316034 level0=3811573 missed=380153 evicted=380143 maxused=10
closetimeouts=0
This has the system spending a lot of time closing a file, opening a new one,
writing a log to it, and then repeating the process a LOT. That can drastically
slow down your log processing. Since maxused is 10, that indicates defaults. Set
the cach size to something larger than the number of files you expect to have
open
another one is
Tue Feb 4 22:30:36 2025: action-7-ommysql: origin=core.action
processed=2270931 failed=0 suspended=0 suspended.duration=0 resumed=0
It looks like many of your outputs are not seeing the processed number increase,
so something is blocking, causing the queues to fill and then everything stops.
take a look at https://www.rsyslog.com/doc/whitepapers/queues_analogy.html and
consider adding some queues to some of the actions that could block if the
remote system pauses. you do have a queue on action 8 (looks like the elk
forward) and that queue is not filling up
try setting the pstats to output more frequently than once every 10 min and have
it running before the time that logs stop processing, it may give a little more
detail. Look for a time when the queue size goes from near zero (normal
operations) to something much larger, hopefully it happens slowly enough for us
to see some stats.
I surprised we aren't seeing any failed or syspended (other than open failed for
inbound tcp connections)
I don't think this section is doing what you expect:
$ActionQueueType LinkedList # use asynchronous processing
$ActionQueueFileName syslogdb1 # set file name, also enables disk mode
$ActionResumeRetryCount -1 # infinite retries on insert failure
$ActionQueueSaveOnShutdown on # save in-memory data if rsyslog shuts down
$ActionQueueHighWatermark 51200000 # Switch to disk mode when queue =>
~4.76GiB ( 5120000000 x 512 bytes avg msg size)
$ActionQueueLowWatermark 25600000 # Exit disk mode when queue < ~1.86GiB
$ActionQueueMaxDiskSpace 30G
This is setting up a queue for the next action in the config that is not using
the action() format (I think this is the writes to
/var/log/rsyslog/%HOSTNAME%/messages but it's really hard to be sure). This is
one of the biggest reasons why this format is depreiciated, it's hard even for
experts to keep track of what's happening, especially when the config is spread
across multiple files
David Lang
On Wed, 5 Feb 2025, Levi Wilbert wrote:
Date: Wed, 5 Feb 2025 20:52:18 +0000
From: Levi Wilbert <lwilb...@uwyo.edu>
To: David Lang <da...@lang.hm>
Cc: Levi Wilbert via rsyslog <rsyslog@lists.adiscon.com>
Subject: Re: [rsyslog] Rsyslog Losing Messages
In fact, I've enabled rsyslog-stats already. It does look like the queue has
been getting hammered, so much that the main queue is full, with millions of
messages enqueued. I've attached an hours worth of rsyslog-stats during the
impacted time.
Levi Wilbert
HPC & Linux Systems Administrator
ARCC - Division of Research and Economic Development
Information Technology Ctr 226
1000 E. University Avenue, Laramie, WY 82071-200
________________________________
From: David Lang <da...@lang.hm>
Sent: Wednesday, February 5, 2025 1:39 PM
To: Levi Wilbert <lwilb...@uwyo.edu>
Cc: David Lang <da...@lang.hm>; Levi Wilbert via rsyslog
<rsyslog@lists.adiscon.com>
Subject: Re: [rsyslog] Rsyslog Losing Messages
I forgot to mention the other reason you may not see logs, if an output blocks,
all log processing halts (unless you have action/ruleset queues in place)
In your configs, you send logs to elasticsearch using omfwd over TCP, if
eleasticsearch can't handle the message, all log processing will pause. The logs
will get queued up (to the limits of your queues) and be delivered later. But if
your queues get overrun, you may lose logs.
I would suggest that you enable impstats, writing to a local file, and see what
it shows during the time that log processing isn't happening.
David Lang
On Wed, 5 Feb 2025, Levi
Wilbert wrote:
Date: Wed, 5 Feb 2025 20:18:34 +0000
From: Levi Wilbert <lwilb...@uwyo.edu>
To: David Lang <da...@lang.hm>,
Levi Wilbert via rsyslog <rsyslog@lists.adiscon.com>
Subject: Re: [rsyslog] Rsyslog Losing Messages
1. your VM server gets overloaded and stops scheduling your VM for a chunk of
time
*
The VM itself appears fine. I can SSH to it, open 514/tcp w/ telnet from a
remote host, cd, view files, etc.
2. you have a network problem (overload, interupption) that causes the packets
to not get through.
*
It looks like packets are hitting the syslog server. I tested with a VM on
which I generated logs during the impacted period, and could see traffic
incoming into the syslog server using tcpdump. Granted, visually looking at it
I can't guarantee every log is getting through, but I can see syslog traffic
from that host, and no logs ever appear in the any of output destinations.
3. you have a flood of messages that are arriving faster than they can be
processed and your network buffers on your OS are overflowing (from your
description, this doesn't seem likely)
for the network problem, this doesn't have to be on your VM server.
For example, if you are sending the logs via UDP and have a router that gets
overloaded with a nightly backup, it is allowed to drop UDP packets.
*
this is something I can look into, but as I mentioned in #2, I tested w/ a VM
sending syslogs during the impacted times, could see syslog traffic arriving on
the syslog server port, but those logs never appear to get passed along.
So look at what else is going on on the network/systems around the time of your
log outage? is that when a nightly backup runs somewhere? other big batch job?
Additionally, I can share our config (included: /etc/rsyslog.conf,
etc/rsyslog.d/*.conf).
Levi Wilbert
HPC & Linux Systems Administrator
ARCC - Division of Research and Economic Development
Information Technology Ctr 226
1000 E. University Avenue, Laramie, WY 82071-200
________________________________
From: David Lang <da...@lang.hm>
Sent: Wednesday, February 5, 2025 10:55 AM
To: Levi Wilbert via rsyslog <rsyslog@lists.adiscon.com>
Cc: Levi Wilbert <lwilb...@uwyo.edu>
Subject: Re: [rsyslog] Rsyslog Losing Messages
◆ This message was sent from a non-UWYO address. Please exercise caution when
clicking links or opening attachments from external sources.
we would need to see your config to have any idea what's going on (are you
sending via UDP, TCP, RELP, other??)
But there are a few basic things that can go wrong
1. your VM server gets overloaded and stops scheduling your VM for a chunk of
time
2. you have a network problem (overload, interupption) that causes the packets
to not get through.
3. you have a flood of messages that are arriving faster than they can be
processed and your network buffers on your OS are overflowing (from your
description, this doesn't seem likely)
for the network problem, this doesn't have to be on your VM server.
For example, if you are sending the logs via UDP and have a router that gets
overloaded with a nightly backup, it is allowed to drop UDP packets.
So look at what else is going on on the network/systems around the time of your
log outage? is that when a nightly backup runs somewhere? other big batch job?
David Lang
On Wed, 5 Feb 2025, Levi Wilbert via rsyslog wrote:
Date: Wed, 5 Feb 2025 16:18:15 +0000
From: Levi Wilbert via rsyslog <rsyslog@lists.adiscon.com>
To: "rsyslog@lists.adiscon.com" <rsyslog@lists.adiscon.com>
Cc: Levi Wilbert <lwilb...@uwyo.edu>
Subject: [rsyslog] Rsyslog Losing Messages
Greetings,
We are using Rsyslog on RHEL9.3 to gather logs in an environment of around 600
or so servers. All of these servers forward directly to our single syslog
server, which then forwards the logs along to a mysql db (runs on a separate
server), ELK stack, and to file locally on the system.
I've noticed at around the same time each night, rsyslog begins dropping most
of the incoming logs, and there is a gap where almost all logs simply aren't
recorded.
Network connectivity seems ok, as I am able to connect to the syslog server,
connect to 514/TCP port (we also use UDP), and I can see logs hitting the
server using tcpdump on the NIC.
The syslog server is a virtualized server w/ 4 CPU cores and 8G of RAM.
Would anyone have any idea on how to tune rsyslog to avoid these periods of log
loss?
Levi Wilbert
HPC & Linux Systems Administrator
ARCC - Division of Research and Economic Development
Information Technology Ctr 226
1000 E. University Avenue, Laramie, WY 82071-200
_______________________________________________
rsyslog mailing list
https://lists.adiscon.net/mailman/listinfo/rsyslog
http://www.rsyslog.com/professional-services/
What's up with rsyslog? Follow https://twitter.com/rgerhards
NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of
sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE
THAT.
