Parsing Cisco FWSM with device-id
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 guess csv parser. If you are lucky, you can rewrite the PROGRAM and MSG fields from the csv parser (not sure if it actually works, but wouldn't be surprised if it did), like: csv_parser .... columns($PROGRAM,$MESSAGE) Robert On Wednesday, October 5, 2011 20:00 CEST, Martin Holste <mcholste@gmail.com> 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? ______________________________________________________________________________ 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
Just a follow-up to anyone else who needs to cope with Cisco devices being logged with an extra hostname given which shifts $HOST into $PROGRAM, you can fix the program and message using this: filter f_rewrite_cisco_program { match('^(%(?:ASA|PIX|FWSM)\-\d\-\d{6}): ([^\n]+)' value("MESSAGE") type("pcre") flags("store-matches" "nobackref")); }; rewrite r_cisco_program { set("$1", value("PROGRAM") condition(filter(f_rewrite_cisco_program))); set("$2", value("MESSAGE") condition(filter(f_rewrite_cisco_program))); }; log { rewrite(r_cisco_program); <usual log statements> }; The anchor '^' at the beginning should make performance very good. A bonus PCRE fact: [^\n]+ is much faster than .+ so I recommend using it whenever you're matching any char. Second bonus PCRE fact: PCRE 8.20RC3 compiled with sljit is 20-30% faster than older PCRE's. Note to Balabit: you guys should seriously consider a configure script flag to compile with sljit and newer PCRE's. On Wed, Oct 5, 2011 at 1:24 PM, Fekete Róbert <frobert@balabit.hu> wrote:
I guess csv parser. If you are lucky, you can rewrite the PROGRAM and MSG fields from the csv parser (not sure if it actually works, but wouldn't be surprised if it did), like:
csv_parser .... columns($PROGRAM,$MESSAGE)
Robert
On Wednesday, October 5, 2011 20:00 CEST, Martin Holste <mcholste@gmail.com> 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? ______________________________________________________________________________ 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
______________________________________________________________________________ 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
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
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@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
participants (3)
-
Balazs Scheidler
-
Fekete Róbert
-
Martin Holste