Saturday, March 19, 2011

Remote logging with Log4j

I'm writing about Log4j's Socket Appender. I can't just use and stay quiet. It's just really useful. So here is the case. You have a web application running in multiple instances behind a load balancer. Each server is going to have a log file and yes it's hard too track the log files down across multiple instances. If an instance is terminated you might even lose the log file. So we are gonna need a central log server that aggregates the log files to the central log server and this is done by log4j's Socket Appender.

I'll demonstrate it on my local computer but it would simply work for the case. I assume you have already installed and configured log4j for you application.

First we need to setup the log server. For this we use org.apache.log4j.net.SimpleSocketServer that can service multiple SocketAppender clients. SimpleSocketListener waits for logging events from SocketAppender clients. After reception the events are logged according to the server policy. It takes two parameters: port and configFile; where port is the port to listen on and configFile is configuration script in properties or XML format.

For server logging properties would look like this.
wave@wave-laptop:~/log_test$ cat socket_server.properties 
log4j.rootLogger=debug,stdout,R

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p %c{1}:%L - %m%n

log4j.appender.R=org.apache.log4j.RollingFileAppender

# Log file name 
log4j.appender.R.File=my_log.log 

# Max size that the portal log file will grow before being rolled
log4j.appender.R.MaxFileSize=10MB 

# Max number of rolled log files that will be maintained
log4j.appender.R.MaxBackupIndex=100

#Using PatternLayout for log file formatting
log4j.appender.R.layout=org.apache.log4j.PatternLayout

log4j.appender.R.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %5p %c{1}:%L - %m%n
Now let's run the server application.
wave@wave-laptop:~/log_test$ java -classpath log4j-1.2.16.jar org.apache.log4j.net.SimpleSocketServer 4445 socket_server.properties 
2011-03-19 17:13:19  INFO SimpleSocketServer:60 - Listening on port 4445
2011-03-19 17:13:19  INFO SimpleSocketServer:63 - Waiting to accept a new client.
It starts listening on the port 4445. Just a reminder don't forget to configure your firewall to allow the port :).

Now let's look at the log client application.
// LogClient.java

import org.apache.log4j.Logger;
import org.apache.log4j.net.SocketAppender;

public class LogClient {

static Logger log = Logger.getLogger(LogClient.class);
  public static void main(String[] args) {
    log.debug("hi there");
    log.debug("loggin from remote server");
    log.debug("end");
 }
}
And here is the xml file for the application.

log4j.xml:
<log4j:configuration>
  <appender name="stdout" class="org.apache.log4j.ConsoleAppender">
    <layout class="org.apache.log4j.PatternLayout">
     <param name="ConversionPattern" value="%d{ABSOLUTE} %5p %c{1}:%L - %m%n"/>
    </layout>
  </appender>

  <appender name="socket" class="org.apache.log4j.net.SocketAppender">
     <param name="RemoteHost" value="localhost"/>
     <param name="Port" value="4445"/>
  </appender>

  <root>
    <priority value="debug"></priority>
    <appender-ref ref="stdout"/> 
    <appender-ref ref="socket"/>
  </root>
</log4j:configuration>
As you see it's a really simple application uses log4j and we appended the socketAppender to the xml config. There is no layout associated with SocketAppender because it sends serialized events to the remote server.

Compile and run the java code and the result should look like:
wave@wave-laptop:~/log_test$ java -classpath log4j-1.2.16.jar org.apache.log4j.net.SimpleSocketServer 4445 socket_server.properties 
2011-03-19 18:01:19  INFO SimpleSocketServer:60 - Listening on port 4445
2011-03-19 18:01:19  INFO SimpleSocketServer:63 - Waiting to accept a new client.
2011-03-19 18:02:06  INFO SimpleSocketServer:65 - Connected to client at /127.0.0.1
2011-03-19 18:02:06  INFO SimpleSocketServer:66 - Starting new socket node.
2011-03-19 18:02:06  INFO SimpleSocketServer:63 - Waiting to accept a new client.
2011-03-19 18:02:06 DEBUG Main:9 - hi there
2011-03-19 18:02:06 DEBUG Main:10 - loggin from remote server
2011-03-19 18:02:06 DEBUG Main:11 - end
2011-03-19 18:02:06  INFO SocketNode:94 - Caught java.io.EOFException closing connection.
And yes it's saved on my_log.log file. If you stop and restart the SimpleSocketServer the client will transparently reconnect to the new server instance, although the events generated while disconnected will be lost. If the remote server is reachable, then log events will eventually arrive there. Otherwise, if the remote server is down or unreachable, the logging events will simply be dropped.

It's a really simple application but you got the idea.

To dive deep inside log4j check this out.

Happy logging :)

No comments:

Post a Comment