Syslog: Sending Java log4j2 to rsyslog on Ubuntu

Logging has always been a critical part of application development. But the rise of OS virtualization, applications containers, and cloud-scale logging solutions has turned logging into something bigger that managing local debug files.

Modern applications and services are now expected to feed log aggregation and analysis stacks (ELK, Graylog, Loggly, Splunk, etc). This can be done a multitude of ways, in this post I want to focus on modifying log4j2 so that it sends directly to an rsyslog server.

Even though we focus on sending to an Ubuntu ryslog server in this post, this could be any entity listening for syslog traffic, such as Logstash.

Enable rsyslog on receiving Ubuntu Server

The first task is to enable rsyslog on the receiving Ubuntu server. As shown below, modify ‘/etc/rsyslog.conf’ and uncomment the lines that listen on the port 514 UDP port. Additionally, add a line defining the template ‘jsonRfc5424Template’ which will allow us to write the log information as json.

# provides UDP syslog reception, uncomment the two lines below
$ModLoad imudp
$UDPServerRun 514
$UDPServerAddress 127.0.0.1

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
# add the line below which provides json output
$template $template jsonRfc5424Template,"{\"type\":\"syslog\",\"host\":\"%HOSTNAME%\",\"message\":\"<%PRI%>1 %TIMESTAMP:::date-rfc3339% %HOSTNAME% %APP-NAME% %PROCID% %MSGID% %STRUCTURED-DATA% %msg:::json%\"}\n"

This is an opportunity to log extra metadata, and here we add metadata fields for ‘type’ and ‘host’. This can greatly assist in the processing pipeline for Logstash and other solutions.

We could restart the rsyslog service now and the log output would go to ‘/var/log/syslog’ in the traditional BSD style format. But let’s take it one step further and have our application logs written to their own file in a json format.

Create ‘/etc/rsyslog.d/30-testlog4j.conf’ with the content below which tells syslog to write any syslog messages from ‘testlog4j’ to their own file in json format, and then stop any further processing on the message.

if $programname == 'testlog4j' or $syslogtag == 'testlog4j' then /var/log/testlog4j/testlog4j.log;jsonRfc5424Template
& stop

As a side note, the ‘programname’ check would be true if the syslog was being sent in the older BSD style, while the ‘syslogtag’ catches the message when sent in the newer RFC5424 style.

Now, create the log directory, make sure the syslog port 514 is enabled on the local firewall and restart the rsyslog service:

# mkdir -p /var/log/testlog4j
# chown syslog:syslog /var/log/testlog4j
# chmod 755 /var/log/testlog4j
# ufw allow 514/udp
# service rsyslog restart

If the rsyslog service is not started (“ps -A | grep rsyslog”), then errors in the rsyslog configuration can be found by:

# rsyslogd -N1

Validate syslog processing

Before we start sending messages via Java and the log4j2 framework, let’s do a sanity from the console. Preferably from the host where the Java application server will actually run, use the standard Ubuntu ‘logger’ utility to send syslog messages via UDP (the -u is for a bug workaround).

> logger -p local0.warn -d -n myhost "test message to catchall" -u /ignore/socket

You will notice on the syslog server side that this message is sent to /var/log/syslog, formatted similar to below:

Oct 16 19:58:51 myhost myuser: test message to catch all

Now, let’s run the same command, but this time we will specify a syslog tag of ‘testlog4j’

> logger -t testlog4j -p local0.warn -d -n myhost "to testlog4j" -u /ignore/socket

Now the output can be seen coming from /var/log/testlog4j/testlog4j.log and will look similar to below:

{"type":"syslog","host":"myhost","message":"<132>1 2016-10-16T20:16:16-05:00 myhost testlog4j - - -  to testlog4j"}

This proves that syslog is listening, and incoming messages tagged as ‘testlog4j’ do in fact get processed into their own file with specialized json template.

Send log4j2 messages to Syslog

The final step is actually sending log4j messages to our syslog server. Here is a simple Java program:

import org.apache.logging.log4j.*;

public class TestLog4j {
    
    private static final Logger logger = LogManager.getLogger(TestLog4j.class);
    
    public static void main(String[] args) throws Exception
      {
         logger.debug("debug message");
         logger.info("info message");
         logger.warn("warn message");
         logger.error("error message");
         try {
             int i = 1/0;
         }catch(Exception exc) {
             logger.error("error message with stack trace",
                     new Exception("I forced this exception",exc));
         }
         logger.fatal("fatal message");
      }    

}

You will need the log4j-api -<version>.jar and log4j-core-<version>.jar jars in your classpath to compile and run the program above.

You will also need ‘log4j2.xml’ resource file in the classpath:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn">

