Details

    • Bug
    • Resolution: Fixed
    • Major
    • None
    • None
    • Web Interface
    • debian 7, syslog-ng

    Description

      syslog.php is discarding portions of the msg field when certain characters are present in the msg. I have already confirmed that syslog-ng is not damaging the msg field and that the data is making it to syslog.php intact by turning on debugging in syslog-ng an duplicating it's output into a file.

      Here is the original log message

      Wed Mar 26 12:54:17 2014 : Auth: Login incorrect (mschap: External script says Logon failure (0xc000006d)): [username] (from client 10.100.1.3 port 0 cli a4c3612a4077 via TLS tunnel)
      

      Here is the syslog-ng prepped version that is being sent to syslog.php

      radius||local0||notice||notice||85||2014-03-26 12:54:17||Wed Mar 26 12:54:17 2014 : Auth: Login incorrect (mschap: External script says Logon failure (0xc000006d)): [username] (from client 10.100.1.3 port 0 cli a4c3612a4077 via TLS tunnel)||Auth
      

      Observium matches everything inside the delimiters except the MSG field, what it puts in the DB for MSG is:

       [username] (from client 10.100.1.3 port 0 cli a4c3612a4077 via TLS tunnel)
      

      That includes the preceding space that was after the )): . It does get the program after MSG correct as well. My initial thought is that it is some sort of after processing that is butchering the MSG field.

      Attachments

        Activity

          [OBS-760] syslog cropping some logs

          Looks like this hasn't quite been fixed. Found another instance where the program gets dropped and the first part of the message gets used in it's place.

          For messages sent to syslog.php like this:

          app-web1||mail||info||info||16||2014-04-02 12:03:32||A87EC201127: to=<address@hotmail.com>, relay=10.1.1.185[10.1.1.185]:25, delay=1.3, delays=0.18/0.01/0.01/1.1, dsn=2.6.0, status=sent (250 2.6.0 <20140402160331.A87EC201127@app-web1.domain.edu> [InternalId=20728197] Queued mail for delivery)||postfix/smtp
          

          Get inserted into the database as:

          device_id 79
          facility mail
          priority 6
          level 6
          tag 16
          timestamp 2014-04-02 12:03:32
          program A87EC201127
          msg

          to=<address@hotmail.com>, relay=10.1.1.185[10.1.1.185]:25, delay=1.3, delays=0.18/0.01/0.01/1.1, dsn=2.6.0, status=sent (250 2.6.0 <20140402160331.A87EC201127@app-web1.domain.edu> [InternalId=20728197] Queued mail for delivery)

          Here are a few more processed syslog lines that also insert with the program replaced with the first part of the msg up to the ":"

          app-web1||mail||info||info||16||2014-04-02 12:03:31||A87EC201127: uid=33 from=<www-data>||postfix/pickup
          

          app-web1||mail||info||info||16||2014-04-02 12:03:31||A87EC201127: message-id=<20140402160331.A87EC201127@app-web1.domain.edu>||postfix/cleanup
          

          app-web1||mail||info||info||16||2014-04-02 12:03:31||A87EC201127: from=<www-data@domain.edu>, size=1348, nrcpt=1 (queue active)||postfix/qmgr
          

          app-web1||mail||info||info||16||2014-04-02 12:03:32||A87EC201127: removed||postfix/qmgr
          

          slm4996 Solomon Seal added a comment - Looks like this hasn't quite been fixed. Found another instance where the program gets dropped and the first part of the message gets used in it's place. For messages sent to syslog.php like this: app-web1||mail||info||info||16||2014-04-02 12:03:32||A87EC201127: to=<address@hotmail.com>, relay=10.1.1.185[10.1.1.185]:25, delay=1.3, delays=0.18/0.01/0.01/1.1, dsn=2.6.0, status=sent (250 2.6.0 <20140402160331.A87EC201127@app-web1.domain.edu> [InternalId=20728197] Queued mail for delivery)||postfix/smtp Get inserted into the database as: device_id 79 facility mail priority 6 level 6 tag 16 timestamp 2014-04-02 12:03:32 program A87EC201127 msg to=<address@hotmail.com>, relay=10.1.1.185[10.1.1.185]:25, delay=1.3, delays=0.18/0.01/0.01/1.1, dsn=2.6.0, status=sent (250 2.6.0 <20140402160331.A87EC201127@app-web1.domain.edu> [InternalId=20728197] Queued mail for delivery) Here are a few more processed syslog lines that also insert with the program replaced with the first part of the msg up to the ":" app-web1||mail||info||info||16||2014-04-02 12:03:31||A87EC201127: uid=33 from=<www-data>||postfix/pickup app-web1||mail||info||info||16||2014-04-02 12:03:31||A87EC201127: message-id=<20140402160331.A87EC201127@app-web1.domain.edu>||postfix/cleanup app-web1||mail||info||info||16||2014-04-02 12:03:31||A87EC201127: from=<www-data@domain.edu>, size=1348, nrcpt=1 (queue active)||postfix/qmgr app-web1||mail||info||info||16||2014-04-02 12:03:32||A87EC201127: removed||postfix/qmgr

          Confirmed fixed.

          slm4996 Solomon Seal added a comment - Confirmed fixed.

          Fixed in r5154.

          landy Mike Stupalov added a comment - Fixed in r5154.

          People

            adama Adam Armstrong
            slm4996 Solomon Seal
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: