On Tue, 5 Aug 2014, Doug McClure wrote:
Just wow! Thank you so much for taking the time to provide such a detailed
response explaining what I'm seeing. Between yourself and David and
Rainer's input I think I have a good grasp on this. I hope I can write
something up on my blog and make this meaningful for many more!
Is there anyone with a parsing script to analyze the stats file as you
did? I'm aware of the upload utility on the rsyslog site, but creating
something reusable like a script --> chart/excel approach for profiling and
tuning may be useful.
impstats does have the option to zero the counters each time they are output.
Rainer works best with the cumulative counters, but I find that zeroing the
counters makes it much clearer to me what's going on.
Try it and see what works best for you.
David Lang
Doug
On Tue, Aug 5, 2014 at 11:32 AM, Dave Caplinger <
[email protected]> wrote:
In general, if you watch the impstats output, you can observe the input
message rate, the Main Q processing rate, and the output (action) queue
delivery rate. (This seems to match your config, just based onthe
impstats output.)
So in your case, inputs are imptcp (IPv4), imptcp (IPv6), and imuxsock.
Only imptctp IPv4 seems to have any significant input though:
Mon Aug 4 13:14:16 2014: imptcp(*/10514/IPv4): submitted=270859
Mon Aug 4 13:15:16 2014: imptcp(*/10514/IPv4): submitted=696044
Mon Aug 4 13:16:16 2014: imptcp(*/10514/IPv4): submitted=1382669
...
Mon Aug 4 13:44:18 2014: imptcp(*/10514/IPv4): submitted=11225030
Mon Aug 4 13:45:18 2014: imptcp(*/10514/IPv4): submitted=11505799
The deltas between each of these numbers are your per-minute input log
rate into rsyslog. For this period of time you are seeing between 168K and
823K messages/minute (2K-14K log/sec), which is not particularly large.
For rsyslog's processing, the Main Q is handling these promptly; note the
"size=" parameter below, which is almost always 0, indicating that all of
the messages are being delivered elsewhere (to an output/action queue), and
all the discarded numbers are also 0:
Mon Aug 4 13:14:16 2014: main Q: size=0 enqueued=270878 full=0
discarded.full=0 discarded.nf=0 maxqsize=31209
Mon Aug 4 13:15:16 2014: main Q: size=4150 enqueued=696078 full=0
discarded.full=0 discarded.nf=0 maxqsize=31209
Mon Aug 4 13:16:16 2014: main Q: size=0 enqueued=1382717 full=0
discarded.full=0 discarded.nf=0 maxqsize=31209
...
Mon Aug 4 13:44:18 2014: main Q: size=0 enqueued=11225727 full=0
discarded.full=0 discarded.nf=0 maxqsize=45639
Mon Aug 4 13:45:18 2014: main Q: size=0 enqueued=11506501 full=0
discarded.full=0 discarded.nf=0 maxqsize=45639
You'll probably also notice that the 'enqueued=' values entering the Main
Q above are very close (within 40 per minute) to the imptcp input rate we
saw above. This is the sum of all your input modules' logs, but also
includes messages generated by the pstats module itself since they also go
through the main queue by default.
Finally, you can do a similar analysis of the output side of this
equation. Note there are 3 separate log lines for the 'logstashforwarder'
queue:
Mon Aug 4 13:45:18 2014: logstashforwarder: processed=11506500 failed=0
Mon Aug 4 13:45:18 2014: logstashforwarder[DA]: size=73087110
enqueued=4611952 full=0 discarded.full=0 discarded.nf=0 maxqsize=74314630
Mon Aug 4 13:45:18 2014: logstashforwarder: size=245 enqueued=11506500
full=0 discarded.full=0 discarded.nf=0 maxqsize=17825
The first shows messages successfully 'processed' by this queue, which in
this case means delivery to either the Disk Assist files, or to the actual
remote destination. The second shows messages sent to Disk-Assist files
(because you have configured it to do so based on the watermark level of
number of messages sitting in this queue.) The final one shows messages
arriving from the Main Q.
So... I calculated the logstash delivery/dequeue rate as the enqueue rate
minus the DA queue growth rate, which gives me between 1K and 9K log/sec,
with an average of 6,385. This is higher than your average input rate of
6,040, so that's good, but note that your peak input rate was almost
14K/sec. So your input logs (blue) are periodically overrunning logstash's
ability to receive (red) in the chart below:
_______________________________________________
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.
_______________________________________________
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.
