what version of rsyslog is this? I'm not seeing the queue stats for the disk
queue that you say you have defined (I no longer have your original message with
your full config)
I do not understand what is happening, main queue size is 0 so imtcp should be
able to accept new messages, your outputs are not showing syspended, the queue
says it has never been full
David Lang
On Fri, 2 Nov 2018, Rory Toma wrote:
If I'm reading right, imtcp thinks it has no new messages?
Fri Nov 2 17:12:09 2018: forward1: origin=core.action processed=712779
failed=0 suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 17:12:09 2018: forward2: origin=core.action processed=0 failed=0
suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 17:12:09 2018: imtcp(110): origin=imtcp submitted=712779
Fri Nov 2 17:12:09 2018: resource-usage: origin=impstats utime=916388169
stime=142221083 maxrss=90124 minflt=26083 majflt=0 inblock=8 oublock=312
nvcsw=321384 nivcsw=1171 openfiles=1434
Fri Nov 2 17:12:09 2018: main Q: origin=core.queue size=0 enqueued=712779
full=0 discarded.full=0 discarded.nf=0 maxqsize=3548
Fri Nov 2 17:13:09 2018: global: origin=dynstats
Fri Nov 2 17:13:09 2018: forward1: origin=core.action processed=712779
failed=0 suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 17:13:09 2018: forward2: origin=core.action processed=0 failed=0
suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 17:13:09 2018: imtcp(110): origin=imtcp submitted=712779
Fri Nov 2 17:13:09 2018: resource-usage: origin=impstats utime=976430226
stime=142221083 maxrss=90124 minflt=26083 majflt=0 inblock=8 oublock=328
nvcsw=321385 nivcsw=1187 openfiles=1434
Fri Nov 2 17:13:09 2018: main Q: origin=core.queue size=0 enqueued=712779
full=0 discarded.full=0 discarded.nf=0 maxqsize=3548
Fri Nov 2 17:14:09 2018: global: origin=dynstats
Fri Nov 2 17:14:09 2018: forward1: origin=core.action processed=712779
failed=0 suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 17:14:09 2018: forward2: origin=core.action processed=0 failed=0
suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 17:14:09 2018: imtcp(110): origin=imtcp submitted=712779
Fri Nov 2 17:14:09 2018: resource-usage: origin=impstats utime=1036475780
stime=142221083 maxrss=90124 minflt=26083 majflt=0 inblock=8 oublock=336
nvcsw=321386 nivcsw=1203 openfiles=1434
Fri Nov 2 17:14:09 2018: main Q: origin=core.queue size=0 enqueued=712779
full=0 discarded.full=0 discarded.nf=0 maxqsize=3548
David Lang wrote on 11/2/18 4:05 PM:
On Fri, 2 Nov 2018, Rory Toma wrote:
WHat am I looking for? As far as I can tell, the number enqueued remains
constant for 15 minutes, then starts up again.
you should see the number processed continue to climb, and the queue sizes
drop gradually, when they drop enough, it will start accepting new
messages.
to avoid your impstats logs getting delayed, write them to a file directly
(or use a separate ruleset that has it's own queue for the impstats output)
David Lang
David Lang wrote on 11/2/18 3:53 PM:
On Fri, 2 Nov 2018, Rory Toma wrote:
Interesting. It stopped processing for 15 minutes, then started to
spontaneously process incoming packets again,
look at the impstats output, I'll bet that it shows that it started
processing messages again, allowing for more messages to be accepted.
David Lang
Rory Toma via rsyslog wrote on 11/2/18 4:18 PM:
OK, so the submitted maxes out for imtcp at submitted=583161
At this point, rsyslog thinks there are no more messages, even though
tcpdump shows a ton. It's as if imtcp just stops working.
David Lang wrote on 11/2/18 2:58 PM:
On Fri, 2 Nov 2018, Rory Toma wrote:
OK, turned off counter reset. Also, I noticed that when I restarted,
if I waited about 2 minutes for all connections to clear out of
FIN_WAIT, et al... It seems to log better.
Now we wait an hour...
So now I see:
Fri Nov 2 15:52:49 2018: imtcp(110): origin=imtcp submitted=142983
Fri Nov 2 15:52:49 2018: resource-usage: origin=impstats
utime=12115102 stime=2320953 maxrss=56332 minflt=16662 majflt=0
inblock=8 oublock=16 nvcsw=37439 nivcsw=99 openfiles=334
Fri Nov 2 15:52:49 2018: main Q: origin=core.queue size=0
enqueued=142983 full=0 discarded.full=0 discarded.nf=0
maxqsize=58676
Fri Nov 2 15:53:49 2018: global: origin=dynstats
Fri Nov 2 15:53:49 2018: forward1: origin=core.action
processed=153749 failed=0 suspended=0 suspended.duration=0 resumed=0
Fri Nov 2 15:53:49 2018: forward2: origin=core.action processed=0
failed=0 suspended=0 suspended.duration=0 resumed=0
so this shows 142983 new messages arriving and 153749 processed (do
you have a disk queue somewhere to account for the extra messages??)
but at one point it was 58676 messages behind.
let it run a while to where the throughput slows down and let's see
what it shows.
I expect that the number enqueued will continue to climb, but the
number processed will taper off.
David Lang
David Lang wrote on 11/2/18 2:47 PM:
On Fri, 2 Nov 2018, Rory Toma wrote:
Date: Fri, 2 Nov 2018 15:44:10 -0700
From: Rory Toma <[email protected]>
To: David Lang <[email protected]>
Cc: Rory Toma via rsyslog <[email protected]>
Subject: Re: [rsyslog] Need help with high volume forwarding config
Does this mean that the packets are not even being forwarded?
Fri Nov 2 15:41:59 2018: main Q: origin=core.queue size=0
enqueued=8059 full=0 discarded.full=0 discarded.nf=0 maxqsize=632
so you received 8059 messages
Fri Nov 2 15:42:59 2018: global: origin=dynstats
Fri Nov 2 15:42:59 2018: action-0-builtin:omfwd:
origin=core.action processed=2591 failed=0 suspended=0
suspended.duration=0 resumed=0
and you sent 2591 messages through action 0 (this is why it's good
to have name='something' in the action to be sure you are looking at
the right thing
Fri Nov 2 15:42:59 2018: action-1-builtin:omfwd:
origin=core.action processed=0 failed=0 suspended=0
suspended.duration=0 resumed=0
Fri Nov 2 15:42:59 2018: imtcp(110): origin=imtcp submitted=2591
Fri Nov 2 15:42:59 2018: resource-usage: origin=impstats
utime=2954582 stime=383935 maxrss=19192 minflt=5924 majflt=0
inblock=8 oublock=32 nvcsw=3462 nivcsw=7 openfiles=250
Fri Nov 2 15:42:59 2018: main Q: origin=core.queue size=0
enqueued=2591 full=0 discarded.full=0 discarded.nf=0 maxqsize=632
but here it says there were only 2591 messages received, are you
resetting the counters each time? if so, it's probably best not to
do that right now.
David Lang
David Lang wrote on 11/2/18 2:34 PM:
On Fri, 2 Nov 2018, Rory Toma via rsyslog wrote:
We have several rsyslog hosts that forward to a logstash server.
It runs great, then after about an hour, data slows down until we
get a trickle. I did not see anything last time I ran impstats,
so I'm stuck. Here's my config (centos7, rsyslog 8.39) Any advice
how to debug this?
Well, logstash has lots of bottlenecks, is it keeping up or is it
refusing to accept more data?
what does impstats show? does it show the output to logstash being
suspended?
until you know that the recipient is able to receive more logs, I
don't know that it's worth looking at the rsyslog config.
David Lang
_______________________________________________
rsyslog mailing list
http://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.
