Use a Logger

Rule #3 happens to have two parts. Let's take a look at them.

Rule #3a:

Use a Logger to output data in your programs.

Do not use System.out.println(...), unless necessary. You might say, "this is madness, Umer?!". I say "Madness? This is Starscriber". No in all honesty, I have nothing against the plain old Java output mechanisms, but at Starscriber, we are in the business of writing server applications which run in the background as a service, also called daemon, hence we don't always see the output on our dark consoles. Loggers allow us to control where we want to send the output at run-time, and the possible destinations could be:

1. Screen
2. File (re: the infamous Logfiles)
3. Database
4. or even to Email

In addition to this, we can tell Loggers to automatically archive or split the files based on some criteria. For example, the SMG Server starts a new log file each day, appending the date in its name. To have this, I made changes to the logback.xml which is the main configuration file, without writing a single line of code in the SMG Server.

We'll use Logback (SLF4j) for our projects. In my opinion, it is better than Log4j.

Rule #3b:

When printing variables using Logger, do not use String concatenation to construct the output string. Use the curly braces notation {} to pass arguments to the function.

Ah, this is hard to explain, let us look at examples:

logger.debug("There are now " + count + " user accounts: " + userAccountList); // bad style, slower

The example above is a complete no-no and I don't want to see such statements in your code. If I do, I will make sure that you wake up in the Cube.

We can fix the above line of code by using the curly braces:

logger.debug("There are now {} user accounts: {}", count, userAccountList);    // faster

The reason is that String concatenation is not cheap. Consider the Java statement above. Suppose we are operating in the INFO level, as a result, the call to Logger.debug() is suppressed. However, leaving the above expression as it is will be costly in terms of performance as the JVM, when it encounters this statement, will still execute this statement. It will first prepare the argument by concatenating the String with int and so on, pass it to the Logger.debug(), only finding out that the debug() function has simply ignored the request altogether.

The syntax in the last example works for only up to three variables. If you want to print a more than three variables, you must use the following syntax:

logger.debug("{}, {}, {}, {}, {}", new Object[]{"val1", "val2", "val3", "val4", "val5"}

In the above statement, there is no costly String concatenation. Everything is passed straight to the Logger.debug() function, which if disable, will simply discard the request and the only cost we might occur is the setting up of Stack and parameters. (Although I don't know the details of Logback code, but if the function and value which identifies the level logger is operating are final, HotSpot could inline the function reducing the cost even further. Ah, getting ahead of myself again).

Using Logback

There are two ways to initialize Logback based loggers.

Static Loggers:

For example:

private static final Logger logger;
static
{
    logger = LoggerFactory.getLogger(EnclosingClassName.class);
}

Non-static Loggers:

For example:

private final Logger logger;
logger = LoggerFactory.getLogger(this.getClass().getSimpleName());

You can use any style you prefer.

Rules for using TRACE, DEBUG and ERRORS

SLF4J has following levels, in order of strictness: (ERROR, WARN, INFO, DEBUG, TRACE) In production setting, all loggers will operate in the INFO Level: TRACE and DEBUG logs will not be printed. This is to done to keep the size of log files manageable.

During development, use TRACE liberally in your code every where you like to print out any useful information. Use DEBUG to print out potentially useful DEBUG information for yourself and other stakeholders such as QA, IT, etc. Use INFO, WARN and ERROR to print out the information that you would want to be in the log files for effective troubleshooting.

So don't use System.out.println(...) at all?

I wish this was true, but it ain't. You will have to resort to using println in the following cases:

1. When the program is loading before logback is initialized
2. When the program is terminating due to an error condition, it is a good idea to output to the standard output as well.