Friday, February 3, 2017

Log4j Logging

Why logging is important in any application?

Logging is very important to any application. It helps us collect information about how the application is running and also helps us debug if any failure occurs.

What is Log4j?

Log4j is a brilliant logging API available both on Java and .net framework.

Advantages are:
– Log4j allows you to have a very good logging infrastructure without putting in any efforts.
– Log4j gives you the ability to categorize logs at different levels (Trace, Debug, Info, Warn, Error and Fatal).
– Log4j gives you the ability to direct logs to different outputs. For e.g. to a file, Console or a Database.
– Log4j gives you the ability to define the format of output logs.
– Log4j gives you the ability to write Asynchronous logs which helps to increase the performance of the application.
– Loggers in Log4j follow a class hierarchy which may come handy to your applications.

If you are not able to understand any of these points than don’t worry. Things will get clearer as we approach to the end of Log4j Tutorial series.
Downloading Log4j Jar:

Steps to follow:

1)      Go to Apache Logging Services and click Apache log4j.














2)      Click on “Download” on the left side menu.



3)      You will always get the latest version here. Click on the ZIP file under Mirrors column.



4)      Click on the highlighted link at the top of the page.

         


5)      Select the radio button for “Save File” and click OK. Zip file will be saved on your system with in few seconds.

6)      Right click on the Zip file and select “Extract All“.



7)      Specify the location.

             

8)      Wait for the Extraction to finish.


9)      Open the Log4j extracted folder from the saved location.



 You are done with downloading the Log4j JAR file, now all you need to do is to add this JAR file to your project and write your first Log4j logging enabled test script.

Adding Log4j Jar to Project Library:

1)      Right click the project name and navigate to Build Path and select “Configure Build Path“.




2)      Click on Add External JARS and navigate to the folder where you have kept the Log4j jar files.



3)      Select the Executable Jar File and click Open.


Log4j

Log4j consists of four main components
– LogManager
– Loggers
– Appenders
– Layouts

LogManager:


This is the static class that helps us get loggers with different names and hierarchy. You can consider LogManager as a factory producing logger objects.
A sample code will be:

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {

         //mainLogger is a logger object that we got from LogManager. All loggers are
        //using this method only. We can consider LogManager as a factory to create
        //Logger objects
static Logger mainLogger = LogManager.getLogger(SampleTest.class.getName());

            public static void main(String[] args) {
                        // TODO Auto-generated method stub
                        BasicConfigurator.configure();
                        mainLogger.info("This is just a logger");       

            }
}

LogManager, as the name suggests, is the Manager of all logger objects. This is the static class that you refer to for creating Logger objects. LogManager also keeps a list of all the loggers being created by the application. If I were to summarize, LogManager does following work

– Create instances of Logger objects.
– Store references of all the created logger objects.
– Allow reuse of same logger object in different parts of the code.

Lets look at this example code. This shows how we can create different logger instances out of a LogManager.

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {

            public static void main(String[] args) {

                //This is how we create a logger object
                        Logger logger1 = LogManager.getLogger("Logger1");
                        Logger logger2 = LogManager.getLogger("Logger2");
                        Logger logger3 = LogManager.getLogger("Logger3");
                        BasicConfigurator.configure();
                        logger1.info("This is logger 1");
                        logger2.info("This is logger 2");
                        logger3.info("This is logger 3");                    
            }
}

We can also retrieve all the logger objects inside LogManager at a particular instance by using the getCurrentLoggers() method. Here is the code sample

package Log4jSampleTest;
import java.util.Enumeration;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {
            public static void main(String[] args) {
                        // TODO Auto-generated method stub

                        Logger logger1 = LogManager.getLogger("Logger1");
                        Logger logger2 = LogManager.getLogger("Logger2");
                        Logger logger3 = LogManager.getLogger("Logger3");
                        BasicConfigurator.configure();
                        logger1.info("This is logger 1");
                        logger2.info("This is logger 2");
                        logger3.info("This is logger 3");        

                        Enumeration loggers = LogManager.getCurrentLoggers();
                        while(loggers.hasMoreElements())
                        {
                                    logger3.info("Logger name is " + loggers.nextElement().getName());                                
                        }
            }
}

One very important property of LogManager it lets us retrieve an existing logger object by name. Also, if we try to create a logger object with the same name as an existing logger object, it will pass on the reference of the existing logger object instead of creating one. This can be shown in the code below

