Locking files while using Java Logger

Question

I am creating a logger that will log things throughout my program. It seems to work fine. This is what the class looks like.

public class TESTLogger {

  protected static File file;
  protected static Logger logger = Logger.getLogger("");

  public TESTLogger(String logName) {
      setupLogger(logName);
  }

  private static void setupLogger(String logName) {
      String basePath  = Utils.getBasePath();

      File logsDir = new File(basePath);
      if(logsDir.exists() == false) {
          logsDir.mkdir();
      }
      String filePath = basePath + File.separator + logName + ".%g.log";
      file = new File(filePath);
      try {
          FileHandler fileHandler = new FileHandler(filePath, 5242880, 5, true);
          fileHandler.setFormatter(new java.util.logging.Formatter() {
              @Override
              public String format(LogRecord logRecord) {
                  if(logRecord.getLevel() == Level.INFO) {
                      return "[INFO  " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                  } else if(logRecord.getLevel() == Level.WARNING) {
                    return "[WARN  " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                  } else if(logRecord.getLevel() == Level.SEVERE) {
                    return "[ERROR " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                  } else {
                    return "[OTHER " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                }

              }
          });
          logger.addHandler(fileHandler);
      } catch (IOException e) {
      }
  }

  private static void writeToFile(Level level, String writeThisToFile) {
      logger.log(level, writeThisToFile);
  }

  private static String createDateTimeLog() {
      String dateTime = "";
      Date date = new Date();
      SimpleDateFormat simpleDateFormat = new SimpleDateFormat("yyyy-MM-dd H:mm:ss");
      dateTime = simpleDateFormat.format(date);
      return dateTime;
  }

  public void error(String message) {
      writeToFile(Level.SEVERE, message);
  }

  public void warn(String message) {
      writeToFile(Level.WARNING, message);
  }

  public void info(String message) {
      writeToFile(Level.INFO, message);
  }
}

When my application starts it creats the TESTLogger object. Then whenever I log I run logger.info / logger.warn / logger.error with my log message. That is working great. However, multiple instances of my jar can be running at the same time. When that happens, it creates a new instance of the log. IE: I could have myLog.0.log. When the second instance of the jar logs something it will go under myLog.0.log.1, then myLog.0.log.2 and so on.

I don't want to create all these different instances of my log file. I thought I might use a File Lock (from java.nio.channels package). However, I have not been able to figure out how to do that with the Java Logger class I am using (java.util.logging).

Any ideas how to prevent this from happening would be great. Thanks in advance.

EDIT: Ok. So I have rewritten writeToFile and it seems to work a little better. However, every now and again I still get a .1 log. It doesn't happen as much as it used to. And it NEVER gets to .2 (it used to get all the way up to .100). I would still like to prevent this .1, though.

This is what my code looks like now:

private static void writeToFile(Level level, String writeThisToFile) {

    try {
        File file = new File("FileLock");
        FileChannel channel = new RandomAccessFile(file, "rw").getChannel();
        FileLock lock = null;
        try {
            lock = channel.tryLock(0, Long.MAX_VALUE, true);
            if(lock != null) {
                logger.log(level, writeThisToFile);
            }
        } catch (OverlappingFileLockException e) {

        }
        finally {
            if(lock != null) {
                lock.release();
            }
            channel.close();
        }

    } catch (IOException e) {}
}

EDIT #2: What it currently looks like.

Entrance point into my JAR:

public class StartingPoint {

  public static void main(String[] args) {
    MyLogger logger = new MyLogger("myFirstLogger");
    logger.info("Info test message");
    logger.warn("Warning test message");
    logger.error("Error test message");
  }
}

MyLogger class:

public class MyLogger {

  protected static File file;
  protected static Logger logger = Logger.getLogger("");

  public MyLogger(String loggerName) {
    setupLogger(loggerName);
  }

  private void setupLogger(String loggerName) {

    String filePath = loggerName + "_%g" + ".log";
    file = new File(filePath);
    try {
        FileHandler fileHandler = new FileHandler(filePath, 5242880, 5, true);
        fileHandler.setFormatter(new java.util.logging.Formatter() {
            @Override
            public String format(LogRecord logRecord) {
                if(logRecord.getLevel() == Level.INFO) {
                    return "[INFO  " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                } else if(logRecord.getLevel() == Level.WARNING) {
                    return "[WARN  " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                } else if(logRecord.getLevel() == Level.SEVERE) {
                    return "[ERROR " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                } else {
                    return "[OTHER " + createDateTimeLog() + "]  " + logRecord.getMessage() + "\r\n";
                }

            }
        });
        logger.addHandler(fileHandler);
        logger.addHandler(new SharedFileHandler());  // <--- SharedFileHandler added

    } catch (IOException e) {}
  }

  private void writeToFile(Level level, String writeThisToFile) {
    logger.log(level, writeThisToFile);
  }

  private static String createDateTimeLog() {
    String dateTime = "";
    Date date = new Date();
    SimpleDateFormat simpleDateFormat = new SimpleDateFormat("yyyy-MM-dd H:mm:ss");
    dateTime = simpleDateFormat.format(date);
    return dateTime;
  }

