Log Filtering With Rsyslog: Traditional Syslog
Log Filtering With Rsyslog: Traditional Syslog
DAV I D L A N G
                                                   I
               David Lang is a Staff IT Engineer        n my first ;login: article [1], I provided an overview of how to build an
               at Intuit, where he has spent            enterprise-class logging system and recommended using rsyslog as the
               more than a decade working               transport. For those who are not familiar with modern syslog daemons,
               in the Security Department
                                                   this may seem like a strange recommendation. In this article I will provide an
               for the Banking Division. He
was introduced to Linux in 1993 and has been
                                                   overview of rsyslog’s capabilities, with the focus on its filtering capabilities.
making his living with Linux since 1996. He        Where a traditional syslog limited you to filtering on the facility and severity
is an Amateur Extra Class Radio Operator           reported by the application writing the logs, rsyslog lets you filter anything in
and served on the communications staff of          the log message, as well as several things that are not.
the Civil Air Patrol California Wing, where his
duties included managing the statewide digital     Traditional Syslog
wireless network. He was awarded the 2012          Traditional syslog messages have a facility value (the type of log it is) and a severity value
Chuck Yerkes award for his participation on        (the importance of the message). These are combined to create the priority (PRI) of the
various open source mailing lists.                 message, which is a decimal number: PRI = Facility * 8 + Severity.
david@lang.hm
                                                   The log messages are sent between machines in the format:
                                                        <PRI>timestamp hostname syslogtag message
                                                   Normally, when the messages are written to a file, the <PRI> header is left off, so what shows
                                                   up in the file is:
                                                        timestamp hostname syslogtag message
www.usenix.org	                                                                                               O C TO B E R 2 0 1 3   VO L . 3 8 N O . 5     23
SYSADMIN
Log Filtering with Rsyslog
Almost every program that writes to syslog allows you to specify        String Generation Modules provide predefined templates such
what facility to use, and almost none of them prevent you from          as the following built-in templates:
configuring anything you want. With scripts, you can use the
                                                                           RSYSLOG_DebugFormat, RSYSLOG_FileFormat,
/usr/bin/logger command to log whatever you want.
                                                                           RSYSLOG_ForwardFormat, RSYSLOG_SysklogdFileFormat,
   $ logger -p kernel.emerg -t kernel -s “The system is on fire!!!”        RSYSLOG_SyslogProtocol23Format,
                                                                           RSYSLOG_TraditionalFileFormat,
results in a log that looks like the following and is tagged with
                                                                           RSYSLOG_TraditionalForwardFormat
the facility “kernel” and the severity “emergency”:
   Jul 21 19:55:43 myhostname kernel: The System is on fire!!!          Compatibility with Traditional Syslog
                                                                        Rsyslog supports the traditional PRI-based filtering syntax, so
Rsyslog                                                                 if your current usage fits within this syntax, you can continue to
Rsyslog has a rapid development cycle compared to Linux                 use it.
distros. As of the time of writing, most Linux distros ship with
                                                                        At startup, rsyslog needs a little more information in its config
rsyslog 5.x, while RHEL versions 6.3 and earlier ship with
                                                                        file to tell it which input modules to load and how to configure
 rsyslog 3.22 as the default. Rsyslog 5.x became an option in
                                                                        them, but the filtering lines can be identical.
  RHEL 5.9 and became the default in RHEL 6.4. Meanwhile, the
  current supported version is rsyslog 7.4. As can be expected,         An example /etc/rsyslog.conf equivalent to the /etc/syslog.conf
  the current upstream versions include many features that are          shown earlier would be:
  not available in older versions. Adiscon, the primary sponsor of
                                                                           $ModLoad imuxsock
  rsyslog, development hosts repositories for the newest versions
                                                                           $ModLoad imklog
  for both RHEL/CentOS and Ubuntu packages, and several other
                                                                           $ModLoad imudp
  people maintain current packages for other systems [2].
                                                                           $UDPServerRun 514
Among the many changes in rsyslog 6.x there was a new config               mail.*	/var/log/mail.log
syntax added. Unless stated otherwise, all examples provided in            auth,authpriv.*	/var/log/auth.log
this article have been tested with rsyslog 3.x or newer.                   *.*	/var/log/messages
                                                                           *.*		@192.168.1.6
Rsyslog has a modular design and, in addition to the capabilities
of traditional syslog, supports many other modules that offer           Because rsyslog has an include function, the /etc/rsyslog.conf
many additional functions.                                              could be simplified to:
Input Modules accept input into rsyslog:                                   $ModLoad imuxsock
                                                                           $ModLoad imklog
   im3195, imdiag, imfile, imgssapi, imjournal, imklog, imkmsg,
                                                                           $ModLoad imudp
   immark, impstats, imptcp, imrelp, imsolaris, imtcp, imttcp, imudp.
                                                                           $UDPServerRun 514
   imuxsock, imzmq3
                                                                           $IncludeConfig /etc/rsyslog.conf
