Working with Log4j logging…

Sometimes when we run our test cases it is very important to share some information about our test, for example if the test is failed or passed, any specific message or information to user regarding any exceptions or errors etc. This not only provides additional information to the tester or user but also helps in debugging if the test case fails during execution.

The easiest way of logging information is to use ‘System.out.println‘, which prints information into the console. But this has many disadvantages. One of them is that the printed information is not saved anywhere, as a result it’s lost after every execution. Another main disadvantage of using ‘System.out.println‘ is that it has impact to the performance of our code. However we can overcome all these problems by using a Logging tool.

There are many logging tools or APIs available in market. Some of them are: Log4j, SLF4J, Logback etc.. However we will be concentrating on Log4j as it is very simple and easy to learn.

Log4j has built-in log levels that allow users to log information into variety of destinations like a database, file, console etc.. The log level can be configured in a XML or Properties file. Different log levels in decreasing order of severity:

  • OFF – The highest possible rank and is intended to turn off logging.
  • FATAL – Severe errors that cause premature termination.
  • ERROR – Other runtime errors or unexpected conditions.
  • WARN – Use of deprecated APIs, poor use of API, ‘almost’ errors, other runtime situations that are undesirable or unexpected.
  • INFO – Interesting runtime events (startup/shutdown).
  • DEBUG – Detailed information on the flow through the system.
  • TRACE – Most detailed information.

