Possible race condition/uninitialized buffer when logging duplicated messages to ommysql

Bug #1201469 reported by Rômulo
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
rsyslog (Ubuntu)
New
Undecided
Unassigned

Bug Description

I'm running rsyslog with the ommysql plugin. The configuration file is as follows (unimportant details omited):

    $ModLoad ommysql
    $template custom_mysql_stmt,"INSERT INTO events (message, facility, from_host, priority, device_reported_time, received_at, info_unit_id, syslog_tag, program_name, program_pid) VALUES ('%msg%', %syslogfacility%, '%HOSTNAME%', %syslogpriority%, '%timereported:::date-mysql%', '%timegenerated:::date-mysql%', %iut%, '%syslogtag%', '%programname%', %syslogtag:R,ERE,1,ZERO:\[([0-9]{1,5})\]--end%)",SQL
    :programname, !startswith, "mysqld" :ommysql:localhost,syslog,syslog,password;custom_mysql_stmt

That works in normal conditions. However, when under heavy load, rsyslog sometimes fails with "db error (1064): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near...". I've patched rsyslog and was able to get a sample of the offending query being generated:

    INSERT INTO events (message, facility, from_host, priority, device_reported_time, received_at, info_unit_id, syslog_tag, program_name, program_pid) VALUES (' last message repeated 2 times', 1, '\', 7, '20130715142048', '20130715142048', 1, 'arachni[4509]:', 'arachni', 4509)

'%HOSTNAME%' is being replaced by '\', which clearly makes the query invalid.

A sample of other queries shows that maybe a race condition is causing uninitialized data to be sent to the ommysql plugin:

    INSERT INTO events (message, facility, from_host, priority, device_reported_time, received_at, info_unit_id, syslog_tag, program_name, program_pid) VALUES (' last message repeated 10 times', 1, '=/s', 6, '20130715141700', '20130715141700', 1, 'arachni[4509]:', 'arachni', 4509)
    INSERT INTO events (message, facility, from_host, priority, device_reported_time, received_at, info_unit_id, syslog_tag, program_name, program_pid) VALUES (' last message repeated 2 times', 1, '9st:4', 7, '20130715141808', '20130715141808', 1, 'arachni[3965]:', 'arachni', 3965)
    INSERT INTO events (message, facility, from_host, priority, device_reported_time, received_at, info_unit_id, syslog_tag, program_name, program_pid) VALUES (' last message repeated 2 times', 17, '.4', 6, '20130715141823', '20130715141823', 1, 'httpd-access[6394]:', 'httpd-access', 6394)

I assume it's something internal to the ommysql plugin, because the same messages are also being sent to /var/log/syslog and that trash does not appear there:

    Jul 15 14:20:48 arachni[4509]: last message repeated 2 times
    Jul 15 14:17:00 arachni[4509]: last message repeated 10 times
    Jul 15 14:18:08 arachni[3965]: last message repeated 2 times
    Jul 15 14:18:23 httpd-access[6394]: last message repeated 2 times

Software version information:

    $ lsb_release -rd
    Description: Ubuntu 12.04.2 LTS
    Release: 12.04

    $ apt-cache policy rsyslog
    rsyslog:
      Installed: 5.8.6-1ubuntu8.4
      Candidate: 5.8.6-1ubuntu8.4
      Version table:
     *** 5.8.6-1ubuntu8.4 0
            500 http://sa-east-1a.clouds.archive.ubuntu.com/ubuntu/ precise-updates/main amd64 Packages
            100 /var/lib/dpkg/status
         5.8.6-1ubuntu8 0
            500 http://sa-east-1a.clouds.archive.ubuntu.com/ubuntu/ precise/main amd64 Packages

Rômulo (r37c)
summary: Possible race condition/uninitialized buffer when logging duplicated
- messages
+ messages to ommysql
Revision history for this message
Rômulo (r37c) wrote :

As also suggested in another bug report, using Adiscon repositories fixes the issue: http://www.rsyslog.com/ubuntu-repository/

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.