Re: [logs] firewall logging and rulesets

From: Mikael Olsson (mikael.olsson@private)
Date: Sat Oct 25 2003 - 04:56:39 PDT

  • Next message: Hal Snyder: "Re: [logs] stupid question about facility and level"

    Tina Bird wrote:
    > [firewall logging is messy]
    In the interest of throwing some hard facts and examples in here, I'll 
    do a quick rundown of how our firewall does its logging:
    It'll send logs through syslog, or through our own logging format.
    The latter is a bit more detailed; in addition to all the detail
    that the syslog format has, it also includes up to 150 bytes of the 
    original datagram in binary format, which the log viewer can display 
    much like any network sniffer. (There's also a command line utility
    which outputs stuff in a format much like the syslog format)
    I'll concentrate on the syslog format here.
    It's based on a simple "name=value" structure, so parsing it is
    fairly straight-forward. Values are not quoted unless they need
    to be (i.e. if they contain spaces).
    (Lines that begin with spaces are continued from the previous line.)
    Opening a connection:
    2003-10-25T13:00:00.699928+02:00 <134>
      EFW: CONN: prio=1 rule=OvikOnlineOut conn=open connipproto=TCP 
      connrecvif=int connsrcip= connsrcport=1432 
      conndestif=ext conndestip= conndestport=80
    Closing a connection (not the same one):
    2003-10-25T13:00:01.150210+02:00 <134>
      EFW: CONN: prio=1 rule=OvikOnlineIn conn=close connipproto=ICMP 
      connrecvif=ext connsrcip= connsrcid=512 
      conndestif=int conndestip= conndestid=512 
      origsent=106 termsent=106
    Rules can be named, and the name is included in the log, e.g.
    All internal events related to filtering can be controlled 
    through settings, and for such events, the name of the setting
    is used, e.g.:
    2003-10-25T13:00:02.393791+02:00 <133>
      EFW: DROP: rule=LogOpenFails reason=no_new_conn_for_this_packet 
      recvif=ext srcip= destip= ipproto=TCP 
      ipdatalen=20 srcport=80 destport=61763 rst=1 ack=1
    This packet was allowed access by the ruleset, but the state
    engine didn't want to open a new state on account of the packet
    being a RST+ACK packet (it probably belonged to a state that timed
    out long ago).  The LogOpenFails setting is set to "On", so it
    got logged, with "rule=LogOpenFails".
    Now, you may have noticed that in the conn=open/conn=close events
    above, all IP/port parameters begin with "conn..". There's a reason
    for that. When you want to say "i didn't like this packet A that
    belonged to connection X", you need to be able to separate the
    parameters, like in this case:
    2003-10-25T13:00:36.102458+02:00 <133>
      EFW: DROP: rule=LogStateViolations event=unexpected_tcp_flags 
      endpoint=terminator state=TCP_OPEN connipproto=TCP 
      connrecvif=int connsrcip= connsrcport=2744 
      conndestif=ext conndestip= conndestport=1192 
      origsent=642 termsent=184 
      recvif=ext srcip= destip= ipproto=TCP 
      ipdatalen=28 srcport=1192 destport=2744 tcphdrlen=28 syn=1 ack=1
    In this event, the connection terminator (server) sent a SYN ACK
    to the originator, even though it has indicated that the state
    has been successfully opened (we've seen ACKs from it after the 
    initial three-way handshake).  This could be because of packet 
    duplication and delay somewhere along the route.
    The "LogStateViolations" setting controls whether or not such
    events are logged.
    The syslog facility is configured on a per-server basis; each
    firewall can log to an arbitrary number of syslog servers.
    The syslog _severity_, as well as which servers to send the event
    to, can be set on a per-rule basis.  "No servers" is of course
    a valid option :)
    The firewall emits log entries when new configurations are uploaded
    to it (no management is done on the firewall itself):
    [...] EFW: NETCON: event=connect peer=
    [...] EFW: NETCON: event=upload_begin peer=
      file=FWCore_N.cfg size=33984 
    [...] EFW: NETCON: event=upload_complete peer= 
      file=FWCore_N.cfg size=33984
    [...] EFW: NETCON: event=disconnect peer=
    [...] EFW: SYSTEM: shutdown=RECONFIGURE time=1 
      reason="Reconfigure due to NetCon Automation (Peer:"
    [...] EFW: SYSTEM: shutdown=RECONFIGURE
    [...] EFW: SYSTEM: startup=normal corever=8.10.01 uptime=1113603 
      cfgfile=FWCore_N.cfg cfgver=341 
      previous_shutdown="2003-10-11 12:33:35: Reconfigure due to NetCon 
        Automation (Peer:"
    The management software (GUI as well as command line utils) 
    automatically handles configuration concurrency and archival:
      # fwctl --cfginfo -v 341 mygw
      Version:  341 (341)
      Date:     2003-10-11 14:33
      User:     Administrator
      upped p2p-out from 200 to 400 kbit/s (and p1 from 20 to 30)
      # fwctl --cfginfo -v 340 mygw
      Version:  340 (341)
      Date:     2003-09-06 19:05
      User:     Administrator
      allowing nntp to
    It's looked like this since -99 or so, and I'm more or less happy 
    with it.  The one thing I'm not happy with is that you can't change 
    the severity or destinations of built-in events (e.g. LogFailedOpens,
    LogStateViolations, etc), but I'm hoping we can find the time to fix 
    that soonish.
    Now, if someone here wants to tell me that we're doing something 
    severely r-o-n-g, I'm all ears.  On the other hand, if you want to 
    use it and beat someone else over the head with: feel free :)
    Mikael Olsson, Clavister AB
    Storgatan 12, Box 393, SE-891 28 ÖRNSKÖLDSVIK, Sweden
    Phone: +46 (0)660 29 92 00   Mobile: +46 (0)70 26 222 05
    Fax: +46 (0)660 122 50       WWW:
    LogAnalysis mailing list

    This archive was generated by hypermail 2b30 : Sat Oct 25 2003 - 12:57:05 PDT