  public void error(String message) {
    writeToFile(Level.SEVERE, message);
  }

  public void warn(String message) {
    writeToFile(Level.WARNING, message);
  }

  public void info(String message) {
    writeToFile(Level.INFO, message);
  }
}

And finally... SharedFileHandler:

public class SharedFileHandler extends Handler {
  private final FileChannel mutex;
  private final String pattern;

  public SharedFileHandler() throws IOException {
    this("loggerLockFile");
  }

  public SharedFileHandler(String pattern) throws IOException {
    setFormatter(new SimpleFormatter());
    this.pattern = pattern;
    mutex = new RandomAccessFile(pattern, "rw").getChannel();
  }

  @Override
  public void publish(LogRecord record) {
    if (isLoggable(record)) {
        record.getSourceMethodName(); //Infer caller.
        try {
            FileLock ticket = mutex.lock();
            try {
                doPublish(record);
            } finally {
                ticket.release();
            }
        } catch (IOException e) {}
        catch (OverlappingFileLockException e) {}
        catch (NullPointerException e) {}
    }
  }

  private void doPublish(LogRecord record) throws IOException {
    final FileHandler h = new FileHandler(pattern, 5242880, 5, true);
    try {
        h.setEncoding(getEncoding());
        h.setErrorManager(getErrorManager());
        h.setFilter(getFilter());
        h.setFormatter(getFormatter());
        h.setLevel(getLevel());
        h.publish(record);
        h.flush();
    } finally {
        h.close();
    }
  }

  @Override
  public void flush() {}

  @Override
  public synchronized void close() throws SecurityException {
    super.setLevel(Level.OFF);
    try {
        mutex.close();
    } catch (IOException ioe) {}
  }
}

Answer 1

The FileHandler does everything it can to prevent two concurrently running JVMs from writing to the same log file. If this behavior was allowed the log file would be almost impossible to read and understand.

If you really want to write everything to one log file then you have to do one of the following:

1. Prevent concurrent JVM processes from starting by changing how it is launched.
2. Have your code detect if another JVM is running your code and exit before creating a FileHandler.
3. Have each JVM write to a distinct log file and create code to safely merge the files into one.
4. Create a proxy Handler that creates and closes a FileHandler for each log record. The proxy handler would use a predefined file name (different from the log file) and a FileLock to serialize access to the log file from different JVMs.
5. Use a dedicated process to write to the log file and have all the JVMs send log messages to that process.

Here is an untested example of a proxy handler:

import java.io.IOException;
import java.nio.channels.FileChannel;
import java.nio.channels.FileLock;
import java.nio.channels.OverlappingFileLockException;
import java.nio.file.Paths;
import java.util.logging.*;
import static java.nio.file.StandardOpenOption.*;

public class SharedFileHandler extends Handler {
    private final FileChannel mutex;
    private final String pattern;

    public SharedFileHandler() throws IOException {
        this("%hjava%g.log");
    }

    public SharedFileHandler(String pattern) throws IOException {
        setFormatter(new SimpleFormatter());
        this.pattern = pattern;
        Path p = Paths.get(new File(".").getCanonicalPath(), 
            pattern.replace("%", "") + ".lck");
        mutex = FileChannel.open(p, CREATE, WRITE, DELETE_ON_CLOSE);
    }

    @Override
    public void publish(LogRecord record) {
        if (isLoggable(record)) {
            record.getSourceMethodName(); //Infer caller.
            try {
                FileLock ticket = mutex.lock();
                try {
                    doPublish(ticket, record);
                } finally {
                    ticket.release();
                }
            } catch (IOException | OverlappingFileLockException ex) {
                reportError(null, ex, ErrorManager.WRITE_FAILURE);
            }
        }
    }

    private synchronized void doPublish(FileLock ticket, LogRecord record) throws IOException {
        if (!ticket.isValid()) {
           return;
        }
        final FileHandler h = new FileHandler(pattern, 5242880, 5, true);
        try {
            h.setEncoding(getEncoding());
            h.setErrorManager(getErrorManager());
            h.setFilter((Filter) null);
            h.setFormatter(getFormatter());
            h.setLevel(getLevel());
            h.publish(record);
            h.flush();
        } finally {
            h.close();
        }
    }

    @Override
    public void flush() {
    }

    @Override
    public synchronized void close() throws SecurityException {
        super.setLevel(Level.OFF);
        try {
             mutex.close();
        } catch (IOException ioe) {
            this.reportError(null, ioe, ErrorManager.CLOSE_FAILURE);
        }
    }
}

Here is a simple test case

public static void main(String[] args) throws Exception {
    Random rnd = new Random();
    logger.addHandler(new SharedFileHandler());
    String id = ManagementFactory.getRuntimeMXBean().getName();
    for (int i = 0; i < 600; i++) {
        logger.log(Level.INFO, id);
        Thread.sleep(rnd.nextInt(100));
    }
}