Here we will be using ‘NewTourPageFactory‘ project from our last post Working with Page Factory….

  1. First step is to download the Log4j jars. Go to Google and type in ‘Log4j Jar download’. Click on the first link and we will be taken to ‘logging.apache.org’ website. Click below link to navigate directly to the download page. Log4j Download.
  2. Click ‘log4j-1.2.17.tar.gz’ as displayed below to navigate to download page.

    Log4j Download
  3. Click the below link to start the download. Once clicked, ‘log4j-1.2.17.tar’ will be downloaded in ‘Downloads’ folder of your local machine.

    Click to download Jar
  4. Unzip ‘log4j-1.2.17.tar’ file to view the Log4j jar. We have to add this jar into our Java Project.

    Log4j jar
  5. To add Log4j jar into our project, right click on the project name and click Properties. Click on Java Build Path -> Add External Jars. Go to the local folder where ‘log4j-1.2.17’ is saved. Add the Jar and click OK to close the window. Once complete, we will see ‘log4j-1.2.17’ jar inside ‘Referenced Libraries’.

    Add Log4j jar
  6. Next steps is to add the Configuration file. Configuration file not only allow us to set the destination output where we want to print the log information but also help us in setting up the log levels. We can configure Log4j using both Property file as well as XML file. Here we will be focusing on XML file. Right click on ‘src‘ folder and click New -> Other. Select XML file as displayed below. Click Next and name the file as ‘log4j.xml’.

    Select XML file and click Next
  7. Copy and paste below code into ‘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/'>
    	<!-- Appender for printing in console -->
    	<appender name="console" class="org.apache.log4j.ConsoleAppender">
    		<layout class="org.apache.log4j.PatternLayout">
    		    <!-- %d{yyyy-MM-dd HH:mm:ss} refers to Date format 2017-03-23 15:54:44 INFO  Log:15 -->
    		    <!-- %-5p refers to Type of logging INFO-->
    		    <!-- %c{1}  -->
    			<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n" />
    		</layout>
    	</appender>
    	<!-- Appender for printing in file -->
    	<appender name="file" class="org.apache.log4j.RollingFileAppender">
    		<!-- Appending false -->
    		<param name="append" value="false" />
    		<!-- Maximum 10kb size. New file will be created and old file renamed -->
    		<param name="maxFileSize" value="10KB" />
    		<!-- Maximum 5 log files. Old ones will be deleted -->
    		<param name="maxBackupIndex" value="5" />
    		<!-- Location of log file -->
    		<param name="file" value="test-output/log/${logfoldername}/${logfilename}.log" />
    		<layout class="org.apache.log4j.PatternLayout">
    			<param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n" />
    		</layout>
    	</appender>
    
    
    	<root>
    	<!-- Setting Logging level  -->
    		<level value="info" />
    		<!-- Setting logging level for console -->
    		<appender-ref ref="console" />
    		<!-- Setting logging level for file -->
    		<appender-ref ref="file" />
    	</root>
    </log4j:configuration>
    
  8. In the above XML code, the appenders are defined first. We can have as many appenders based on different log destinations. In our case, we are naming them as ‘console’ and ‘file’ for printing logs to both console and file. Notice the class names used in both appenders. Inside appenders, a layout is defined, in our case ‘org.apache.log4j.PatternLayout’ class is used. This layout formats the logging event and return the result as String. The output depends on the conversion pattern. A conversion pattern is composed of literal text and format control expressions called conversion specifiers, which starts with a percent sign (%) and is followed by optional format modifiers and a conversion character. The log messages in our case will be printed in below format.

    Notice the information displayed before log messages
  9. Notice that for file appender, we are setting configurable parameters like setting the file size, number of files, location for saving the file etc.. For setting the log file name with current date, we will be using system properties (‘logfoldername‘ and ‘logfilename‘) set in our TestNG script.
  10. Next comes the root logger. The root logger mentioned in above XML code logs messages with level INFO or above to both destinations, console and file.
  11. Next step is to create a Log class with log methods. We will use these log methods in all our project class. Right click on ‘src‘ folder and click New ->  Package. Name the package as ‘com.selenium.util’ and click Finish to close the window. This is where we will place our Log class.
  12. Right click on ‘com.selenium.util’ package and click New -> Class. Name the class as ‘Log’. Copy and paste the below code into our Log.class file. Notice that we are creating a logger object using which we will be printing different log messages.
    package com.selenium.util;
    
    import org.apache.log4j.Logger;
    
    public class Log {
    
    	// Initialize Log4j logs
    	private static Logger Log = Logger.getLogger(Log.class.getName());//
    
    	// This is to print log for the beginning of the test case
    	public static void startTestCase(String sTestCaseName) {
    
    		Log.info("****************************************************************************************");
    
    		Log.info("$$$$$$$$$$$$$$$$$$$$$                 " + sTestCaseName + "       $$$$$$$$$$$$$$$$$$$$$$$$$");
    
    		Log.info("****************************************************************************************");
    	}
    
    	// This is to print log for the end of the test case
    	public static void endTestCase(String sTestCaseName) {
    
    		Log.info("XXXXXXXXXXXXXXXXXXXXXXX             " + "-E---N---D-" + "             XXXXXXXXXXXXXXXXXXXXXX");
    	}
    
    	// info method for printing info message
    	public static void info(String message) {
    
    		Log.info(message);
    	}
    
    	// warn method for printing warning message
    	public static void warn(String message) {
    
    		Log.warn(message);
    	}
    
    	// error method for printing error message
    	public static void error(String message) {
    
    		Log.error(message);
    	}
    
    	// fatal method for printing fatal message
    	public static void fatal(String message) {
    
    		Log.fatal(message);
    	}
    
    	// debug method for printing debug message
    	public static void debug(String message) {
    
    		Log.debug(message);
    	}
    }
    
  13. Next step is to update our Page Object and TestNG class with different log information. We will start with ‘HomePage’ class. Copy and paste below code to HomePage.java file. Notice that we have used ‘log.info’ methods to print log messages in console and file. Since we have set ‘level value=info‘ in ‘log4j.xml’ file, messages with priority equal or greater than ‘info‘ such as ‘warn‘, ‘error‘, ‘fatal‘ etc. will be printed. Other log level will not be printed.
    package com.selenium.pages;
    
    import org.openqa.selenium.WebDriver;
    import org.openqa.selenium.WebElement;
    import org.openqa.selenium.support.FindBy;
    import com.selenium.util.Log;
    
    public class HomePage {
    	//Declare WebDriver
    	WebDriver driver;
    	//Element Locators for username textbox
    	@FindBy(name = "userName")
    	private WebElement userName;
    	
    	//Element Locators for password textbox
    	@FindBy(name = "password")
    	private WebElement password;
    	
    	//Element Locators for login button
    	@FindBy(name = "login")
    	private WebElement login;
    	
    	//Constructor. Driver Initialization
    	public HomePage(WebDriver driver) {
    		this.driver = driver;
    	}
    
    	// Login method. Notice there is no return type
    	public void loginUser(String uname, String pwd) {
    		// Enter username
    		userName.sendKeys(uname);
    		Log.info("HomePage.loginUser - username entered");
    		// Enter password
    		password.sendKeys(pwd);
    		Log.info("HomePage.loginUser - password entered");
    		// Click Login button
    		login.click();
    		Log.info("HomePage.loginUser - login button clicked");
    	}
    }
    
  14. Update the ‘FlightFinderPage.java’ file with below code. Notice that we have used ‘log.info’ methods to print log messages in console and file.
    package com.selenium.pages;
    
    import org.openqa.selenium.WebDriver;
    import org.openqa.selenium.WebElement;
    import org.openqa.selenium.support.FindBy;
    import org.openqa.selenium.support.ui.Select;
    import com.selenium.util.Log;
    
    public class FlightFinderPage {
    
    	//Declare WebDriver
    	WebDriver driver;
    	//Element Locators for one way radio button
    	@FindBy(xpath = "//input[@value='oneway']")
    	private WebElement onewayRadio;
    	
    	//Select the location from dropdown
    	@FindBy(name = "fromPort")
    	private WebElement fromPortDrop;
    	
    	//Select the day from dropdown
    	@FindBy(name = "fromDay")
    	private WebElement fromDayDrop;
    	
    	//Click Business radio button
    	@FindBy(xpath = "//input[@value='Business']")
    	private WebElement businessRadio;
    	
    	//Click find flights button
    	@FindBy(name = "findFlights")
    	private WebElement findFlightsButton;
    	
    	//Constructor. Driver Initialization
    	public FlightFinderPage(WebDriver driver) {
    		this.driver = driver;
    	}
    
    	//Find Flights method. Notice there is no return type
    	public void findFlights(String departFrom, String departDate) {
    		// Click one way radio button
    		onewayRadio.click();
    		Log.info("FlightFinderPage.findFlights - One way Radio Button clicked");
    		// Select Departing From dropdown
    		Select dropFrom = new Select(fromPortDrop);
    		dropFrom.selectByValue(departFrom);
    		Log.info("FlightFinderPage.findFlights - Depart From Dropdown clicked");
    
    		// Select Departing Day dropdown
    		Select dropDay = new Select(fromDayDrop);
    		dropDay.selectByValue(departDate);
    		Log.info("FlightFinderPage.findFlights - Depart Date Dropdown clicked");
    
    		// Click business class
    		businessRadio.click();
    		Log.info("FlightFinderPage.findFlights - Business Radio Button clicked");
    
    		// Click Find Flights button
    		findFlightsButton.click();
    		Log.info("FlightFinderPage.findFlights - Find Flights Button clicked");
    	}
    
    }
    
  15. Update ‘SelectFlightPage.java’ file with below code.
    package com.selenium.pages;
    
    import org.openqa.selenium.WebDriver;
    import org.openqa.selenium.WebElement;
    import org.openqa.selenium.support.FindBy;
    import org.openqa.selenium.support.How;
    import com.selenium.util.Log;
    
    public class SelectFlightPage {
    
    	//Declare WebDriver
    	WebDriver driver;
    	//Element Locators for reserve flight button
    	//@FindBy(name = "reserveFlights")
    	@FindBy(how = How.NAME, using = "reserveFlights")
    	private WebElement reserveFlightsButton;
    
    	//Constructor. Driver Initialization
    	public SelectFlightPage(WebDriver driver) {
    		this.driver = driver;
    	}
    
    	// Reserve Flight method. Notice there is no return type
    	public void reserveFlight() {
    		// Click reserve Flights button
    		reserveFlightsButton.click();
    		Log.info("SelectFlightPage.reserveFlight - Reserve Flight button clicked");
    	}
    }
    
  16. Update ‘BookFlightPage.java’ file with below code. Notice that for better understanding we are including class.method name information in our log messages.
    package com.selenium.pages;
    
    import org.openqa.selenium.WebDriver;
    import org.openqa.selenium.WebElement;
    import org.openqa.selenium.support.FindBy;
    import com.selenium.util.Log;
    
    public class BookFlightPage {
    
    	//Declare WebDriver
    	WebDriver driver;
    	//Element Locators for first name textbox
    	@FindBy(name = "passFirst0")
    	private WebElement firstNameTextBox;
    	
    	//Element Locators for last name textbox
    	@FindBy(name = "passLast0")
    	private WebElement lastNameTextBox;
    	
    	//Element Locators for credit number textbox
    	@FindBy(name = "creditnumber")
    	private WebElement ccNumberTextBox;
    	
    	//Element Locators for Buy Flights button
    	@FindBy(name = "buyFlights")
    	private WebElement buyFlightsButton;
    
    	//Constructor. Driver Initialization
    	public BookFlightPage(WebDriver driver) {
    		this.driver = driver;
    	}
    
    	//Book Flight method.Notice there is no return type
    	public void bookFlight(String fname, String lname, String ccNumber) {
    		// Enter first name
    		firstNameTextBox.sendKeys(fname);
    		Log.info("BookFlightPage.bookFlight - First Name entered");
    		// Enter last name
    		lastNameTextBox.sendKeys(lname);
    		Log.info("BookFlightPage.bookFlight - Last Name entered");
    		// Enter credit card number
    		ccNumberTextBox.sendKeys(ccNumber);
    		      Log.info("BookFlightPage.bookFlight - Credit card entered");
    		// Confirm purchase
    		buyFlightsButton.click();
    		Log.info("BookFlightPage.bookFlight - Buy Flights Button clicked");
    	}
    }
    
  17. Update ‘FlightConfirmationPage.java’ file with below code.
    package com.selenium.pages;
    
    import org.openqa.selenium.WebDriver;
    import org.openqa.selenium.WebElement;
    import org.openqa.selenium.support.FindBy;
    import org.testng.Assert;
    
    import com.selenium.util.Log;
    
    public class FlightConfirmationPage {
    
    	//Declare WebDriver
    	WebDriver driver;
    	//Element Locators for confirmation text
    	@FindBy(xpath = "//font[contains(text(),'Confirmation')]")
    	private WebElement confirmationText;
    	
    	//Element Locators for logout button
    	@FindBy(xpath = "//img[@src='/images/forms/Logout.gif']")
    	private WebElement logOutButton;
    
    	//Constructor. Driver Initialization
    	public FlightConfirmationPage(WebDriver driver) {
    		this.driver = driver;
    	}
    
    	//Verify and Log out method. 
    	public void clickLogOut() {
    		// Assert if Confirmation text is displayed
    		Assert.assertTrue(confirmationText.isDisplayed());
    		Log.info("FlightConfirmationPage.clickLogOut - Assertion completed");
    		// Click Logout button
    		logOutButton.click();
    		Log.info("FlightConfirmationPage.clickLogOut - Log Out Button clicked");
    	}
    }
    
  18. Final step is to update the TestNG script with log messages. Update ‘BookFlight.java’ file with below code. Notice inside ‘beforeTest’ method we are setting the location of  ‘log4j.xml’ file and also setting system properties for ‘logfoldername‘ and ‘logfilename‘.
    package com.selenium.testcase;
    
    import org.testng.annotations.Test;
    import com.selenium.pages.BookFlightPage;
    import com.selenium.pages.FlightConfirmationPage;
    import com.selenium.pages.FlightFinderPage;
    import com.selenium.pages.HomePage;
    import com.selenium.pages.SelectFlightPage;
    import com.selenium.util.Log;
    import org.testng.annotations.BeforeMethod;
    import org.apache.log4j.xml.DOMConfigurator;
    import org.openqa.selenium.WebDriver;
    import org.openqa.selenium.chrome.ChromeDriver;
    import org.openqa.selenium.support.PageFactory;
    import org.testng.annotations.AfterMethod;
    import org.testng.annotations.DataProvider;
    import org.testng.annotations.BeforeTest;
    
    public class BookFlight {
    
    	WebDriver driver;
    	HomePage homePage;
    	FlightFinderPage flightFinderPage;
    	SelectFlightPage selectFlightPage;
    	BookFlightPage bookFlightPage;
    	FlightConfirmationPage flightConfirmationPage;
    
    	// Test Case
    	@Test(dataProvider = "newTourData")
    	public void bookFlight(String uname, String pwd, String departFrom, String departDate, String fname, String lname,
    			String ccNum) {
    
    		/*
    		 * Test case logic.
    		 * 
    		 */
    		Log.startTestCase("Test Case bookFlight");
    		Log.info("BookFlight.bookFlight - Home Page Opens");
    		homePage.loginUser(uname, pwd);
    		Log.info("BookFlight.bookFlight - Flight Finder Page Opens");
    		flightFinderPage.findFlights(departFrom, departDate);
    		Log.info("BookFlight.bookFlight - Select Flight Page Opens");
    		selectFlightPage.reserveFlight();
    		Log.info("BookFlight.bookFlight - Book Flight Page Opens");
    		bookFlightPage.bookFlight(fname, lname, ccNum);
    		Log.info("BookFlight.bookFlight - Flight Confirmation Page Opens");
    		flightConfirmationPage.clickLogOut();
    		Log.endTestCase("Test Case bookFlight");
    
    	}
    
    	// Driver and Page Objects Initialization
    	@BeforeMethod
    	public void beforeMethod() {
    		// Initialize driver
    		driver = new ChromeDriver();
    		Log.info("BookFlight.beforeMethod - Chrome Driver Intialized");
    		// Maximize window
    		driver.manage().window().maximize();
    		Log.info("BookFlight.beforeMethod - Browser maximized");
    
    		// Page Factory Initialization for all page objects
    		homePage = PageFactory.initElements(driver, HomePage.class);
    		flightFinderPage = PageFactory.initElements(driver, FlightFinderPage.class);
    		selectFlightPage = PageFactory.initElements(driver, SelectFlightPage.class);
    		bookFlightPage = PageFactory.initElements(driver, BookFlightPage.class);
    		flightConfirmationPage = PageFactory.initElements(driver, FlightConfirmationPage.class);
    		Log.info("BookFlight.beforeMethod - Page Factory intialization complete");
    
    		// Nvaigate to URL
    		driver.get("http://newtours.demoaut.com");
    		Log.info("BookFlight.beforeMethod - open New Tour URL");
    
    	}
    
    	// Driver closure
    	@AfterMethod
    	public void afterMethod() {
    		// Close and quit the driver to close the Browser
    		driver.close();
    		driver.quit();
    		Log.info("BookFlight.afterMethod - Browser closed");
    	}
    
    	// Create test data
    	@DataProvider
    	public Object[][] newTourData() {
    		return new Object[][] { { "demo", "demo", "London", "7", "john", "Doe", "56465465" } };
    	}
    
    	// Setting System property
    	@BeforeTest
    	public void beforeTest() {
    		// Set System Property for driver location
    		System.setProperty("webdriver.chrome.driver", System.getProperty("user.dir") + "/Chrome/chromedriver");
    		SimpleDateFormat sdf1 = new SimpleDateFormat("yyyy-MM-dd");
    		SimpleDateFormat sdf2 = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss");
    		//Set System Property for log file location
    		System.setProperty("logfoldername", sdf1.format(Calendar.getInstance().getTime()));
    		System.setProperty("logfilename", sdf2.format(Calendar.getInstance().getTime()) + "-LOG");
    		
    		Log.info("BookFlight.beforeTest - System property setting complete");
    		DOMConfigurator.configure("src/log4j.xml");
    		Log.info("BookFlight.beforeTest - XML config complete");
    	}
    }
    
  19. Below is how project structure looks like.

    Project Structure
  20. Now that we have completed all changes in our ‘NewTourPageFactory‘ project, next step is to run our TestNG script. Right click on ‘BookFlight’ class and click Run As -> TestNG Test.
  21. After successful execution, log messages are printed in console as displayed below.

    Log messages in console output
  22. A new log file is created under ‘NewTourPageFactory/test-output/log’ folder. This is based on the setting ‘value=test-output/log/${logfoldername}/${logfilename}.log’ that we did in ‘log4j.xml’ file.

    Log file inside test-output folder

