Fabrizio Giudici is a Senior Java Architect with a long Java experience in the industrial field. He runs Tidalwave, his own consultancy company, and has contributed to Java success stories in a number of fields, including Formula One. Fabrizio often appears as a speaker at international Java conferences such as JavaOne and Devoxx and is member of JUG Milano and the NetBeans Dream Team. Fabrizio is a DZone MVB and is not an employee of DZone and has posted 67 posts at DZone. You can read more from them at their website. View Full User Profile

Logging on a Per-Thread Basis

11.21.2009
| 13976 views |
  • submit to reddit

As far as I know, most of the logging facility configurations enable you to specify the maximum size of a log file, how many will roll, where data is fed to and eventually dispatching multiple destinations in function of the log level. I've found nothing (apart from a couple of discussions on java.net forums) about splitting logs in function of the thread - that is, all the logging from a thread goes in a file and the logging from another thread goes in another file.

Why should one do that? I'm not thinking of production, but about testing - precisely parallel testing, and now I think you've got the point. Well-written tests are completely independent of each other, thus there's no point in looking at a global sequence of events - instead, you want to consider each one as an independent sequence of events.

So, here is my solution: a custom java.util.logging.Handler that dispatches to multiple FileHandlers in function of the ThreadGroup.

package it.tidalwave.thesefoolishthings.junit;

import javax.annotation.Nonnull;
import java.util.HashMap;
import java.util.Map;
import java.util.logging.FileHandler;
import java.util.logging.Handler;
import java.util.logging.LogRecord;
import java.io.IOException;

public class MultiThreadHandler extends Handler
{
private static final Handler VOID_HANDLER = new Handler()
{
@Override
public void publish (final LogRecord logRecord)
{
}

@Override
public void flush()
{
}

@Override
public void close()
{
}
};

private static final Map<ThreadGroup, String> LOG_NAME_MAP = new HashMap<ThreadGroup, String>();

private final Map<String, Handler> handlerMap = new HashMap<String, Handler>();

protected String directory = "target/logs";

public static void setLogName (final @Nonnull String name)
{
LOG_NAME_MAP.put(Thread.currentThread().getThreadGroup(), name);
}

public static void resetLogName()
{
LOG_NAME_MAP.remove(Thread.currentThread().getThreadGroup());
}

public void setDirectory (final String directory)
{
this.directory = directory;
}

public String getDirectory()
{
return directory;
}

@Override
public void publish (final @Nonnull LogRecord logRecord)
{
getHandler().publish(logRecord);
}

@Override
public void flush()
{
getHandler().flush();
}

@Override
public void close()
throws SecurityException
{
getHandler().close();
}

@Nonnull
private synchronized Handler getHandler()
{
final String id = LOG_NAME_MAP.get(Thread.currentThread().getThreadGroup());

if (id == null)
{
return VOID_HANDLER;
}

Handler handler = handlerMap.get(id);

if (handler == null)
{
try
{
final String fileName = id.replace(':', '_').replace('/', '_').replace('[', '_').replace(']', '_').replace(' ', '_');
handler = new FileHandler(String.format("%s/log-%s.log", directory, fileName));
handler.setFormatter(getFormatter());
handlerMap.put(id, handler);
}
catch (IOException e)
{
e.printStackTrace();
}
catch (SecurityException e)
{
e.printStackTrace();
}
}

return (handler != null) ? handler : VOID_HANDLER;
}
}

The test (or the facility running the tests) should call the static method setTestName() which will be associated to the current ThreadGroup; from now on, all the logging generated by the current thread and its children (hence the need for the ThreadGroup) will go to that file. The ThreadGroup association to the file name is done by hand - I think I've sometimes seen a ThreadGroupLocal class, but I couldn't find anything with Google. A real ThreadGroupLocal would be more sophisticated, but a simple Map is good for my purpose.

It can be used, for instance, with this configuration file:

handlers=java.util.logging.FileHandler, it.tidalwave.thesefoolishthings.junit.MultiThreadHandler

java.util.logging.FileHandler.level = ALL
java.util.logging.FileHandler.pattern = target/logs/jrawio.log
java.util.logging.FileHandler.limit = 10000000
java.util.logging.FileHandler.count = 20
java.util.logging.FileHandler.formatter = it.tidalwave.imageio.SingleLineLogFormatter

java.util.logging.ConsoleHandler.level = ALL
java.util.logging.ConsoleHandler.formatter = it.tidalwave.imageio.SingleLineLogFormatter

it.tidalwave.thesefoolishthings.junit.MultiThreadHandler.level = ALL
it.tidalwave.thesefoolishthings.junit.MultiThreadHandler.directory = target/logs
it.tidalwave.thesefoolishthings.junit.MultiThreadHandler.formatter = it.tidalwave.imageio.SingleLineLogFormatter
For the record, I wasn't able to have the 'directory' property actually set by the configuration file - frankly I just supposed that one could set properties by standard JavaBean conventions, but I'm not sure. There are a few things to finish, but it can be used - actually, I've tried with a home-made JUnit parallel test runner and seems to work. I'll blog later about the parallel test runner as there are still issues and I'm not sure whether they are due to the parallel runner or to some code under test with a few not-thread-safe sections.

 

 

0
Your rating: None
Published at DZone with permission of Fabrizio Giudici, author and DZone MVB.

(Note: Opinions expressed in this article and its replies are the opinions of their respective authors and not those of DZone, Inc.)

Comments

Jesse Sightler replied on Sat, 2009/11/21 - 6:55pm

Or you could just use NDCs and grep. :)

Fabrizio Giudici replied on Sun, 2009/11/22 - 3:53pm

Too bad there's not (AFAIK) a NDC stuff for java.util.logging. I suppose the reason is because jul is not largely used in server-side projects, where analysing per-thread logs makes more sense in production.

Yves Bossel replied on Mon, 2009/11/23 - 1:57pm

We have been using NDC in a production environment. If you also log the request hash, session hash and user id, you have a great tool to trace user requests and debug the code. The request is the right granularity to log a web application (you'll have to create a filter to correctly set the ndc logging limits, i.e. request).

Chris Knoll replied on Tue, 2009/11/24 - 9:39pm

Any reason why thread local vars are out of the question?

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.