Stackable Parser Modules parse or modify the data the input
                                                                        Several Linux distros use the line:
modules accepted:
                                                                           $IncludeConfig /etc/rsyslog.d/*.conf
   pmrfc3164, pmrfc5424, pmaixforwardedfrom, pmcisconames,
   pmlastmsg, pmrfc3164sd, pmsnare                                      to let you manage the configurations for different applications in
                                                                        separate application-specific files, without having all configu-
Message Modification Modules modify the parsed message or
                                                                        ration information collected in the same file. There is a bug in
create variables from the message:
                                                                        rsyslog 6.x and 7.0 (fixed in 7.2) that caused the included files to
   mmanon, mmaudit, mmcount, mmfields, mmjsonparse, mmnormalize,        be processed in reverse order. One caution with included files:
   mmsnmptrapd                                                          rsyslog includes all the files and then evaluates the resulting
                                                                        config. This means that if you set a configuration value in one
Output Modules deliver the message to a destination:
                                                                        included file, it will still be in effect for later included files.
   omelasticsearch, omgssapi, omhdfs, omhiredis, omjournal,
   omlibdbi, ommail, ommongodb, ommysql, omoracle, ompgsql,             Modification of the Outbound Message
   omprog, omrabbitmq, omrelp, omruleset, omsnmp, omstdout,             Rsyslog also allows you to change the log message that it sends
   omtesting, omudpspoof, omuxsock, omzmq3, omfwd (tcp/udp              out to any destination. You can create a format template [3] with
   network delivery), omdiscard, omfile, ompipe, omshell, omusrmsg      a config entry like:
24               O C TO B E R 2 0 1 3   VO L . 3 8 N O . 5 	www.usenix.org
                                                                                                                              SYSADMIN
                                                                                                      Log Filtering with Rsyslog
   $template strangelog,”text %hostname:::lowercase% %msg% more\n”     Mmjsonparse will parse a JSON-formatted message and create
where the items between ‘%’ are variables (with formatting             a tree of variables for you to use. This was implemented to sup-
options).                                                              port the CEE logging standard, and requires that the JSON start
                                                                       with @cee:.
Then in your action, you can tell rsyslog to use a specific tem-
plate instead of the default template:                                 These rsyslog.conf additions are needed to use this module:
                                                                          $ModLoad mmjsonparse
   *.*    /var/log/messages;strangelog
                                                                          *.* :mmjsonparse:
Rsyslog even lets you create a template for the filename, so you
could use a configuration like:                                        This supports multiple levels of structure: $!root!level1!level2!
                                                                       etc. refers to an individual item, $! refers to the entire tree, and
   $template sortedlogs=”/var/log/messages-%fromhost-ip%”              $!root!level1 refers to a partial subtree.
   *.*    ?sortedlogs;strangelog
                                                                       Mmnormalize [5] lets you define a rule set for parsing messages,
to write the messages to different files, with filenames in the for-   and it will do a very efficient parse of the log message, creating
mat specified by the “sortedlogs” template, based on the source        variables.
IP address.
                                                                       For example, starting with this example log message:
Variables Available                                                       Jul 21 19:55:03 kernel: [1084540.211910] Denied: IN=eth0 OUT=
Rsyslog provides different flavors of variables for use in config         MAC=00:30:48:90:cc:a6:00:30:48:da:48:e8:08:00 SRC=10.10.10.10
files: message property variables, trusted property variables,            DST=10.10.10.11 LEN=60 TOS=0x10 PREC=0x00 TTL=64 ID=28843
message content variables, and user-defined variables.                    DF PROTO=TCP SPT=44075 DPT=444 WINDOW=14600 RES=0x00 SYN
                                                                          URGP=0
Message Property Variables
These are items derived from the message or the connection             and the rule file normalize.rb:
information, such as the timestamp within the message, the                rule=: %kerntime:word% Denied: IN=%in:word% OUT=
timestamp when the message was received on the local system,              MAC=%mac:word% SRC=%src-ip:ipv4% DST=%dst-ip:ipv4%
the hostname in the message, the hostname/IP of the system                LEN=%len:number% TOS=%tos:word% PREC=%prec:word%
that delivered the message to the local box, PRI info, etc. [4].          TTL=%ttl:number% ID=%id:number% %DF:word% PROTO=%proto:word%
For rsyslog version 5 and earlier, these were the only variables          SPT=%src-port:number% DPT=%dst-port:number%
available.                                                                WINDOW=%window:number% RES=%res:word% %pkt-type:word%
www.usenix.org	                                                                                    O C TO B E R 2 0 1 3   VO L . 3 8 N O . 5     25
SYSADMIN
Log Filtering with Rsyslog
◆◆   Normal variables, which can be created by “message modifi-           You can use “$$!portnumber” without syntax errors in some
     cation modules” or by config statements. These are addressed         cases, but this results in an indirect reference to something.
     as “$!name”.
                                                                          New Filtering Capabilities
◆◆   Local variables, which cannot be set by message modification
     modules. These are addressed as “$.name”.                            Use Last Match
◆◆   Global variables, which cannot be set by message modifi-             The simplest and fastest “filter” to use is the ‘&’ filter; It isn’t
     cation modules, but will persist across log messages (other          really a filter because it just tells rsyslog to use the result of the
     variables are cleared after every message is processed). These       last test. If that last test matched, the ‘&’ will match as well.
     are addressed as “$/name”.                                           This is extremely useful for cases in which you want to do sev-
Here are some examples of defining variables. Unlike other con-           eral things if a condition is met.
fig statements, set and unset require a trailing ‘;’:                     A common example is when you want to log all messages of
     set $!user!level1!var1=”test”;
                                                                          a particular type in one place, and send them off to another
     set $!user!level1!var1=$!something + 1;
                                                                          system.
     unset $!user!level1;                                                      mail.*	/var/log/mail.log
                                                                               &	@mailanalysis
Using Variables
One common problem that people run into when using variables              With rsyslog version 6 and later you can use {} to group multiple
is the fact that the different types of variables were added to           actions together, and as a result ‘&’ isn’t needed as much as it
rsyslog at different times, and as a result there are different ways      used to be.
they are named.                                                                Mail.*	    { /var/log/mail.log
                                                                               	          @mailanalysis }
The traditional message property variables have just the variable
name, such as “timereported” or “fromhost-ip”.
                                                                          Stop Processing This Log Action
Other properties, mostly referring to the runtime environment             When you know that you don’t want to process a log message any
(rather than the log message), have names like “$myhostname”              longer, you can tell rsyslog to stop and not waste time checking
or “$now”:                                                                any further rules. This is commonly used in conjunction with
◆◆   Variables parsed from the message with mm modules have               the & filter or a block of actions to prevent rsyslog from trying to
     names like “$!name”.                                                 match any other filter rules after you have done what you want
                                                                          with a message. Without a stop, the message will get sent to
◆◆   Local variables have names like “$.name”.
                                                                          every output that has a matching filter:
◆◆   Global variables have names like “$/name”.
                                                                               mail.*	/var/log/mail.log
◆◆   When using variables, the examples usually have the classic
                                                                               &	@mailanalysis
     properties, so you see things like:
                                                                               &	~
◆◆   %msg% in a template
                                                                          Or with the rsyslog version 6+
◆◆   :msg, in a property-based filter
                                                                               Mail.*     { /var/log/mail.log
◆◆   $msg in a script-style config
                                                                                         @mailanalysis
But when you are using the other variable types, you must be                   stop }
aware that the variable prefix ( ‘$’ ‘$!’ ‘$.’ ‘$/’) is considered part
of the variable name, not a reference to it, so you would use some-       and rsyslog will stop processing this message and no other rules
thing like:                                                               will be checked. Be careful—using included config files as a stop
                                                                          in one file may have an unexpected impact on the processing of
                                                                          another file.
26                 O C TO B E R 2 0 1 3   VO L . 3 8 N O . 5 	www.usenix.org
                                                                                                                                 SYSADMIN
                                                                                                         Log Filtering with Rsyslog
www.usenix.org	                                                                                       O C TO B E R 2 0 1 3   VO L . 3 8 N O . 5     27
SYSADMIN
Log Filtering with Rsyslog
New Config Syntax                                                           becomes longer, although a bit more obvious as to what it does,
The old syntax will continue to be supported, and you can freely            using the new syntax:
mix and match between the different config syntaxes within                     *.*       action(type=”omfile” File=”/var/log/messages”
the same file (or included files) so you don’t have to change your                         Template=”templatename”)
config files when you upgrade. For some of the newer functional-
ity, though, you must use the new syntax.                                   Choosing which syntax to use is completely up to you— use
                                                                            whichever you find easier for the task at hand. Most configura-
In the old config syntax, you must set up options and then                  tions will include a mix of old and new, but in general, the more
execute the function, while the new format looks like function              complex the configuration, the more likely you are to benefit
calls with many parameters.                                                 from the new config syntax. Prior to the config optimizer added
This example is in the old syntax:                                          in rsyslog v7, PRI-based filters were by far the fastest type of
                                                                            filter to use.
   $mmnormalizeUseRawMSG off
   $mmnormalizeRuleBase /rsyslog/rulebase.rb
                                                                            Example
   *.* :mmnormalize:
                                                                            In the first article, I recommended using recent versions of
Here is the equivalent config using the new syntax:                         rsyslog on the Aggregator and Analysis farm machines, so that
                                                                            you can take advantage of the greatly expanded capabilities and
   action(type=”mmnormalize” UseRawMsg=”off”
                                                                            performance of the newer versions. One of the recommendations
         ruleBase=”/etc/rsyslog.d/normalize.rb”)
                                                                            that I made was to use JSON-structured messages for the trans-
Here’s another example using the old syntax for a more complex              port so that additional metadata could be added. The following
action (sending a SNMP trap):                                               config files are an example of what you may want to use.
   $actionsnmptransport udp                                                 Note that in these examples, I mix old and new config styles and
   $actionsnmptarget 192.168.1.100                                          make use of the “always” filter.
   $actionsnmptargetport 162
                                                                            On all “normal” systems (app-servers, routers, switches, etc.),
   $actionsnmpversion 1
                                                                            deliver all messages to the Edge Aggregation servers. On *nix
   $actionsnmpcommunity testtest
                                                                            systems, add an entry like the following to /etc/syslog.conf or
   $actionsnmptrapoid 1.3.6.1.4.1.19406.1.2.1
                                                                            /etc/rsyslog.conf:
   $actionsnmpsyslogmessageoid 1.3.6.1.4.1.19406.1.1.2.1
   $actionsnmpenterpriseoid 1.3.6.1.4.1.3.1.1                                  *.* @edge-server-for-local-network
   $actionsnmptraptype 2
                                                                            Here is an example /etc/rsyslog.conf for an Edge Aggregator.
   $actionsnmpspecifictype 0
                                                                            Note that rsyslog treats newlines as whitespace, so no line con-
   *.* :omsnmp:
                                                                            tinuation characters are necessary. The exception to this is the
With the new syntax, the same config appears in a much more                 $template command, which needs to be on one line (but is split
compact format:                                                             here for printing):
28                  O C TO B E R 2 0 1 3   VO L . 3 8 N O . 5 	www.usenix.org
                                                                                                                           SYSADMIN
                                                                                                   Log Filtering with Rsyslog
   } else {                                                          And, finally, on the Analysis Farm systems, the following mes-
       set $!trusted!local!input = $inputname;                       sage will be produced in /var/log/messages:
   }
                                                                        Jul 24 14:51:42 app-server dlang: testtest
   # set this to reflect the environment that this Edge server is
   servicing                                                         This threw away all the metadata, resulting in a message that
   set $!trusted!environment = “Dev network”;                        looks identical to what was originally generated, but the meta-
   # note the template must be on a single line                      data was available for filtering decisions up to this point. And a
   # wrapping is for display only                                    slightly different format on the Analysis Farm server could make
   $template structured_forwarding,                                  any of the metadata available to the analysis tools.
       “<%pri%>%timereported% %hostname% %syslogtag% @cee:%$!%\n”
   /var/log/messages;structured_forwarding
                                                                     As a second demonstration, on an Edge Aggregator I again
   @@core-server
                                                                     executed:
   #send to the core server via TCP consider using RELP instead         logger testtest
And here is an example configuration for the Analysis Farm           Because this adds trusted properties to the message, it sends the
systems:                                                             following log entry to the Core Aggregator:
   module(load=”imuxsock” SysSock.Annotate=”on”                         <13>Jul 24 21:53:39 edge-server dlang: { “pid”: 4346, “uid”:
       SysSock.ParseTrusted=”on”)                                       1000, “gid”: 1000, “appname”: “logger”, “cmd”: “”, “msg”:
   module(load=”imklog”)                                                “testtest”, “trusted”: { “local”: { “input”: “imuxsock” },
   module(load=”imtcp” MaxSessions=”1000”)                              “environment”: “sending network” } }
   input(type=”imtcp” port=”514”)
   module(load=”mmjsonparse”)
                                                                     Again, the Analysis Farm server will throw away the extra meta-
   action(type=”mmjsonparse”)
                                                                     data and reformat the log to be:
   if $fromhost-ip == “127.0.0.1” then {                                Jul 24 21:53:39 edge-server dlang: testtest
       #if this is a local log, send it to an edge relay.
       set $!trusted!local!input = $inputname;
                                                                     But this time there was more metadata available about the process
       @edge-server
                                                                     that created the log message available prior to the final output.
       stop }                                                        In conclusion, rsyslog has tremendous flexibility in processing
   $template std,”%timereported% %hostname% %syslogtag%%$!msg%\n”    your log messages. You can filter on just about anything that you
   /var/log/messages;std                                             care about, and you can modify messages as you send them out to
To demonstrate how this works, on an app-server I executed:          any of the many different supported outputs.
logger testtest
www.usenix.org O C TO B E R 2 0 1 3 VO L . 3 8 N O . 5 29