package Log4jSampleTest;
import java.util.Enumeration;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {

            public static void main(String[] args) {
                        // TODO Auto-generated method stub
                        Logger logger1 = LogManager.getLogger("Logger1");
                        Logger logger2 = LogManager.getLogger("Logger2");
                        Logger logger3 = LogManager.getLogger("Logger3");
                        BasicConfigurator.configure();
                        logger1.info("This is logger 1");
                        logger2.info("This is logger 2");
                        logger3.info("This is logger 3");        

                        Logger logger1_2 = LogManager.getLogger("Logger1");
                        Logger logger1_3 = LogManager.getLogger("Logger1");
                        //You will see that LogManager doesn’t create a new instance of logger
                        //Object with name Logger1, instead passes on the reference to the
                        //existing Logger1 object. We can confirm this with following lines
                        logger1_2.info("The name of this logger is " + logger1_2.getName());

        if(logger1_3.equals(logger1))
        {
            logger1_3.info("Both objects are same");
        }
        else
        {
            logger1_3.info("Logger1 and logger1_2 are different objects");
        }

            }
}

Loggers:
The next object in the Log4j component list is the Logger class. This is the most important class that you will need. This is the object which lets you log information to the required Log location, be it console or a file or even a database.
Logger objects follow hierarchy similar to class hierarchy in any OOP language. Naming convention of Logger hierarchy is in the name. Each objects name decide which hierarchy it follows. For example we have a logger named “Main.Utility“. So Utility is the child of Main and Main is the father of Utility. Also, all Loggers are derived from root Logger. The actual hierarchy will be root.Main.Utility with root being ancestor of Utility and Father of Main. This can be shown in a diagram as

These relationships are managed by the LogManager class. Lets illustrate it using an example.


package Log4jSampleTest;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {

            public static void main(String[] args) {
                        // TODO Auto-generated method stub         

      Logger chance = LogManager.getLogger(SampleTest.class.getName());          
      Logger logger1 = LogManager.getLogger("Child1");
      Logger logger1Child = logger1.getLogger("Child1.ChildOfLogger1");
      Logger loggerGrandChild = LogManager.getLogger("Child1.ChildOfLogger1.GrandChild");
      System.out.println("logger1's full name is " + logger1.getParent().getName());
      System.out.println("logger1Child's full name is " + logger1Child.getParent().getName());
      System.out.println("loggerGrandChild's full name is " + loggerGrandChild.getParent().getName());

            }
}

As you can see that logger1 is the parent of logger1Child and grandparent of loggerGrandChild’s. This is how we can create hierarchy of logger objects based on the application need.

Logging levels:

Logger class have following print methods that help you log information.
– Trace
– Debug
– Info
– Warn
– Error
– Fatal

So lets say you want to print a Debug log you would just do it by aying Logger.Debug(“This is a debug log”). You may choose to use any other overloaded Logger.Debug() method. All these print statements are called Levels.

Question comes, why do we need log levels?
TRACE < DEBUG < INFO < WARN < ERROR < FATAL.
Each log level expects a certain type of information for e.g Debug level expects logging of that information which may help a programmer debug the application in case of failures. Similarly Error Level expects all the Errors to be logged using this level.
You can set log level of a logger using the Logger.setLevel method. Once you set the Log level of your logger only loggers with that and higher level will be logged. Log levels have following order

Lets understand this with an example, in the code below we have set the level to DEBUG first and than WARN. You will see that only the logs which are at that or higher level will be logged. Here is the code sample.

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {

            public static void main(String[] args) {
                        // TODO Auto-generated method stub

     BasicConfigurator.configure();
     Logger Mylogger = LogManager.getLogger("DebugLogger");

     //Setting up the log level of both loggers
      Mylogger.setLevel(Level.DEBUG);

      Mylogger.trace("This is the trace log - DEBUG");
      Mylogger.debug("This is debug log - DEBUG");
      Mylogger.info("This is info log - DEBUG");
      Mylogger.warn("This is Warn log - DEBUG");
      Mylogger.error("This is error log - DEBUG");
      Mylogger.fatal("This is Fatal log - DEBUG");

      Mylogger.setLevel(Level.WARN);
      Mylogger.trace("This is the trace log - WARN");
      Mylogger.debug("This is debug log - WARN");
      Mylogger.info("This is info log - WARN");
      Mylogger.warn("This is Warn log - WARN");
      Mylogger.error("This is error log - WARN");
      Mylogger.fatal("This is Fatal log - WARN");     
            }
}        
          

Logging run time Exceptions:

This is a very important feature of a Logger class, it enables you to pass on the exception to the output. This comes handy specifically in the cases where we have intentionally caught the exception but we also want to log the information about the exception. Every print method (TRACE, DEBUG…. FATAL) have an overload which is Logger.Debug(Object message, Throwable t), off course we have just taken the example of .Debug only, this allows us to pass the exception. Lets see how its beneficial using a code sample

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {
                     public static void main(String[] args) {
                        // TODO Auto-generated method stub

BasicConfigurator.configure();
Logger LoggerParent = LogManager.getLogger("LoggerParent");
Try
                   {
                          // We will get a divide by zero exception her
                          int x = 200 / 0;
                          }
                          catch(Exception exp)
                          {
                            LoggerParent.warn("Following exception was raised", exp);        
                          }    
                     }
}


