Rewriting firewall logs to move MESSAGE fields back into MESSAGE and populate PROGRAM header

[psy phii]

As mentioned in the palo-alto.rules there is an issue with fortinet and palo-alto firewall logs missing the PROGRAM header causing syslog-ng (I don't use rsyslog) with the sagan template to move the first field in the MESSAGE into the PROGRAM field of the syslog header.  For both vendors this ends up being the date portion of the log MESSAGE field.

This has two effects;

1.  You cannot use the program: option in sagan rules to limit processing of firewall related rules to only firewall logs
2.  In situations where you are processing old logs with sagan any alerts generated will be for the date the log was received on the collector (sagan uses the syslog header timestamp) and have no hint in the alert payload as to the actual date the log was generated.

For palo-alto logs there are actually multiple date's in the log line so #2 is less of an issue there as analysts can read it from there.  I have come up with the following syslog-ng rewrite rule that effectively moves the erroneous PROGRAM value back into the MESSAGE field and places fwlog: in the PROGRAM field.

rewrite r_fixm_subst{subst("^", "$PROGRAM ", value("MESSAGE") condition(message("[0-9][0-9]:")));
                     subst(".*", "fwlog", value("PROGRAM") condition(program("1,.*")));
                     subst("time=", "$PROGRAM time=", value("MESSAGE") condition(message("^time=")));
                     subst("date=.*", "fwlog", value("PROGRAM") condition(program("date=.*")));
};

The first two lines of the rewrite are applicable to palo-alto, while the last two are applicable to fortigate.  If you want to split these the processing order is important (IE: rewrite MESSAGE before PROGRAM)

I then call this rewrite rule in the logchain used with the network source;

source fwnet { network(ip(0.0.0.0) max-connections(10) transport("udp") port(514) keep-hostname(yes) keep-timestamp(yes) so-rcvbuf(409600) log-iw-size(15000)); };

destination fwlog { file("/var/log/fwlog" log-fifo-size(46000)); };

log { source(fwnet); rewrite(r_fixm_subst); destination(fwlog); flags(flow_control); };

Below are before and after log samples;

BEFORE~

10.56.153.239|local3|notice|notice|9d|2017-12-02|22:57:45|date=2017-12-02| time=22:57:45 devname=SOMEDEV devid=SOMESERIAL logid=0317013312 type=utm subtype=webfilter eventtype=ftgd_allow level=notice vd=root policyid=41 sessionid=118227906 user="SOMEUSER" srcip=10.56.152.28 srcport=52062 srcintf="port1" dstip=8.8.8.8 dstport=53 dstintf="wan2" proto=17 service="DNS" hostname="ingest.signalfx.com" profile="default" action=passthrough reqtype=direct sentbyte=0 rcvdbyte=0 direction=outgoing msg="URL belongs to an allowed category in policy" method=domain cat=52 catdesc="Information Technology"

AFTER~

10.56.153.239|local3|notice|notice|9d|2017-12-02|22:57:45|fwlog| date=2017-12-02 time=22:57:45 devname=SOMEDEV devid=SOMESERIAL logid=0317013312 type=utm subtype=webfilter eventtype=ftgd_allow level=notice vd=root policyid=41 sessionid=118227906 user="SOMEUSER" srcip=10.56.152.28 srcport=52062 srcintf="port1" dstip=8.8.8.8 dstport=53 dstintf="wan2" proto=17 service="DNS" hostname="ingest.signalfx.com" profile="default" action=passthrough reqtype=direct sentbyte=0 rcvdbyte=0 direction=outgoing msg="URL belongs to an allowed category in policy" method=domain cat=52 catdesc="Information Technology"


The rewrite filter works for both fortinet and palo-alto.    Once in place you would want to uncomment the correct prefix in the normalization rulebase for palo-alto and add prefix's for fortigate.

For Palo-Alto:

~~line 255-256~~
prefix= %-:number,%date:date-iso% %time:time-24hr%,%devserial:char-sep:\x2C%,
#prefix= %time:time-24hr%,%devserial:char-sep:\x2C%,

For fortigate you would probably want to change lines 170-173 to look like:

prefix= date=%date:date-iso%

rule=: time=%time:time-24hr% devname=%-:word% devid=%-:word% logid=%-:word% type=%-:word% subtype=%-:word% level=%-:word% vd=%-:word% srcip=%src-ip:ipv4% srcport=%src-port:number% srcintf=%-:word% dstip=%dst-ip:ipv4% dstport=%dst-port:number% dstintf=%-:word% %-:rest%

prefix=


The prefix= following the rule is needed to empty the prefix before processing other rules. You can avoid needing that if you prepend the date=%date:date-iso% to the actual rule= line.


Champ,  one thing I would like to point out is that using the syslog header timestamp is probably fine in most cases but I can think of a few cases where it would be desirable to use the timestamp embedded in the actual message.  Perhaps adding support for additional liblognorm json objects for date and time field extraction would be useful.

Those few cases I can think of mainly involve setups where logs are sent to a local collector via UDP for spooling to disk prior to relaying via TCP to a centralized sagan host for analysis.  If the centralized host is not configured to keep-timestamps and there is a connectivity disruption and  restoration then timestamp skew would cause issues with time based correlations with other event logs. Even if the system is configured to keep-timestamps the default syslog-ng config does not include the year in the header.....

[Da Beave]

Very good information and thank you.   We do a similar trick with Cisco ASA logs when Cisco "emblem" (?) is enabled.   Cisco ASA's use the "program" field to supply "error" codes.   When Cisco "emblem" is enabled,  they code gets moved from the "program" field to the "message" field.  This causes detection to fail.    We've seen situation were we might have a few thousand Cisco ASA's going to Sagan.   Out of those,  a few dozen will send the way you describe.   We are left with a choice. Hunt down those devices or fix at syslog-ng/rsyslog.

I'll see if I can get Mr. Wink to post his fix for syslog-ng in these situation.

Champ,  one thing I would like to point out is that using the syslog header timestamp is probably fine in most cases but I can think of a few cases where it would be desirable to use the timestamp embedded in the actual message.  Perhaps adding support for additional liblognorm json objects for date and time field extraction would be useful.

Those few cases I can think of mainly involve setups where logs are sent to a local collector via UDP for spooling to disk prior to relaying via TCP to a centralized sagan host for analysis.  If the centralized host is not configured to keep-timestamps and there is a connectivity disruption and  restoration then timestamp skew would cause issues with time based correlations with other event logs. Even if the system is configured to keep-timestamps the default syslog-ng config does not include the year in the header.....

This isn';t a bad idea.  I can see it being more useful when replaying logs.  Could you open a feature request on github so this doesnt fall through the cracks?