Custom Logging Class: Efficiency

Question

I wrote a logging class for several of my applications, but I have noticed that it is fairly in-efficient. Can anyone suggest improvements?

What I am looking for:

• Pointers on improving efficiency
• Tips for lowering the code-footprint
• Suggested functional improvements

Please be as nit-picky as possible, I'd like to make this class as robust as possible.

import java.io.FileInputStream;
import java.io.FileWriter;                                          
import java.io.IOException;                                         
import java.io.PrintWriter; 
import java.text.SimpleDateFormat;  
import java.util.Date;                                              
import java.util.Properties;

class FunctionLogging
{
    private String path;                                           
    private boolean appendToFile = false;



    public FunctionLogging(String file_path, int logLevel, boolean append_value)
    {
        path = file_path;   //used as a placeholder variable for the output path. Can be hard-coded but is preferredly configurable from properties file                                      
        appendToFile = append_value; //Set as true when called in each class used in. true appends line to the end of the file, false overwrites file contents
    }
    public void writeToFile(int logType, String textLine) throws IOException
    {
        FileInputStream propFile = new FileInputStream("config.ini");
        Properties config = new Properties(System.getProperties());
        config.load(propFile);
        String tempLev = config.getProperty("loggingLevel");
        int logLevel = Integer.parseInt(tempLev);
        if(logType<=logLevel)
        {
            //This section is devoted to creating a timestamp of the instance when the output string is created.
            Date date = new Date();
            SimpleDateFormat format = new SimpleDateFormat();
            format = new SimpleDateFormat("dd-MM-yyyy|HH:mm:ss:SSSSSS|");
            String timeStamp = format.format(date);
            SimpleDateFormat app = new SimpleDateFormat();
            app = new SimpleDateFormat("dd-MM-yyyy");
            String dateApp = app.format(date);
            int id = 0;

            String[] messages = new String[4];
            messages[0]="FATAL";
            messages[1]="WARN";
            messages[2]="NOTICE";
            messages[3]="DEBUG";
            FileWriter logWriter = new FileWriter(path+dateApp+".log", appendToFile);
            PrintWriter loggerLines = new PrintWriter(logWriter);

            loggerLines.println(timeStamp+id+++"|"+messages[logType]+"|"+textLine);
            loggerLines.close();
        }
    }
}

Answer 1

Efficiency

• the biggest improvement will be to not open the config file each time you log something, but only once when instantiating the logger.
• you could also open the log file only once, but it might not be a good idea to have it open for the whole lifetime of the program.
• create only one instance of the two SimpleDateFormat objects and store it in a class level field instead of creating them each time.
• also create your messages array only once as a field.

Robustness

• use an enum instead of string for your warning levels
• you are never closing your propFile stream.

Readability

• follow the standard Java indent style: curly brackets go on the same line as the opening statement.
• use more spaces (around <=, =, etc). This point and the previous one can be fixed by any IDE.
• don't do this: timeStamp+id+++"|".
• use camelCase for all variable names, don't mix it with snake_case except for final static fields.
• use JavaDoc style comments.
• remove variables that are only used in one place.
• use try with resources to save the close statement.
• choose better variable names. app would be clearer as shortDateFormat, format as extendedDateFormat, dateApp as logFileName, appendValue as appendToFile, logLevel as maximalLogLevel (should this maybe be minimal?), logType as logLevel.

There are probably more improvements, but with this your code already looks a bit nicer:

public class FunctionLogging {

    private String path;
    private boolean appendToFile = false;
    private int logLevel;
    private String[] messages = new String[] {"FATAL", "WARNING", "NOTICE", "DEBUG"};

    private SimpleDateFormat format = new SimpleDateFormat("dd-MM-yyyy|HH:mm:ss:SSSSSS|");
    private SimpleDateFormat app = new SimpleDateFormat("dd-MM-yyyy");

    /**
     *
     * @param filePath used as a placeholder variable for the output path. Can be hard-coded but is preferredly configurable from properties file
     * @param logLevel set as true when called in each class used in. true appends line to the end of the file, false overwrites file contents
     * @param append_value TODO
     */
    public FunctionLogging(String filePath, int logLevel, boolean appendValue) throws IOException {
        path = filePath;
        appendToFile = appendValue;

        loadConfig();
    }

    private void loadConfig() throws IOException {
        try (FileInputStream propFile = new FileInputStream("config.ini")) {
            Properties config = new Properties(System.getProperties());
            config.load(propFile);
            logLevel = Integer.parseInt(config.getProperty("loggingLevel"));
        }
    }

    public void writeToFile(int logType, String textLine) throws IOException {
        if (logType <= logLevel) {
            Date date = new Date();
            String timeStamp = format.format(date);
            String dateApp = app.format(date);

            FileWriter logWriter = new FileWriter(path + dateApp + ".log", appendToFile);
            try (PrintWriter loggerLines = new PrintWriter(logWriter)) {
                loggerLines.println(timeStamp + "1|" + messages[logType] + "|" + textLine);
            }
        }
    }
}

Or with enums:

public class FunctionLogging {

    public enum Level {

        FATAL("FATAL", 1),
        WARNING("WARNING", 2),
        NOTICE("NOTICE", 3),
        DEBUG("DEBUG", 4);

        private final String message;
        private final int level;

        private Level(String message, int level) {
            this.message = message;
            this.level = level;
        }

        @Override
        public String toString() {
            return message;
        }

        public int getLevel() {
            return level;
        }
    }

    // [...]

    public void writeToFile(Level level, String textLine) throws IOException {
        if (level.getLevel() <= logLevel) {
            // [...]
            try (PrintWriter loggerLines = new PrintWriter(logWriter)) {
                loggerLines.println(timeStamp + "1|" + level.toString() + "|" + textLine);
            }
        }
    }

