If I/O is truly the bottleneck and you don't need file rotation and file locking then create a Handler that queues the fully formatted output string/bytebuffer from your LogRecord + "trace message". Then hand off/queue the fully formatted output string/bytebuffer to a thread to perform the I/O.
Otherwise, if you need to use the FileHandler and want to pass a LogRecord + your trace to the publish method you can just subclass the FileHandler and then create a mapping between your LogRecord and trace that is visible to your custom formatter. A few ways to do that are:
- Create a Map<LogRecord, Trace> visible to both the handler and formatter.
- Create a LogRecord subclass to hold the trace and convert each LogRecord to your new subclass and super.publish the LogRecord subclass. Then cast each LogRecord in your formatter to access the trace.
4.Now I've realised that I can't use the "log" methods provided by the logger, as that attempts to invoke methods on the current thread to format and print out the messages.
Logger.log creates LogRecords and invokes handler.publish for the attached handlers and parent handlers by default. It is handler.publish that is performing the I/O on the current thread. What you have to do is remove all handlers that perform I/O on publish and replace them with handlers that just queue LogRecords on publish.
Here is an example of how to create an AsyncFileHandler:
public class AsyncFileHandler extends FileHandler implements Runnable {
private static final int offValue = Level.OFF.intValue();
private final BlockingQueue<LogRecord> queue = new ArrayBlockingQueue<>(5000);
private volatile Thread worker;
public AsyncFileHandler() throws IOException {
super();
}
public AsyncFileHandler(String pattern, int limit, int count, boolean append)
throws IOException {
super(pattern, limit, count, append);
}
@Override
public void publish(LogRecord record) {
int levelValue = getLevel().intValue();
if (record.getLevel().intValue() < levelValue || levelValue == offValue) {
return;
}
final Thread t = checkWorker();
record.getSourceMethodName(); //Infer caller.
boolean interrupted = Thread.interrupted();
try {
for (;;) {
try {
boolean offered = queue.offer(record, 10, TimeUnit.MILLISECONDS);
if (t == null || !t.isAlive()) {
if (!offered || queue.remove(record)) {
handleShutdown(record);
}
break;
} else {
if (offered || handleFullQueue(record)) {
break;
}
}
} catch (InterruptedException retry) {
interrupted = true;
}
}
} finally {
if (interrupted) {
Thread.currentThread().interrupt();
}
}
}
private boolean handleFullQueue(LogRecord r) {
super.publish(r);
return true; //true if handled.
}
private void handleShutdown(LogRecord r) {
super.publish(r);
}
@Override
public void close() {
try {
try {
final Thread t = this.worker;
if (t != null) {
t.interrupt();
shutdownQueue();
t.join();
shutdownQueue();
}
} finally {
super.close();
}
} catch (InterruptedException reAssert) {
Thread.currentThread().interrupt();
}
}
private void shutdownQueue() {
for (LogRecord r; (r = queue.poll()) != null;) {
handleShutdown(r);
}
}
@Override
public void run() {
try {
final BlockingQueue<LogRecord> q = this.queue;
for (;;) {
super.publish(q.take());
}
} catch (InterruptedException shutdown) {
shutdownQueue();
Thread.currentThread().interrupt();
}
}
private Thread checkWorker() {
Thread t = worker;
if (t == null) {
t = startWorker();
}
return t;
}
private synchronized Thread startWorker() {
if (worker == null) {
worker = Executors.defaultThreadFactory().newThread(this);
worker.setDaemon(true); //JDK-8060132
worker.setContextClassLoader(getClass().getClassLoader());
worker.start();
}
return worker;
}
}
There is advice in the LogRecord documentation which even the original authors fail to follow in the MemoryHandler. It reads as the following:
Therefore, if a logging Handler wants to pass off a LogRecord to another thread, or to transmit it over RMI, and if it wishes to subsequently obtain method name or class name information it should call one of getSourceClassName or getSourceMethodName to force the values to be filled in.
So if you are going to buffer LogRecords in a queue you have to call getSourceClassName or getSourceMethodName before you add the records to the queue. Otherwise your log will record the wrong source class and source method names.
