Wednesday, November 20, 2013

Java Logging - The true life saver

How you tackle a defect in your code, specially a server side code? Are you remotely debugging the code at first step? Yes it is convenient to do so and most of the time it save you from the defect. The real question is, can it save you from defects all the time? Imagine you have written a code which is highly dependable on external factors such as data base connection, server level configurations and fortunately all goes well in development environment as well as QA environment. Assume you suddenly got a complaint from the customers that your functionality is not working on production as they expected. How you tackle where it went wrong, are you still willing to perform a remote debug procedure on the production where we need to maintain high availability? Who’s gone to save you now? Don’t worry logger is here. Most of the time it save us from incidents (not all incidents are bugs)

My ABC of defect tackling on a server side code.
  • Try to find any unexpected event on server log at the time the issue was raised.
  • Identify the last known good server log and compare rest with code.
  • If neither of above is able to solve the incident, remotely debug the application.

So it is very important to maintain a good server log. My opinion is we should be able to tackle any issue without remotely debug the code.

Impact on application performance by java logging.

Logging has big influence on application performance since logger has to perform IO operations, string concatenations each time we ask logger to log a message so most of the developers avoid them but it is not advisable to avoid all of them. What we can do is to identify what are needed to be log and what are not. Keep in mind both less and excess logging is not preferable.

Determine the correct type of before log.

I’m using log4j as my logging provider but SL4j is grooming as the standard logging API. In log4j there are four types. It is really important to place log statement on correct category.

DEBUG : The lowest restricted logging type , ideally we should include all the information we need to debug the application but keep in mind DO NOT enable this level on production because it heavily impact on application performance.
Examples :
INFO : More restrictive than DEBUG and only for use to log informative events happens during the execution.
Examples :
WARN : More restricted than INFO and used to log warning and alerts.
Examples : ERROR : Most restricted and used to log exceptions. We need to take those logs as more serious and we must log more details to find out what is wrong.
Examples :
Important facts you should consider while logging.
  • Minimize string concatenations whenever you can.

    String concatenation is a costly operation we should minimize concatenations, even we are using INFO as our debug level so logger is never log anything mark as DEBUG but in JVM it is executed . As I mentioned above DEBUG should contain all the details we should use to tackle the issue so most probably there will be many string concatenations.
    Example : Solution 1 : Check debug level when there are too many string concatenations . Solution 2 : Use parametrized logger framework such as SL4J.

  • Minimize possibility of throwing exception while logging.

    Example :
    There are two possibility of getting NPE in above log statement. I’ve seen scenarios where actual exceptions are hidden by the exceptions thrown by the logger statements so try to avoid them because loggers are here to help us not to worst the situation.

    • Make sure logger is not null before log. Sometimes we are accidently using inherited logger instance which may not be initialized.
    • Make sure “person” object never be null in above statement.

  • Use descriptive log statement.

    Is there any use of follow log statement?

  • Never log sensitive data such as passwords, credit card numbers.
  • Avoid spelling mistakes and try to be grammatically correct all the time.

Thursday, November 7, 2013

Prevention is better than cure (Preventing NPE without null check)

As I mentioned on my previous blog post, NPE (Null Pointer Exception) is the most common exception in java. But if you are having enough attention on to your code, you can easily avoid most of the possibilities of getting NPE. The easiest cure, probably the most common cure for NPE is checking null values whenever there is a doubt. Check follows extreme case.

This works fine, but is this cute? Unarguably this is not the best way to prevent NPE. Think twice, why we do not trust the values return by the bean accessors? If we trust them our code will be like this.

How we can achieve this?
It is not that much hard to archive this. Most of the developers think the sole usage of mutator method is to change the value of the variable. But it is not, check follow bean.

Now we can guarantee, no accessor method will return a null value. Still we are getting an exception (IllegalArgumentException) but keep in mind it is good to getting exception early as possible and here we know the exact reason for getting the exception.

Monday, November 4, 2013

Can you spot a NPE (Null Pointer Exception)?

What is the most common exception that java developer are experiencing? The straight forward answer is NPE. Here I’m not going to discuss all the possibilities of NPE but one freak possibility of getting NPE, you may miss while debugging the code.

Did you spot the NPE possibility ?

This code seems to be fine, there are null checks, no chance of getting NPE at for each loop ( it throws NPE if the list is null ). So where is the NPE possible loophole? Value of get(0) may be null. List is not like other collections, it can contain null values. So two things to remember.
  1. Do a null check before call trim method whenever there is a chance of getting null values as a String.
  2. List is a sequence of objects so there is no limitation of having null as an element of the list, Set also can contain at most one null element. So beware of such hidden null values.