Geeks,  Java,  Programming

Thread safe logging to file using Java

In an attempt to create a simple logging class for a Java socket server application I was writing I wanted to make sure that the class captured all log events from the various threads sending messages to it. I didn’t want to have the situation where some messages were lost because the class could not handle the log messages being sent to it.

In order to do this I decided to use a Consumer – Producer concept. Thankfully in Java this concept has already been thought of via the use of java.util.concurrent.BlockingQueue. The set of classes available for use with this include

From various readings on StackOverflow I decided that DelayQueue, PriorityBlockingQueue and SynchronousQueue were not really appropiate for what I wanted. That left the Array and Linked queues. Both of these on reading appeared to offer what I wanted, but I didn’t know which one to use. So to help I decided to do a bit of Dependency injection and setup some tests that I could run to help me determine if there was any difference in the two and if so I would identify which one to use.

To start with I wanted to have a class that I didn’t have to create new instances of each time I wanted to write a log message. I also wanted to tell my log where to actually write to. Hence I create a EventLog class to do just that.

import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.BlockingQueue;
public class EventLog {

	private static Logstream _eventLog;
	public static Logstream create(BlockingQueue queue, String rootPath, int port)
	{
		_eventLog = new Logstream(queue, rootPath, port);
		return _eventLog;
	}
	
	public static Logstream create(String rootPath, int port)
	{
		return create(new ArrayBlockingQueue(10), rootPath, port);
	}
	
	public static void write(Exception ex, String cls, String func)
	{
		write("Exception: " + ex.toString(), cls, func);
	}
	
	public static void write(String msg, String cls, String func)
	{
		_eventLog.write(msg, cls, func);
	}
}

This has now enabled me to write to a log file as well as not having to create new objects every time to do that (Just looks pretty in the code :)). Now I wanted to set up a couple of capacity unit tests to ensure it could handle writing losts of values quickly.

Using JUnit I set up to test methods:

@Test
public void testLogStreamLinkedBlockingQueue() {
		
	EventLog.create(new LinkedBlockingQueue(), "c:\\Temp\\", 1);
		
	for(int i = 0; i < 10000; i++) {
		EventLog.write(Integer.toString(i), "EventLogUnitTest", "testLogStreamLinkedBlockingQueue");
	}
		
	Assert.assertTrue(true);
}

@Test
public void testLogStreamArrayBlockingQueue() {
		
	EventLog.create(new ArrayBlockingQueue(10), "c:\\Temp\\", 1);
		
	for(int i = 0; i < 10000; i++) {
		EventLog.write(Integer.toString(i), "EventLogUnitTest", "testLogStreamArrayBlockingQueue");
	}
		
	Assert.assertTrue(true);
}

Now to my actual class. All I wanted to to was writing the message to a log file. But to make the BlockingQueue work I had to ensure it ran on it's own thread so I didn't interupt the Producers doing the logging. So I created the simple LogStream class that could do just that.

import java.io.BufferedWriter;
import java.io.FileWriter;
import java.io.IOException;
import java.util.Calendar;
import java.util.Date;
import java.util.concurrent.BlockingQueue;
import java.text.SimpleDateFormat;

public class Logstream implements Runnable {

    private final String _path;			// The root path we will use for logging
    private final int _port;			// the port of the application using this logger
    private final BlockingQueue _queue; // Used to queue up messages for logging
    private final Thread _writeThread;	// Thread to run this logstream on
    
    private int _dayOfMonth = -1;		// The current day of the month
    private String _cachedPath = "";	// Our log path.  Changes for each day of the month
    
    protected Logstream(BlockingQueue queue, String rootPath, int port) {
    	_port = port;
		_path  = rootPath;
		
		_queue = queue;

		_writeThread = new Thread(this);
		_writeThread.start();
    }
	
	public void write(String msg, String cls, String func)
	{
		queue(msg, cls, func);		
	}