With this we came to an end of Log4j logging. We will be using the logging in future frameworks.

Till then Happy Learning!

Additional Information:

Instead of ‘log4j.xml’ file we can also use ‘log4j.properties’ file.

  • Delete the already created ‘log4j.xml’ file from ‘src‘ folder and comment the code ‘DOMConfigurator.configure(“src/log4j.xml”)’ inside ‘beforeTest’ method of ‘BookFlight.java’. Right click on ‘src‘ folder and click New -> Other. Select File under General folder.

    Select File
  • Name the file as ‘log4j.properties’ and click finish to close the window. Copy and paste below details to the properties files.
    # Root logger option
    log4j.rootLogger=INFO, file, console
    
    # Direct log messages to a log file
    log4j.appender.file=org.apache.log4j.RollingFileAppender
    log4j.appender.file.Append=False
    log4j.appender.file.File=${user.dir}/test-output/log/${logfoldername}/${logfilename}.log
    log4j.appender.file.MaxFileSize=10KB
    log4j.appender.file.MaxBackupIndex=5
    log4j.appender.file.layout=org.apache.log4j.PatternLayout
    log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n
    
    # Direct log messages to console
    log4j.appender.console=org.apache.log4j.ConsoleAppender
    log4j.appender.console.Target=System.out
    log4j.appender.console.layout=org.apache.log4j.PatternLayout
    log4j.appender.console.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n
    
  • We can see the same results in console as well as in log file.