On Mon, 6 Nov 2017, Steven Libby wrote:
I've tried removing the ruleset altogether and just using an action to
minimize locking overhead (which I assume would be the same thing you're
referring to here). But just to make sure, I also tried changing the
ruleset queue type to "Direct" and got the same result.
yes
Also, most of the time during my testing I used resumeRetryCount="-1" but
mistakenly left it at "0" when I posted to this mailing list. Reverting
back to "-1" still results in a backlog in the database action queue. When
you say "...some insert attempts...are not being accepted by mysql...", are
you implying that some insert attempts are actually being rejected by
mysql?
that was one possibility when I thought you were not retrying logs.
I have enabled the general query log with the highest level of
verbosity, and also installed the audit plugin, but I am unable to see any
indication that any insert attempts are being rejected. I have yet to
enable the DBUG package yet for further investigation, but will try that
next to see if I can glean any new information.
are logs getting inserted one at a time or in large batches? try to increase
batching, get a debug log for a bit on the rsyslog side and see if it's having
to make multiple attempts to insert messages (for example, you try to deliver up
to 8K messages at once, rsyslog could be rejecting this because the total
request size is too large and rsyslog then tries to deliver 4K, 2K, 1K...
messages until it gets small enough to be accepted)
David Lang
On a side note, I created a separate test table using the MyISAM storage
engine and the insert rate was improved, but still filled up the database
action queue within several minutes. I've reduced the durability of TokuDB
by disabling tokudb_commit_sync and tokudb_fsync_log_period global
variables, but there was zero noticeable performance difference here.
(Background: we use TokuDB for it's compression and secondary clustering
indexes, mainly). I would expect to see excessive CPU utilization or Disk
I/O if the database was struggling to keep up with the rsyslog queue, but
perhaps that expectation is incorrect?
Regards,
Steven
On Sat, Nov 4, 2017 at 5:03 PM, David Lang <[email protected]> wrote:
don't put a queue on the ruleset and the only item in the ruleset
when you have to queues like this, you end up with lots of locking
overhead and poor batch sizing.
with retrycount=0 you never attempt to re-deliver a message that fails, if
you set it to -1 it will retry forever
try setting it to -1 and see if logs are getting stuck (delivery stops),
if so, you are getting some insert attempts that are not being accepted by
mysql and since you have retries disabled, the entire batch is being thrown
away.
On Fri, 3 Nov 2017, Steven Libby via rsyslog wrote:
Date: Fri, 3 Nov 2017 14:53:17 -0400
From: Steven Libby via rsyslog <[email protected]>
To: [email protected]
Cc: Steven Libby <[email protected]>
Subject: [rsyslog] ommysql database queue bottleneck
We are running rsyslog 8.21.0 on a RHEL 6.7 box with 256GB of RAM and 96
cores, writing to a MySQL instance (Percona Server 5.6.28-76) using TokuDB
as the storage engine. This is our centralized log server, which receives
messages from numerous network devices at an average rate of 7k messages
per second. This message rate is fairly consistent throughout the course
of the day.
We noticed records missing from the database when comparing with the raw
records being written directly to a file on another server. Based on the
investigation so far, it appears the lost messages are being discarded due
to queues filling up.
After enabling the impstats module, we discovered that the bottleneck
appears to be in the database queue; but we're having trouble determining
the exact cause of the bottleneck. Database resource utilization is
relatively low (CPU utilization < 4%, Disk I/O < 1%, 5+GB free RAM) and
we've tuned the database configuration to remove any unnecessary overhead.
We've made numerous configuration changes, both on the DB side and in
rsyslogd, and the queue seems to build at roughly the same rate regardless
of of everything we've tried.
We are successfully writing 3k-4k records per-second into the DB, but the
action queue is also building at about that same rate.
Here is the latest rsyslog configuration we've tried (below) cleaned up
for
the purpose of this message. Most of the incoming messages arrive via
imudp. We've tried adjusting the number of threads in that module, as
well
as the batchSize, and the number of messages coming in stays about the
same, regardless. We've also tried different combinations of MainMsg
queue
worker threads and batch sizes, as well as similar adjustments in the
ruleset and action configurations. We've gone through the changelogs up
to
rsyslog 8.31.0 and didn't see anything to indicate that upgrading would
help with the performance. We've also gone through most of the online
documentation at rsyslog.com/doc/v8-stable/ and read some articles by
David
Long regarding performance improvements and the work he did with Intuit.
At this point, any additional help or guidance from the professionals
would
be greatly appreciated. Thanks for taking the time to read this...
#rsyslog v8.x config file
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$RepeatedMsgContainsOriginalMsg on
$OptimizeForUniprocessor off
$PreserveFQDN on
$WorkDirectory /HSD1/syslogQ
$MainMsgQueueFileName mainq-SecInfra
$MainMsgQueueMaxDiskSpace 200g
$MainMsgQueueMaxFileSize 1g
$MainMsgQueueSaveOnShutdown on
$MainMsgQueueType LinkedList
$MainMsgQueueSize 10485760
$MainMsgQueueHighWatermark 10000000
$MainMsgQueueWorkerThreads 8
$MainMsgDequeueBatchSize 8192
module(load="imudp" threads="8" batchSize="8192" timeRequery="10")
module(load="imptcp" threads="8" processOnPoller="off" )
module(load="imuxsock")
module(load="imklog")
module(load="immark")
module(load="ommysql")
module(load="impstats" interval="5" resetCounters="off" format="legacy"
log.syslog="off" log.file="/HSD1/locallog/pstat
s-SecInfra_2017-11-03.log")
module(load="mmutf8fix")
$template SecInfraSyslogTmpl,"insert into SecInfraSyslog.syslogRaw
(recievedAt,deviceReportedTime,deviceTimezone,fromHost,
fromHostIpv4,hostName,facility,priority,localPriority,infoUnitId,
inputName,syslogTag,programName,appName,procId,msgId,message,rawMessage)
values ('%timegenerated:::date-mysql%.%timegenerated:::date-
subseconds%','%timereported:::date-mysql%.%timereported:::
date-subseconds%','%timereported:::date-tzoffsdirection%%timereported:
::date-tzoffshour%','%FROMHOST%','%fromhost-ip%','%
HOSTNAME%',%syslogfacility%,%syslogpriority%,'%PRI%',%iut%,
'%inputname%','%syslogtag%','%programname%','%APP-NAME%','%
PROCID%','%MSGID%','%msg%','%rawmsg%')",SQL
ruleset(name="SecInfra"
queue.saveonshutdown="on"
queue.type="LinkedList"
queue.filename="SecInfra-ruleQ"
queue.highwatermark="1000000"
queue.size="1310720"
queue.dequeuebatchsize="8192"
queue.maxdiskspace="200g"
queue.maxfilesize="10g"
queue.workerthreads="2"
) {
action(name="SecInfra2ArchiveDB"
type="ommysql"
server="127.0.0.1"
db="SecInfraSyslog"
uid="rsyslog"
pwd="************"
serverport="3306"
template="SecInfraSyslogTmpl"
queue.saveonshutdown="on"
queue.type="LinkedList"
queue.filename="SecInfraArchive-dbQ"
queue.highwatermark="1000000"
queue.size="1310720"
queue.dequeuebatchsize="8192"
queue.maxdiskspace="200g"
queue.maxfilesize="10g"
queue.workerthreads="2"
action.resumeRetryCount="0"
action.reportSuspension="on"
action.reportSuspensionContinuation="on"
)
}
input(type="imudp" name="SecInfraUDP" address="************" port="514"
ruleset="SecInfra")
input(type="imtcp" name="SecInfraTCP" address="************" port="514"
ruleset="SecInfra")
Regards,
Steven Libby
_______________________________________________
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.
