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

[Rômulo]

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)]

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