[rsyslog] 100% CPU utilization after receiving logger message [SOLVED]

Ansgar Puester ansgar.puester at netcologne.de
Mon May 15 13:53:31 CEST 2017


Hello,

with some help of Rainer I could solve this problem.
Rainer's advice was to trace the SQL-Statement to a
file using

*.* /var/log/mysql-stmt;MySQLInsert

This shows, that the statement looks like this:

insert
into SystemEvents (Message,
      Facility,
      FromHost, Priority,DeviceReportedTime, ReceivedAt,
      InfoUnitID, SysLogTag, ProcessID)
values (' Testmessage from eiskernel.fritz.box (mark:info)',
      invld,
      'eiskernel', 7, '20170511175514', '20170511175514',
      1, 'root:', '0')

The problem is not a column named "invld" added to the
column list but the character sequence invld in the
value list.

The error message
   Unknown Table Field 'invld' in field list.
seems to be missleading.

Trying to insert the string 'invld' into a column
defined as
   Facility smallint NULL
is handled by MariaDB in converting 'invld' to 0
No error message or warning! Surprise for me.

So I changed my template to

template(name="MySQLInsert" type="string" option.sql="on" string="insert
into SystemEvents (Message, Facility, FromHost, Priority,
DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag, ProcessID) values 
('%msg%',
'%syslogfacility%', '%HOSTNAME%', '%syslogpriority%', 
'%timereported:::date-mysql%',
'%timegenerated:::date-mysql%', %iut%, '%syslogtag%', 
'%procid:R,ERE,0,ZERO:[0-9]+--end%')")

Now all tests run successfully.

Regards
Ansgar

Am 11.05.2017 um 12:37 schrieb Rainer Gerhards:
> 2017-05-11 11:11 GMT+02:00 Ansgar Puester via rsyslog
> <rsyslog at lists.adiscon.com>:
>> Hello,
>>
>> I am using rsyslog on a Eisfair-1 System (http://www.eisfair.org/).
>>
>> When testing rsyslog I found out, that rsyslogd has
>> 100% CPU utilization after receiving a logger message.
>>
>> logger -p mark.info "Testmessage from eiskernel.fritz.box (mark:info)"
>>
>> The same problem occurs when forwarding syslog mark messages
>> using rsyslog as remote logging host.
>>
>> Using strace and debug option I discovered the error message
>> Unknown Table Field 'invld' in field list.
>>
>> It looks like rsyslog tries to use a _column_ named "invld".
>>
>> After adding such a column
>>     alter table SystemEvents add invld text Null;
>> the loop is gone!
>>
>> A debug line shows that the priority is invalid:
>> PRI: invld,
>> inputname: imuxsock rawmsg: '<198>May 11 10:04:08 root: Testmessage from
>> eiskernel.fritz.box (mark:info)'
>>
>> I understand that this is primary a bug of mark messages from logger
>> (logger from util-linux 2.26.2).
>>
>> What I would have expected is, that rsyslog handles this error
>> by storing e.g. NULL into a database column, but not by adding
>> a column named "invld" to the column list.
> 
> That's indeed strange. Could you send me a debug log that shows this behaviour?
> 
> Rainer
>>
>> Could you fix this behavior in one of the next versions?
>> If you need additional information please tell me.
>>
>> Thanks in advance
>> Ansgar
>>
>>
>>
>> Environment:
>> rsyslog is self compiled from scratch
>>
>> eiskernel # /usr/sbin/rsyslogd -version
>> rsyslogd 8.26.0, compiled with:
>>          PLATFORM:                               i686-pc-linux-gnu
>>          PLATFORM (lsb_release -d):              Description:    eisfair-1
>>          FEATURE_REGEXP:                         Yes
>>          GSSAPI Kerberos 5 support:              No
>>          FEATURE_DEBUG (debug build, slow code): No
>>          32bit Atomic operations supported:      Yes
>>          64bit Atomic operations supported:      No
>>          memory allocator:                       system default
>>          Runtime Instrumentation (slow code):    No
>>          uuid support:                           Yes
>>          Number of Bits in RainerScript integers: 64
>>
>> MariaDB Database Ver 15.1 Distrib 5.5.54-MariaDB.
>>
>> rsylog configuration:
>> template(name="MySQLInsert" type="string" option.sql="on" string="insert
>> into SystemEvents (Message, Facility, FromHost, Priority,
>> DeviceReportedTime, ReceivedAt, InfoUnitID, SysLogTag, ProcessID) values
>> ('%msg%',
>> %syslogfacility%, '%HOSTNAME%', %syslogpriority%,
>> '%timereported:::date-mysql%',
>> '%timegenerated:::date-mysql%', %iut%, '%syslogtag%',
>> '%procid:R,ERE,0,ZERO:[0-9]+--end%')")
>>
>> $ModLoad ommysql.so
>> *.* :ommysql:localhost,Syslog,loguser,secret;MySQLInsert
>>
>> _______________________________________________
>> 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.
> 



More information about the rsyslog mailing list