    public void run()
    {
    	// logging never stops unless we restart the entire server so just loop forever
        while(true) {
        	try {
        		StringBuilder builder = _queue.take();	
        		flush(builder);
        	} catch(InterruptedException ex) {
        		flush(ex.toString());
        		System.out.println("Exception: LogStream.run: " + ex.getMessage());
	        }    
        }
    }
    
	private void flush(StringBuilder builder) {	
		flush(builder.toString());
	}
	
    private void flush(String data) {

		BufferedWriter writer = null;

		try {
			
    		System.out.println(data);
    		
    		writer = getOutputStream();
    		
			writer.write(data);
			writer.newLine();
			writer.flush();				
    	}
    	catch(IOException ex) {
    		// what to do if we can't even log to our log file????
    		System.out.println("IOException: EventLog.flush: " + ex.getMessage());
    	}
		finally {
			closeOutputStream(writer);
		}
    }

    private boolean dayOfMonthHasChanged(Calendar calendar) {
    	return calendar.get(Calendar.DAY_OF_MONTH) != _dayOfMonth;
    }
    
    private String getPath() {
    	
    	Calendar calendar = Calendar.getInstance();
    	
    	if(dayOfMonthHasChanged(calendar)) {
    		
        	StringBuilder pathBuilder = new StringBuilder();
    		SimpleDateFormat df = new SimpleDateFormat("dd-MMM-yy");
    		Date date = new Date(System.currentTimeMillis());
    		
    		_dayOfMonth = calendar.get(Calendar.DAY_OF_MONTH);
    		
    		pathBuilder.append(_path);
    		pathBuilder.append(df.format(date)).append("_");
    		pathBuilder.append(_port);
    		pathBuilder.append(".txt");
    	
    		_cachedPath = pathBuilder.toString();    	
    	}
    	
    	return _cachedPath;
    }
    
    private BufferedWriter getOutputStream() throws IOException {
		return new BufferedWriter(new FileWriter(getPath(), true));			
    }
 
    private void closeOutputStream(BufferedWriter writer) {
    	try {
    		if(writer != null) {
    			writer.close();
    		}
    	}
    	catch(Exception ex) {
    		System.out.println("Exception: LogStream.closeOutputStream: " + ex.getMessage());
    	}	
    }

    private StringBuilder queue(String msg, String cls, String func) {
		Date date = new Date(System.currentTimeMillis());
		
		// $time  . ": " . $func . ": " . $msg ."\n"
		StringBuilder msgBuilder = new StringBuilder();
		msgBuilder.append(new SimpleDateFormat("H:mm:ss").format(date));
		msgBuilder.append(": ");
		msgBuilder.append(cls);
		msgBuilder.append("->");
		msgBuilder.append(func);
		msgBuilder.append("()");
		msgBuilder.append(" :: ");
		msgBuilder.append(msg);

		try {
			_queue.put(msgBuilder);
		}
		catch (InterruptedException e) {
			flush(new StringBuilder(e.toString()));
			flush(msgBuilder);
		}
		
		return msgBuilder;
	}
}

After creating this class I ran my unit tests. What I found was the LinkedBlockingQueue did not perform as well as the ArrayBlockingQueue. Not all items appeared to get logged while the ArrayBlockingQueue on every run of the test successfully logged all items.

So, the benefit of using a bit of DI. I can now swap out any BlockingQueue implementation and run tests against the same logging code without changing it. Well chuffed with that I am.

The only problem I had with this solution was What happens if my logging system itself fails? Well for that although I didn't implement any solution a couple of ideas I played around with was making use of the existing logging in Java already. Namely:

http://logging.apache.org/log4j/1.2/index.html
http://www.slf4j.org

But I didn't put those in just yet. And perhaps they might be better logging solutions anyway. However if I do decide to implement these I can do so by not changing the LogEvent and LogStream interfaces thus maintaining the integrity of the rest of the code.

Maybe one day in the future I might look at doing that. But for now. The loggings working as I want. So for using slf4, that is for another day. To be continued.....

You can see a review of this code and what other people have had to say at it's publishing on Stackexchange - Code review

Leave a Reply