0

When I work on personal Java projects, I like to have a way of nicely logging text to console. I generally make some public static class for this to handle prefixing and applying a timestamp to the message so I can omit the usage of System.out.println(“Text”); .

This is a class I wrote a while ago and I tend to reuse it on different projects because I really like the way it formats the text:

import java.text.SimpleDateFormat;
import java.util.Date;

public class Log {

    public static final int LEVEL_INFO = 0;
    public static final int LEVEL_WARNING = 1;
    public static final int LEVEL_ERROR = 2;

    private static SimpleDateFormat df = new SimpleDateFormat("HH:mm:ss");
    /**
     * Used instead of System.out.println for consistent formatting.
     *
     * @param messageToPrefix Message that you want to send to print.
     * @param errorLevel Type of message you want to send.
     */
    public static void print(String messageToPrefix, int errorLevel) {
        StringBuilder message = new StringBuilder();
        message.append("[").append(df.format(new Date())).append("] ");
        switch(errorLevel) {
            case LEVEL_INFO:
                 message.append("[Info] ");
                break;
            case LEVEL_WARNING:
                message.append("[Warning] ");
                break;
            case LEVEL_ERROR:
                message.append("[Error] ");
                break;
        }
        message.append(messageToPrefix);
        System.out.println(message.toString());
    }
}

This is all works as expected but there is a small problem I noticed a while ago: this way of creating a timestamp is very resource intensive! Calling this requires the code I want to log to halt until the timestamp has been made and written to console. This just seems inefficient to me (even tho we are talking about several milliseconds here). I came to this conclusion when I compared the runtime of this logging method to one that used System.currentTimeMillis() which does not format it to a nice timestamp but shows the runtime in ms if used like this:

public class Log {

    private static final long startTime = System.currentTimeMillis();

    public static final int LOG_LEVEL_INFO = 0;
    public static final int LOG_LEVEL_WARNING = 1;
    public static final int LOG_LEVEL_ERROR = 2;
    public static final int LOG_LEVEL_UNKNOWN = 3;

    /**
     * Used instead of System.out.println for consistent formatting.
     *
     * @param msg Message that you want to send to log.
     * @param importance How important is the message?
     */
    public static void print(String msg, int importance) {
        StringBuilder finalMsg = new StringBuilder();
        finalMsg.append("[").append(System.currentTimeMillis() - startTime).append(" ms] ");
        switch (importance) {
            case 0:
                finalMsg.append("[INFO] ");
                break;
            case 1:
                finalMsg.append("[WARNING] ");
                break;
            case 2:
                finalMsg.append("[ERROR] ");
                break;
            default:
                finalMsg.append("[UNKNOWN] ");
                break;
        }
        finalMsg.append(msg);
        System.out.println(finalMsg);
    }
}

This way proved to be way faster even on a small scale like 50 messages over approx. 50 seconds of running time.

This got me thinking about several questions: Is there a better way for creating timestamps like this? Is there a way to not wait for the logging code to complete? Would starting a thread for this be a good idea? Or am I on a completely wrong track altogether?

I would like to not use any extra libraries for this to keep it small and simple.

Any advice would be much appreciated!

Sjoerd Dal
  • 696
  • 4
  • 14
  • 2
    Use a logging library, e.g. the built-in [`java.util.logging`](https://docs.oracle.com/javase/8/docs/api/java/util/logging/package-summary.html#package.description), also referred to as JUL. – Andreas May 30 '17 at 15:48
  • On another note: [Careful with the static SimpleDateFormat](https://stackoverflow.com/questions/4021151/java-dateformat-is-not-threadsafe-what-does-this-leads-to). Although fixing that will probably further increase your processing time. – Marvin May 30 '17 at 15:49
  • @Andreas I see. Honestly I wasn't aware of its existence. I will try that, Thanks. – Sjoerd Dal May 30 '17 at 15:50
  • @Marvin Yikes! Thanks for the warning. – Sjoerd Dal May 30 '17 at 15:53

1 Answers1

0

EDIT: Alright I think that (after following some advise) that this is a safe way to log and timestamp messages. It may not be the fastest method but it is safe to use and gives me the result I want.

import java.text.SimpleDateFormat;
import java.util.Date;

    public class Log {

        public static final int LEVEL_INFO = 0;
        public static final int LEVEL_WARNING = 1;
        public static final int LEVEL_ERROR = 2;

        private static final ThreadLocal<SimpleDateFormat> formatter = ThreadLocal.withInitial(() -> new SimpleDateFormat("HH:mm:ss"));

        /**
         * Used instead of System.out.println for consistent formatting.
         *
         * @param messageToPrefix Message that you want to send to print.
         * @param errorLevel Type of message you want to send.
         */
        public static void print(String messageToPrefix, int errorLevel) {
            StringBuilder message = new StringBuilder();
            message.append("[").append(formatter.get().format(new Date())).append("] ");
            switch(errorLevel) {
                case LEVEL_INFO:
                    message.append("[Info] ");
                    break;
                case LEVEL_WARNING:
                    message.append("[Warning] ");
                    break;
                case LEVEL_ERROR:
                    message.append("[Error] ");
                    break;
            }
            message.append(messageToPrefix);
            System.out.println(message.toString());
        }
    }

I want to thank the people in the comments for all the advice they gave.

Sjoerd Dal
  • 696
  • 4
  • 14
  • Thread safety only matters if you'll be running your app in a concurrent environment where its state is accessed by multiple threads. If this isn't true, locking will slow your program down. Some thread safe classes (eg. StringBuffer) were re-implemented for this reason (as StringBuilder). And some thread safe classes, eg. BigInteger, come with mutable companion classes (BitSet) to use in particular performance scenarios. – scottb May 30 '17 at 23:28
  • Your class as it was written appears to be thread safe anyway, except for the mutable SimpleDateFormat. Using the corresponding class from the Java Date-Time library, whose objects are immutable (and therefore always thread safe), would allow your program to remain thread safe without the need for locking. – scottb May 30 '17 at 23:31
  • Agreed with scottb. If you can, go for Java Date-Time library and drop the obsolete crap. And you can, even without Java 8 as there's a backport. +++ When working with thread-unsafe parts, consider using `ThreadLocal`. +++ Consider storing the last milliseconds together with the formatted string as a single-element cache. This might be useful even with a modern library though I believe `java.time` optimized heavily. – maaartinus May 31 '17 at 10:37
  • @maaartinus I see. That does seem to be a better solution. I think I will go with my original class then and put the SimpleDateFormat inside a ThreadLocal Object using the initialValue method. – Sjoerd Dal May 31 '17 at 11:19
  • 1
    I see. Note that `ThreadLocal.initialValue ` creates a memory leak when you redeploy the application in a (web server) container. But you probably don't, so it's fine. ;) – maaartinus May 31 '17 at 12:05