Cleaner debug level logging in Java?

Question

Is there a cleaner way for me to write debug level log statements? In some ways one could say that the string literals are basically commenting the code and providing logging in one line and that it is already very clean. But after I add debug level log statements, I find the code much less easier to read up and down. Take this example (I may update to a real example if I get back to my home PC):

int i = 0;
logger.debug("Setting i to 0,"); //Just an example, would show something more complex
i++;

InputStream is = socket.getInputStream();
DataOutputStream dos = new DataOutputStream(socket.getOutputStream());

IOUtils.write(request, dos);
logger.debug("request written to output");

while (!is.read(buffer))
    logger.debug("Reading into buffer");

logger.debug("Data read completely from socket");

CustomObject.doStuff(buffer);
logger.debug("Stuff has been done to buffer");

Answer 1

If you want very fine grained debug instructions I am not sure you can separate the actual code from the debug code.

If you want it at a higher level, maybe adding your logging using AOP could help make things easier to read, maybe use a proxy object?

But if you have debug instructions as fine grained as in the example you provided, IMHO you could gain more by replacing the loggers with unit tests. Don't write in a log that something happened, test that it did.

Answer 2

You could try using aspects, although these have the limitation that you can only put log statements "around" method calls, i.e. before entering and/or after leaving a specific method.

For more detailed logging, I am afraid there is no other way than hand-coded log messages.

I typically strive to remove the not-so-much-needed debug log statements from the code once I made sure that it works the way it should (for which unit tests are a must).

Answer 3

Ask yourself if I run this in a different machine/country/planet, and things go wrong and all I have is only a log file what information do I need to know what has gone wrong ?

Use debug logs in a for loop, or a while loop sparingly. For example, if you are reading 1000 records from a file, performing an op for each record. You could record before the for loop that "file exists and is readable and is going to read 1000 records" and print status after the process is done. If it is say 1000000 records then you could print something every say 100 or 1000 iterations

In your code except for the logger for setting i to 0 everything else sorta makes sense to me. Also care to use log.isDebugEnabled() if your string in the logger statmeent is hard to compute..

ex:

if(log.isDebugEnabled) {
   logger.debug("Here " + obj.aMethodCallThatTakes5MinsToEvaluateToString());
}

UPDATE 1: SLF4J solves only half the problem.

if(slfLog.isDebugEnabled) {
   slfLog.debug(obj.getObjectThatTakes5Mins());
}

Yes the toString is prevented but if you are logging an actual object which is result of some computation you are not prevented.

Answer 4

You will not be able to do much if you dislike the log statements. The information needs to be there somehow.

What you CAN do, is strongly considering what NEEDS to be there. You are basically writing for the log file reader who per definition does not know about how your program works, so the information needs to be concise and correct. Personally I very frequently add the method name to the log statement.

Also note that slf4j allows you to use the {}-syntax which helps somewhat

 log.debug("main() date={}, args={}", new java.util.Date(), args);

Also note that having unit tests, allow you to move much stuff to there simply because you know that THAT works.

Answer 5

Why not simply debug the program with a debugger if things goes wrong? Why do you need to persistently put those log messages there?