[syslog-ng] Parsing Cisco FWSM with device-id

[Martin Holste]

Thanks for looking into this.  I suspect that this problem occurs for
a lot of people, because it affects any PIX, ASA, or FWSM which has a
device-id set.  However, the rewrite expression is incredibly
low-load, so we haven't noticed a CPU increase even when parsing 2-3k
FWSM logs/sec.  I would assume you'd see a CPU hit at some event rate,
but I haven't seen it yet.  The bigger problem is likely getting
syslog-ng to properly parse these logs out-of-the-box, and it seems
ugly to include the rewrite in the stock syslog-ng config.

On Sat, Oct 29, 2011 at 2:27 PM, Balazs Scheidler <bazsi at balabit.hu> wrote:
> On Wed, 2011-10-05 at 13:00 -0500, Martin Holste wrote:
>> So I have a customer who has enabled the device-id configuration
>> directive on his FWSM, and that means that instead of this from a
>> normal FWSM:
>> <174>%FWSM-6-302013: Built inbound TCP...
>> it sends this:
>> <174>FWSMHostName %FWSM-6-30203: Built inbound TCP...
>>
>> This means that the program name does not get properly parsed as
>> syslog-ng pushes it into the msg field.  If I can't convince the
>> customer to remove the device-id setting, what's the least
>> CPU-intensive way of coping with this so that program and msg are set
>> correctly?
>
> I was just wondering why this can't be parsed by the syslog-ng message
> parsing code.
>
> hmm... checking that code out myself, it seems to assume that if there's
> no timestamp, then the whole header is missing:
>
>      /* no timestamp, format is expected to be "program[pid] message" */
>      /* Different format */
>
>      /* A kernel message? Use 'kernel' as the program name. */
>      if ((self->flags & LF_INTERNAL) == 0 && ((self->pri & LOG_FACMASK) == LOG_KERN))
>        {
>          log_msg_set_value(self, LM_V_PROGRAM, "kernel", 6);
>        }
>      /* No, not a kernel message. */
>      else
>        {
>          /* Capture the program name */
>          log_msg_parse_legacy_program_name(self, &src, &left, parse_options->flags);
>        }
>      self->timestamps[LM_TS_STAMP] = self->timestamps[LM_TS_RECVD];
>
> The root cause has been buried under years of improving a heuristics to detect
> the proper syslog format. This is already implemented this way in syslog-ng 2.0.
>
> Let me check 1.6... That has the same comment. As far as history goes back,
> that code is there. Don't ask me why.
>
> Uhum. I think I've found it in the ChangeLog for 1.4.0rc3 (from February, 2000):
>
>        ...
>
>        * src/log.c (parse_log_msg): don't remove programname from the
>        whole message, set programname to "kernel" when a message comes
>        from LOG_KERN facility (needed for SunOS)
>
>        ...
>
>        * src/log.c (parse_log_msg): if no date is received on a logline
>        parse the first word as programname
>
> I seem to have been porting syslog-ng to AIX at that time. This time I
> have checked that AIX uses a properly formatted syslog header on
> its /dev/log device:
>
> Incoming log entry; line='<13>Oct 29 21:19:54 root: almafa \x0a'
>
> Hmm.. I've checked out the mailing list archives too, it is probably
> related to this thread:
>
> https://lists.balabit.hu/pipermail/syslog-ng/2000-February/000438.html
>
> I'm somewhat reluctant to change the log message parser though, I've
> bitten too many times with this, however that would be the best way to
> fix your problem, instead of having to resort to rewrite rules.
>
> I'll have another go to understand those ancient threads and if I can
> come up with a proper understanding, it might be easier to just change
> the parsing code so that it eats FWSM logs properly. supporting the
> syslogd version in slink may not be more important than a current Cisco
> device ;)
>
> --
> Bazsi
>
>
> ______________________________________________________________________________
> Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng
> Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng
> FAQ: http://www.balabit.com/wiki/syslog-ng-faq
>
>