<Appenders>
    <Console name="console" target="SYSTEM_OUT">
      <PatternLayout pattern="TOCONSOLE %d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>
    
    <!--  OPTION#1: Use standard syslog and add fields with LoggerFields -->
    <Syslog name="syslog" format="RFC5424" host="myhost" port="514"
            protocol="UDP" appName="testlog4j" includeMDC="false" mdcId="testlog4j"
            facility="LOCAL0" enterpriseNumber="18060" newLine="false"
            messageId="Audit">
            <LoggerFields>
                  <KeyValuePair key="thread" value="%t"/>
                  <KeyValuePair key="priority" value="%p"/>
                  <KeyValuePair key="category" value="%c"/>
                  <KeyValuePair key="exception" value="%ex"/>
            </LoggerFields>
                        
    </Syslog>
            
    <!--  OPTION#2: Use socket with explicit pattern -->
    <Socket name="syslogsocket" host="myhost" port="514" protocol="UDP">
          <PatternLayout
        pattern="&lt;134&gt;%d{MMM dd HH:mm:ss} ${hostName} testlog4j: {
              &quot;thread&quot;:&quot;%t&quot;,
              &quot;priority&quot;:&quot;%p&quot;,
              &quot;category&quot;:&quot;%c{1}&quot;,
              &quot;exception&quot;:&quot;%exception&quot;
              }%n"
          />
    </Socket>            
            
</Appenders>

<Loggers>
    <Root level="warn">
      <AppenderRef ref="console"/>
      <AppenderRef ref="syslog"/>
    </Root>
</Loggers>    
  
</Configuration>

There are two options for writing to the syslog socket on UDP 514. The first is to use the <Syslog> element and is the option we are using above. The second is to simply use a <Socket> appender and explicitly define a pattern that is syslog compatible.

Adding extra fields such as Java thread and Java stack exceptions to the <Syslog> element means modify the <LoggerFields>. Adding extra fields to the <Socket> means modifying the <PatternLayout>. I personally prefer the clean json produced by the Socket, but it is all about how you prefer to parse it in later steps in the logging pipeline.

Using the <Syslog> element, you get the following output:

{"type":"syslog","host":"myhost","message":"<132>1 2016-10-16T21:25:20.931-05:00 myhost testc - Audit [testlog4j@18060 category="TestLog4j" exception="" priority="WARN" thread="main"] warn message"}
{"type":"syslog","host":"myhost","message":"<131>1 2016-10-16T21:25:20.933-05:00 myhost testc - Audit [testlog4j@18060 category="TestLog4j" exception="" priority="ERROR" thread="main"] error message"}
{"type":"syslog","host":"myhost","message":"<131>1 2016-10-16T21:25:20.933-05:00 myhost testc - Audit [testlog4j@18060 category="TestLog4j" exception="java.lang.Exception: I forced this exception#012#011at TestLog4j.main(TestLog4j.java:26)#012Caused by: java.lang.ArithmeticException: / by zero#012#011at TestLog4j.main(TestLog4j.java:23)#012" priority="ERROR" thread="main"] error message with stack trace"}
{"type":"syslog","host":"myhost","message":"<129>1 2016-10-16T21:25:20.936-05:00 myhost testc - Audit [testlog4j@18060 category="TestLog4j" exception="" priority="FATAL" thread="main"] fatal message"}

While the <Socket> produces the following:

{"type":"syslog","host":"myhost","message":"<134>1 2016-10-16T21:28:31-05:00 myhost testc - - -  {         \"thread\":\"main\",         \"priority\":\"WARN\",         \"category\":\"TestLog4j\",         \"exception\":\"\"         }"}
{"type":"syslog","host":"myhost","message":"<134>1 2016-10-16T21:28:31-05:00 myhost testc - - -  {         \"thread\":\"main\",         \"priority\":\"ERROR\",         \"category\":\"TestLog4j\",         \"exception\":\"\"         }"}
{"type":"syslog","host":"myhost","message":"<134>1 2016-10-16T21:28:31-05:00 myhost testc - - -  {         \"thread\":\"main\",         \"priority\":\"ERROR\",         \"category\":\"TestLog4j\",         \"exception\":\" java.lang.Exception: I forced this exception#012#011at TestLog4j.main(TestLog4j.java:26)#012Caused by: java.lang.ArithmeticException: / by zero#012#011at TestLog4j.main(TestLog4j.java:23)#012\"         }"}
{"type":"syslog","host":"myhost","message":"<134>1 2016-10-16T21:28:31-05:00 myhost testc - - -  {         \"thread\":\"main\",         \"priority\":\"FATAL\",         \"category\":\"TestLog4j\",         \"exception\":\"\"         }"}

Hopefully, it is obvious that you could also write these messages directly to any syslog server, such as Logstash listening on port 514.

But if you wanted to pre-process the log, you could also consider using something like the ELK Filebeat agent to tail the syslog, parse the json, and forward it on to Redis, Logstash, or any entity that fronts your processing pipeline.

REFERENCES

https://vexxhost.com/resources/tutorials/how-to-setup-remote-system-logging-with-rsyslog-on-ubuntu-14-04-lts/

https://www.digitalocean.com/community/tutorials/how-to-centralize-logs-with-rsyslog-logstash-and-elasticsearch-on-ubuntu-14-04

http://ideaheap.com/2015/03/log4j2-rsyslog-logging/

https://techpunch.co.uk/development/how-to-ship-logs-with-rsyslog-and-logstash

http://www.rsyslog.com/doc/v5-stable/configuration/templates.html

https://logging.apache.org/log4j/2.x/manual/appenders.html#SyslogAppender

https://www.badllama.com/content/tomcat-7-logging-syslog-log4j

http://stackoverflow.com/questions/28433265/logstash-multiline-with-syslog

http://www.slf4j.org/manual.html

http://stackoverflow.com/questions/24205093/how-to-create-a-custom-appender-in-log4j2/24220688#24220688

http://www.syslog4j.org/docs/faq/faq.html