Using log4j's SocketAppender

Intro

Java loggers such as Apache log4j are excellent tools for logging your application's output. If you're still using System.out you should really consider switching to a logger. With only a very minimal increase in the amount of code you have to write, you get a lot of useful features over System.out. You simply replace System.out by something like LOG.info and LOG.debug and add one line to each class that creates the LOG object. You then get a lot of features for free:

• write your application's output to other places than the console, typically a log file; but you can even report errors over email
• print extra information such as the time, the class name and the method name
• filter which messages to log, e.g. only errors, also warnings, also info, also debug information. This can even depend on which package the code is in; e.g. you can set the level to "debug" for your own code and to "warning" for third party libraries.

All these features are typically configured in one file and are completely transparent to your code. There are several loggers of which log4j is probably the most popular one, but since JDK 1.4 Java also has a logger. There is also an easy way to be able to use any of several logger implementations so you can easily switch between them without affecting your code. This is by using Apache Commons Logging.  


My situation

I am using commons logging together with log4j as implementation. When I was writing a small system for (integration) testing our server/client system, I thought it would be useful if the output produced by each client is available at the server, which I also made to be the machine which starts each of the remote clients and runs the tests. I am using the Windows-specific tool "psexec" to remotely launch the javaws command - Java Web Start - to launch each client without having to worry about copying jars to the client. Unfortunately, javaws does not pipe the standard console output and error streams to the Process you use to start it. (Psexec also had an issue with these streams, RemCom.exe is an alternative without these issues but I found it useless for javaws because it runs under user SYSTEM and does not show the "accept certificate" GUI dialog). Instead of copying the log file of each client we can use log4j's SocketAppender at each client to send the log entries to the server.


Log4j SocketAppender

For the rest of this post I assume you are somewhat familiar with setting up log4j through a log4j.xml config file, otherwise check their website.

A possible solution to the above problem is by using the SocketAppender. Instead of writing to console or file, this appender writes to a socket. So for my problem I would adjust the log4j.xml of my client application to write to a socket on the server. I did not find good official documentation of how to setup both the client and server. The first thing I found through google search was this post. This helped me a bit further to know what to use and what not to do. For the client config I stumbled upon some documentation from JBoss on which I based the client config:

    <appender name="socket" class="org.apache.log4j.net.SocketAppender">
        <param name="Port" value="4560" />
        <param name="RemoteHost" value="localhost" />
        <param name="ReconnectionDelay" value="60000" />
        <param name="Threshold" value="INFO" />
    </appender>

This configuration is sufficient to create an appender which sends the info (or warnings/errors) to the remote server with the given hostname on port 4560. When it cannot connect it tries again in 60 seconds. This appender can then be used like any other appenders in your config. This configuration is not too hard. But what to do on the side that should receive the log entries? As far as I know the only higher level class that log4j provides for this is the org.apache.log4j.net.SimpleSocketServer, otherwise you will have to create the server side sockets yourself (which isn't all that hard as we will see). This class has a main method so it can be run as a separate program. It takes two parameters, namely the port to start the server on and the server side log4j configuration file. It will then listen to any client that connects to it and log the messages using this configuration. Surprisingly this worked right "out of the box". However for my application I didn't want to start a separate program for this; I wanted the client output to be written in between the integration test server output. I could probably just call this main method directly from my code, but conceptually this somehow didn't feel right; it also has the (arguably very small) disadvantages that you have to specify the location of your log4j config file and that you have to convert the port number to a String. Moreover, my program would completely block unless I created a separate thread on which to call the main method. This was reason enough to write my own class based on the SimpleSocketServer. This code turned out to be quite short and simple indeed, so I did some copy/paste and came up with the following class:

package nl.hm.olga.integration;

import java.net.InetAddress;
import java.net.ServerSocket;
import java.net.Socket;

import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.log4j.net.SocketNode;
import org.apache.log4j.net.SocketServer;
import org.apache.log4j.spi.LoggerRepository;

public class SocketLogger extends Thread {

    private static final int DEFAULT_PORT = 4560;
    private static Logger cat = Logger.getLogger(SocketServer.class);
    private final int port;

    public SocketLogger(int port) {
        this.port = port;
    }

    public SocketLogger() {
        this(DEFAULT_PORT);
    }

    @Override
    public final void run() {
        try {
            cat.info("Listening on port " + port);
            ServerSocket serverSocket = new ServerSocket(port);
            while (true) {
                cat.info("Waiting to accept a new client.");
                Socket socket = serverSocket.accept();
                InetAddress inetAddress = socket.getInetAddress();
                cat.info("Connected to client at " + inetAddress);

                LoggerRepository h = LogManager.getLoggerRepository();

                cat.info("Starting new socket node.");
                // TODO: can we use information in the socket to
                // record the client host?
                new Thread(new SocketNode(socket, h)).start();
            }
        } catch (Exception e) {
            e.printStackTrace();
        }
    }
}

The socket server can then be started in the server initialization code by calling

    new SocketLogger().start();

Note that the information that the clients send through the socket appender contains no formatting information whatsoever; only the client side log entry (LoggingEvent) information. The server simply logs them as if they originated from the server. This has the following consequences:

• The logged time is the time reported by the client (which is probably what we do want)
• The formatting layout used for the client logs is ignored in the server logs
• There is no way to see which client has sent the log entry, unless you change log4j SocketAppender implementation or let the client explicitly output its name in the log entries.

The last point is probably the most annoying. A solution would be to include the client host name and some kind of Java VM identifier to (a subclass of?) LogEntry; but we would need to adjust the log4j implementation and the client could send a fake id. We could probably also adjust the server code to add the client's address information and port to the log (don't forget that several clients may run on the same machine). A quick and dirty solution is to simply add the client name to the string passed in each LOG.info call. I wouldn't recommend this approach in production code because you would need some static/singleton class to look up the client ID in each and every logger call.

Another issue is that opening a port which accepts remote logging events from any - i.e. possibly untrusted - client is probably not a good idea. You might want to add some security or use the existing security mechanism if you have one, after which you securely send LoggingEvent objects, but this would mean you are basically writing your own Appender and server code.


Conclusions

For testing purposes it can be useful and it is quite easy to set up log4j in a client/server system to have clients send their logging events to the server. The client only has to add a few lines to the log4j.xml file to add a SocketAppender and with the SimpleSocketServer or the SocketLogger I provided above (which comes with absolutely no warranty...) the server only needs to call one simple command to start logging requests from any client.

Unfortunately there is no transparent out-of-the-box support for logging the name and an ID of the client.

This system might be used (unchanged) in production code only behind a good firewall, it is probably not wise to use it directly over the internet.