    // [...]

// usage:

writeToFile(FunctionLogging.Level.DEBUG, "something happened");

Answer 2

Other answers have given great feedback. Use them. @tim's answer is particularly comprehensive.

I am going to suggest a different way, though, and it is because you expressly indicated that performance was a concern.

There are three factors that are performance related that you should consider.

1. debug logging overhead
2. IO overhead
3. logging latency

debug overhead

How often do you run your program in debug mode? And, if it is not often, what is the cost of preparing debug messages, and not using them?

If you have code like this in your application:

writeToFile(3, "Saving record " + id + " to destination " + file.toString());

Then, even if you are not debugging the application, you are still building a String containing the message, and doing a toString on the file.

A simpler way to solve this problem, is to treat the message as a format string, and add optional parameters to your method:

public void writeToFile(int level, String format, Object...values) {
    if (level <= logLevel) {
        // yes, we need to log this....
        String message = String.format(format, values);

        ... do something with the message.

    }
}

Now you can call your logging like:

writeToFile(3, "Saving record %d to destination %s", id, file);

Note, doing things this way means that a lot of the hard work is only done if the message is actually going to be printed.

IO operations

@Tim indicates that re-reading your config file each time is slow. He's right. Reopening your log file each time is also a problem. A better way to do it would be to open the log file just once, and then to flush it after each write to it. That way, if your application dies, it has already flushed all of it's logs.

Low-Latency

The process of actually printing and writing out to file is really slow, especially in code that is otherwise performance sensitive. A good solution to this is to use multi-threaded logging....

Have one thread that listens for events on a queue, and your application just dumps stuff on the queue when a log is required. The cost of dumping an event is much less than the cost of actually writing and flushing the IO. An ArrayBlockingQueue is a good option.

You have a thread that simply does:

private static final class LogEvent {
    private final long time;
    private final Level level;
    private final String format;
    private final Object[] values;

    ......

}

private final BlockingQueue<LogEvent> tolog = new ArrayBlockingQueue<>(100);

Now, your write event becomes:

public void writeLogEvent(Level level, String format, Object...values) {
    if (level > logLevel) {
        return;
    }
    tolog.put(new LogEvent(System.currentTimeMillis(), level, format, values));
}

And, on the logging side, you don't need to worry about log file conflicts, etc... you simply:

while(true) {
    LogEvent event = tolog.take();
    writer........
}

Now, the bulk of the hard logging work is not even on the threads that are doing the real work. You also have a multi-threaded environment and thread-safe logging. If logging starts backing up, you throttle the application at 100 events in the queue. Basically, you have a better solution.

Answer 3

//This section is devoted to creating a timestamp of the instance when the output string is created.
Date date = new Date();
SimpleDateFormat format = new SimpleDateFormat();
format = new SimpleDateFormat("dd-MM-yyyy|HH:mm:ss:SSSSSS|");
String timeStamp = format.format(date);
SimpleDateFormat app = new SimpleDateFormat();
app = new SimpleDateFormat("dd-MM-yyyy");
String dateApp = app.format(date);
int id = 0;

Whenever you feel the need to comment on a block of code and say "that chunk does this", you're saying "my method is doing too many things".

Extract that part into its own function, and give it a meaningful name - the need for the comment should disappear :)

---

The log levels don't feel instinctive:

messages[0]="FATAL";
messages[1]="WARN";
messages[2]="NOTICE";
messages[3]="DEBUG";

It looks like the lowest level has the highest index - I would revert them. Also, NOTICE would be INFO, and logging frameworks I've used also have a TRACE level below DEBUG.

logType looks like it should be an enum, not an int.

Answer 4

In addition to all the valuable point so far: You specifically asked about robustness. There is one thing that you did not seem to consider:

Concurrency!

_{(rolfl mentioned it indirectly in his answer while I was writing this answer. I thought about omitting my answer, but ... this just fit perfectly :) )}

When multiple threads are accessing the same logger instance concurrently, you may end up with garbage in your log file.

Of course, you could simply make your writeToFile method synchronized, but this is a large hammer for a tiny nail. Solving this properly is not so trivial. The java.util.logging loggers internally use lock objects and some synchronized methods, e.g. in the StreamHandler#publish(Record) method to alleviate this problem (note that here the synchronization only takes place in a handler, which is not necessarily called for each and every log call, and only in the implementations that actually need the synchronization).

Answer 5

This bit of code could be shrunk down to size

        SimpleDateFormat format = new SimpleDateFormat();
        format = new SimpleDateFormat("dd-MM-yyyy|HH:mm:ss:SSSSSS|");

like this

SimpleDateFormat format = new SimpleDateFormat("dd-MM-yyyy|HH:mm:ss:SSSSSS|");

There really isn't the need to create a new SimpleDateFormat and then wipe it out to replace it with another new SimpleDateFormat

Same thing here

        SimpleDateFormat app = new SimpleDateFormat();
        app = new SimpleDateFormat("dd-MM-yyyy");

To this:

SimpleDateFormat app = new SimpleDateFormat("dd-MM-yyyy");

---

This can also be shortened up

    String tempLev = config.getProperty("loggingLevel");
    int logLevel = Integer.parseInt(tempLev);
    if(logType<=logLevel)
    {

to this

if(logType<=Integer.parseInt(config.getProperty("loggingLevel")))
{
    //...       

If you were going to use those variables elsewhere in the code then it would be a good idea to create them, but you are just wasting the memory here because you don't use the variables anywhere else.

---

We just removed memory allocation for 2 variables, and we also reduced allocating 4 SimpleDateFormat's down to 2 that should increase the efficiency a little bit.