2

I've written a custom logging Class that behaves very similarly to a PrintWriter like System.out or System.err. The main difference is that when myLogger.printf("Hello World!\n"); is called, the data isn't written directly to the log file, but instead to an internal queue, and this queue only gets flushed to the output file via the flush(); method. So use of the code looks like this:

myLogger.println("Line 1.");
myLogger.println("Line 3.");
myLogger.println("Actually that was Line 2. THIS is Line 3!");
myLogger.flush();

Which should give an output that (sort of) looks like this:

2016-03-30 15:44:45::389> Line 1.
2016-03-30 15:44:45::390> Line 3.
2016-03-30 15:44:45::395> Actually that was Line 2. THIS is Line 3!

However, the problem I have is when users make mistakes. Namely, they forget to call flush(), and the data they've written to the logger never gets dumped to the file, and the program closes without ever flushing the data.

I can't flush after every single call, because it would defeat the purpose of writing this class in the first place. And having the system manage automatic flushing would be similarly self-defeating.

My idea was to put a call to flush() inside the finalize() method of the object, but as I've read from several other articles on this site, there's no guarantee that finalize() will ever be called.

Just for clarity's sake, this is what the flush() method looks like:

public void flush() {
    open();
    while(!unwrittenLogs.isEmpty()) {
        String line = unwrittenLogs.poll();
        log.print(line);
    }
    close();
}

private void open() {
    if(log == null) {
        try {
            log = new PrintWriter(new FileOutputStream(logFile, true));
        } catch (FileNotFoundException e) {
            System.err.printf("Unable to open Log File.\n%s\n",e.getMessage());
            e.printStackTrace(System.err);
        }
    }
}

private void close() {
    if(log != null) {
        log.close();
        log = null;
    }
}

So what is my best option to ensure that the logger is flushed before the program quits?

Community
  • 1
  • 1
Xirema
  • 19,889
  • 4
  • 32
  • 68
  • There are two things you can do: flush after every X writes, where X is configurable. Also you can [register a shutdown hook](https://docs.oracle.com/javase/8/docs/api/java/lang/Runtime.html#addShutdownHook-java.lang.Thread-) that calls `flush()` one last time. The shutdown hook won't always be called either, as the VM might just crash. – biziclop Mar 30 '16 at 21:02
  • There is also a subtle data race in your code: when `flush()` is called, another thread may still be posting messages in your logger, so when `close()` is called, `unwrittenLogs` may still have entries that will be silently dropped. – biziclop Mar 30 '16 at 21:25

3 Answers3

3

Put your method into the finalize method, like this:

@Override protected void finalize() throws Throwable {
    // TODO Auto-generated method stub
    // do some crazy stuff here
    super.finalize();
}

This is and example for object destruction.

For saving the data before the JVM gets shut down, use shutdown hooks:

public static void main(final String[] args) {
    Runtime.getRuntime().addShutdownHook(new Thread() {
        @Override public void run() {
            // TODO Auto-generated method stub
            // do the other crazy stuff in here
            super.run();
        }
    });
}

But both will not be a 100% safe to use. 1) You can close the JVM without all finalizers being run 2) If you kill the JVM process via task manager / kill signal, the shutdown hooks wont be triggered

JayC667
  • 2,418
  • 2
  • 17
  • 31
  • 1
    How do you mean? They deal with different aspects in the object lifecycle. One deals with GC, the other the sane shutdown of the JVM. – Will Hartung Mar 30 '16 at 21:08
  • 2
    @WillHartung That is true but if you register a shutdown hook, the object won't be eligible for GC anyway until the VM shuts down. See John Bollinger's answer as to why this is the case. – biziclop Mar 30 '16 at 21:11
  • 1
    throw a weak reference into the mix and that won't be a problem – the8472 Mar 31 '16 at 14:37
3

You've asked two different questions: how to ensure that your loggers' flush() method is invoked before that object is collected, and how to ensure that it is invoked before the program quits. As you gathered from your research, the logger might not be collected before the program quits, therefore a finalizer cannot guarantee that the method will be called.

If you would be satisfied with the logger being ineligible for GC prior to VM shutdown, then you could register a shutdown hook with the runtime, that flushes the logger. Such a hook would need to hold a reference to the logger, and the runtime will hold on to a reference to the hook (an unstarted Thread) until it shuts down, so the logger will remain ineligible for GC until the runtime executes its shutdown hooks.

John Bollinger
  • 160,171
  • 8
  • 81
  • 157
0

An alternative approach to a flushable writer:

  1. use a TransferQueue<LogItem> implementation
  2. create a separate log writer thread
  3. do a take() on the queue. [blocking]
  4. open log file, optionally do truncation and log rotation as desired at this point
  5. write taken item, drain additional items with poll() [non-blocking]
  6. flush and close log file
  7. if(application still running) then goto 3

This approach has several advantages:

  • the log thread will suffer the IO and flush costs, not the threads executing your business logic
  • it's thread-safe as there is only one writing thread
  • log item submission is lock-free as long as the TransferQueue implementation is, such as LinkedTransferQueue
  • the logger thread will keep the VM alive until logs are written, assuming thread.setDaemon(false), which is the default.
the8472
  • 40,999
  • 5
  • 70
  • 122