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
--
Sent from Postbox
<https://www.postbox-inc.com/?utm_source=email&utm_medium=siglink&utm_campaign=reach>
_______________________________________________
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.