Appenders:
Appenders are objects which help Logger objects write logs to different outputs. Appenders can specify a file, console or a data base as the output location.
In this code sample you will see that we have used a console appender to print logs like we would do using System.out or System.err.

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

public class SampleTest {

            //All the loggers that can be used
            static Logger mainLogger = LogManager.getLogger(SampleTest.class.getName());

            public static void main(String[] args) {
                        // TODO Auto-generated method stub
                        BasicConfigurator.configure();
                        //Create a console appender and attach it to our mainLogger
                        ConsoleAppender appender = new ConsoleAppender();
                        mainLogger.addAppender(appender);
                        mainLogger.info("This is just a logger");       
            }
}

Appenders are the Log4j objects which deliver logs to the required destinations. For example a ConsoleAppender will deliver the logs to the console and a FileAppender to the log file. There are many types of Appenders that we have in Log4j, the ones that we will cover today are
– FileAppender 
– ConsoleAppender 
– JDBCAppender

File Appenders:

Almost all the time we want to log our data in a file instead of printing it on the console. This is for obvious reasons, we want a copy of the logs so that we can keep it for reference and browse through it to find problems. Whenever you need to log in a file you will use a FileAppender. This code sample explains you how to create a FileAppender object and than set it to the required logger.

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.FileAppender;
import org.apache.log4j.Layout;
import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.log4j.SimpleLayout;

public class SampleTest {

            public static void main(String[] args) {
                        // TODO Auto-generated method stub

                         BasicConfigurator.configure();
                 Logger OurLogger = LogManager.getLogger("OurLogger");

                 //create a FileAppender object and
                 //associate the file name to which you want the logs
                 //to be directed to.
                 //You will also have to set a layout also, here
                 //We have chosen a SimpleLayout
                 FileAppender fileAppender = new FileAppender();
                 fileAppender.setFile("logfile.txt");
                 fileAppender.setLayout(new SimpleLayout());

                 //Add the appender to our Logger Object.
                 //from now onwards all the logs will be directed
                 //to file mentioned by FileAppender
                 OurLogger.addAppender(fileAppender);
                 fileAppender.activateOptions();

                 //lets print some log 6 times
                 int x = 0;
                 while(x < 6){
                             OurLogger.debug("This is just a log that I want to print " + x);
                             x++;
                 }

            }
}

While creating an appender you have to add the LayOut that you would like to choose. In our case we have chosen SimpleLayout(). Also, when ever you make a change in Appender object for example adding a file path or adding the Layout you have to call .activateOptions(), activateOptions() will activate the options set previously. This is important because your changes to Appender object wont take place until .activateOptions(). You will find the log file in the project folder in your eclipse workspace. Also, this is how the logs look in the logfile:

DEBUG - This is just a log that I want to print 0
DEBUG - This is just a log that I want to print 1
DEBUG - This is just a log that I want to print 2
DEBUG - This is just a log that I want to print 3
DEBUG - This is just a log that I want to print 4
DEBUG - This is just a log that I want to print 5

Console Appenders:

For testing purpose you may want to redirect your output logs to the console. Actually ConsoleAppender directs the logs to System.err and System.out streams. These streams are also read by Console and hence the output is displayed at the console as well. Lets see with a code sample on how to use ConsoleAppender Object

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.FileAppender;
import org.apache.log4j.Layout;
import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.log4j.SimpleLayout;

public class SampleTest {

public static void main(String[] args) {
// TODO Auto-generated method stub                                                          BasicConfigurator.configure();
 Logger OurLogger = LogManager.getLogger("OurLogger");

 //create a ConsoleAppender object
  //You will also have to set a layout also, here
     //We have chosen a SimpleLayout
    ConsoleAppender ConsoleAppender = new ConsoleAppender();
     ConsoleAppender.setLayout(new SimpleLayout());
     //Add the appender to our Logger Object.
     //from now onwards all the logs will be directed
     //to file mentioned by FileAppender
     OurLogger.addAppender(ConsoleAppender);
     ConsoleAppender.activateOptions();
     //lets print some log 6 times
     int x = 0;
     while(x < 6){
 OurLogger.debug("This is just a log that I want to print " + x);
   x++;
     }
  }
}

JDBC Appender:

JDBCAppenders are used to write logs to a Data base. These appenders accept data base connection credentials to connect to DB. Lets see a code sample to understand how JDBCAppenders work.

package Log4jSampleTest;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.FileAppender;
import org.apache.log4j.Layout;
import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.log4j.SimpleLayout;
import org.apache.log4j.jdbc.JDBCAppender;

public class SampleTest {
public static void main(String[] args) {
// TODO Auto-generated method stub

 BasicConfigurator.configure();
 Logger OurLogger = LogManager.getLogger("OurLogger");

 //create a JDBCAppender class instance
 JDBCAppender dataBaseAppender = new JDBCAppender();

 //Provide connection details to the
 //Database appender
 dataBaseAppender.setURL("jdbc:mysql://localhost/test"); //Connection url
dataBaseAppender.setUser("User1"); //Username for the DB connection
dataBaseAppender.setPassword("ThisPassword"); //Password for the DB connection
dataBaseAppender.setDriver("com.mysql.jdbc.Driver");
 // Drivers to use to connect to DB

 //set the sql insert statement that you want to use
 dataBaseAppender.setSql("INSERT INTO LOGS VALUES ('%x', now() ,'%C','%p','%m'");  

  //activate the new options
 dataBaseAppender.activateOptions();
 //Attach the appender to the Logger
OurLogger.addAppender(dataBaseAppender);
    int x = 0;
   while(x < 11){
 OurLogger.debug("This is just a log that I want to print " + x);
   x++;
     }
  }
}

This code explains how to set up a JDBCAppender object and use it for logging. After see the code you will notice that we have to give the insert statement to the JDBCAppender. This statement is used to insert logs in the desired database table. We have used the statement INSERT INTO LOGS VALUES (‘%x’, now() ,’%C’,’%p’,’%m’) It says that logs are inserted in the table named LOGS. Dont worry about %x %C and other similar terms in the Insert Statement.

Layouts:
Layout class help us define how the log information should appear in the outputs. Here is a sample code which uses PatternLayout Class to change the formatting of logs:

package Log4jSampleTest;
import java.util.Enumeration;
import org.apache.log4j.Appender;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.Layout;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.apache.log4j.PatternLayout;

public class SampleTest {

            //All the loggers that can be used
            static Logger mainLogger = LogManager.getLogger(SampleTest.class.getName());

            public static void main(String[] args) {
                        // TODO Auto-generated method stub
                        BasicConfigurator.configure();
                        ConsoleAppender appender = new ConsoleAppender();
                        appender.activateOptions();
                        PatternLayout layoutHelper = new PatternLayout();
                        layoutHelper.setConversionPattern("%-5p [%t]: %m%n");
                        layoutHelper.activateOptions();
                          //mainLogger.getAppender("ConsoleAppender").setLayout(layoutHelper);          
                        appender.setLayout(layoutHelper);
                        mainLogger.addAppender(appender);
                        //Create a console appender and attach it to our mainLogger
                        mainLogger.info("Pattern 1 is displayed like this");
                        layoutHelper.setConversionPattern("%C %m%n");
                        mainLogger.info("Pattern 2 is displayed like this");

            }

}

Writing Test Case with Log4j logging

1)      Create a new XML file – log4j.xml and place it under the Project root folder and Paste the following code in the log4j.xml file.

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">
<appender name="fileAppender" class="org.apache.log4j.FileAppender">
<param name="Threshold" value="INFO" />
<param name="File" value="logfile.log"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d %-5p [%c{1}] %m %n" />
</layout>
</appender>
<root>
<level value="INFO"/>
<appender-ref ref="fileAppender"/>
</root>
</log4j:configuration>

Note: After pasting the code make sure that the code is exactly same, as copying from HTML may change some symbols(“) to (?). 2) Now include logging code in to your test script.

package automationFramework;
import java.util.concurrent.TimeUnit; 
import org.apache.log4j.Logger; 
import org.apache.log4j.xml.DOMConfigurator; 
import org.openqa.selenium.By;
import org.openqa.selenium.WebDriver;
import org.openqa.selenium.firefox.FirefoxDriver;

public class Log4j {

            private static WebDriver driver;
            private static Logger Log = Logger.getLogger(Log4j.class.getName());
            public static void main(String[] args) {
                        DOMConfigurator.configure("log4j.xml");

                        // Create a new instance of the Firefox driver
        driver = new FirefoxDriver();
        Log.info("New driver instantiated");

        //Put a Implicit wait, this means that any search for elements on the page could take the time the implicit wait is set for before throwing exception
        driver.manage().timeouts().implicitlyWait(10, TimeUnit.SECONDS);
        Log.info("Implicit wait applied on the driver for 10 seconds");

        //Launch the Online Store Website

        driver.get("http://shastadigitaltechnologies.blogspot.in/");
        Log.info("Web application launched");

        // Close the driver
        driver.quit();
        Log.info("Browser closed");

            }

}

2)      Check the output file “logfile.txt”. The output will look like below: