Logback – Dynamic creation of log files

Some project have some log constraints that are difficult to implements with Log4j.

Logback is an alternative to log4j. It gives you more possibilities and it can easily implements your log policies.

    log1

Origami by Brian Chan

In this post, I present a simple of Logback configuration for a maven project. This configuration implements a dynamic log files generation.

Sample project description

This post example is inspired from a batch log policy I dealt with. The batch processes N files and generates two logs for each processed file. The first one is a summary of logs with no stack trace for functional users and the second one is a detailed log for programmers.

The picture bellow presents this case of study.

logback
Below the summary of log policies to implement:

  1. Logging errors without stacktrace.
  2. Dynamic file logging (switch to new log file).
  3. Read logging directory from application properties file.
  4. Create log files name with timestamp.

1. Add Maven dependency

First we need to add Slf4j and logback dependency to the project.

<dependency>
	<groupId>org.slf4j</groupId>
	<artifactId>slf4j-api</artifactId>
	<version>1.7.5</version>
</dependency>

<dependency>
	<groupId>ch.qos.logback</groupId>
	<artifactId>logback-classic</artifactId>
	<version>1.0.13</version>
</dependency>

<dependency>
	<groupId>ch.qos.logback</groupId>
	<artifactId>logback-core</artifactId>
	<version>1.0.13</version>
</dependency>

<dependency>
	<groupId>ch.qos.logback</groupId>
	<artifactId>logback-access</artifactId>
	<version>1.0.13</version>
</dependency>

<dependency>
	<groupId>org.slf4j</groupId>
	<artifactId>jcl-over-slf4j</artifactId>
	<version>1.7.5</version>
</dependency>

2. Create a costom layout Class

To customise logging layout, we create a class which extends LayoutBase and override the doLayout method.

public class CustomLogLayout extends LayoutBase<ILoggingEvent>{

	@Override
	public String doLayout(ILoggingEvent event) {
		StringBuffer sbuf = new StringBuffer(128);
	    sbuf.append(new SimpleDateFormat("yyyyMMdd_HHmmss").format(new Date(event.getTimeStamp())));
	    sbuf.append(" ");
	    sbuf.append(String.format("%-6s", event.getLevel()));
	    sbuf.append(" ");
	    sbuf.append(event.getFormattedMessage());
	    if((event.getLevel() == Level.ERROR || event.getLevel() == Level.WARN) && event.getThrowableProxy() !=null) {
	    	sbuf.append(" - ");
	    	sbuf.append(StringUtils.substringBefore(event.getThrowableProxy().getMessage(), IOUtils.LINE_SEPARATOR));
	    }
	    sbuf.append(CoreConstants.LINE_SEPARATOR);
	    return sbuf.toString();
	}

}

3. Logback configuration

In this step we create Logback.xml config file that will use the costomLayout we created in the previous step and will implements the logs policies.

  • Line 3 indicates the path to properties file where it will look for some values. In our case the path is a system property.
  • Line 5 specifies a key for the timestamp value.
  • STIF appender creates a custom log files with the CustomLogLayout class.
  • loggerFileName is a MDC (Mapped Diagnostic Contexts) property. Changing this value will generate a new file.
  • SIFT-TRACE appender creates a verbose log file and it uses logback.classic.PatternLayout.

<configuration>

	<property file="${appli.config.path}" />

	<timestamp key="bySecond" datePattern="yyyyMMddHHmmss" />

	<appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">

		<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
			<level>INFO</level>
		</filter>
		<discriminator>
			<Key>loggerFileName</Key>
			<DefaultValue>unknown</DefaultValue>
		</discriminator>
		<sift>
			<appender name="FILE-${loggerFileName}" class="ch.qos.logback.core.FileAppender">
				<File>${log.dir}/${loggerFileName}_${bySecond}.log</File>
				<Append>false</Append>
				<encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
					<layout class="com.mycompany.log.CustomLogLayout" />
				</encoder>
			</appender>
		</sift>
	</appender>

	<appender name="SIFT-TRACE" class="ch.qos.logback.classic.sift.SiftingAppender">
		<discriminator>
			<Key>loggerFileName</Key>
			<DefaultValue>unknown</DefaultValue>
		</discriminator>
		<sift>
			<appender name="TRACE-${loggerFileName}" class="ch.qos.logback.core.FileAppender">
				<File>${log.dir}/TRACE_${loggerFileName}_${bySecond}.log</File>
				<Append>false</Append>
				<layout class="ch.qos.logback.classic.PatternLayout">
					<Pattern>%d %-5level %logger{5} - %msg%n</Pattern>
				</layout>
			</appender>
		</sift>
	</appender>

	<logger name="org.springframework" level="ERROR" />
	
	<root level="DEBUG">
		<appender-ref ref="SIFT" />
		<appender-ref ref="SIFT-TRACE" />
	</root>

</configuration>

4. Test config

In this step we test the logback configuration.

setup() method set system property for the properties file path where logback will look for loging directory path.

The test simulates processing N files and at the end it verifies that we have 2xN log files.

public class LogTest {

	private static final int TEST_FILE_NUM = 5;

	private static final File TEST_DIR = new File(System.getProperty("java.io.tmpdir"), "logbak-test-dir");

	@Before
	public void setUp() throws IOException {
		System.setProperty("appli.config.path", ClassLoader.getSystemClassLoader().getResource("logback.properties").getPath());
		TEST_DIR.mkdirs();
		FileUtils.cleanDirectory(TEST_DIR);
	}


	@Test
	public void testLogbackFileConfig() throws InterruptedException {

		Logger logger = LoggerFactory.getLogger(LogTest.class);

		// assume SLF4J is bound to logback in the current environment
		LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
		JoranConfigurator configurator = new JoranConfigurator();
		configurator.setContext(context);
		context.reset();

		try {
			configurator.doConfigure(ClassLoader.getSystemClassLoader().getResource("logback.xml").getFile());
		} catch (JoranException je) {
			StatusPrinter.print(context);
			Assert.fail("Erreur de chargement des paramètre logback");
		}

		for (int i = 1; i <= TEST_FILE_NUM; i++) {
			MDC.put("loggerFileName", "file" + i);
			logger.info("log in File{}", i);
			logger.debug("log in File{}", i);
			logger.error("log in File" + i, new Exception("My test exception", new Exception("my cause of exception")));
		}

		Assert.assertEquals(TEST_FILE_NUM * 2, TEST_DIR.listFiles().length);
	}
	
}

JUnit test with Mockito and Spring

It is important to be able to perform some integration testing without requiring deployment to your application server or connecting to other enterprise infrastructure.

This could be done in your Spring project by using Spring-test library and Mockito framework.

   

Photo credit: Honey

In this post, I present a simple way to create a mock and to inject it into a tested bean.

Preparation of testing with Mockito

To make Mockito available, we need to add following dependency in the pom.xml file.

<dependency>
    <groupId>org.mockito</groupId>
    <artifactId>mockito-core</artifactId>
    <version>1.9.5</version>
    <scope>test</scope>
</dependency>
<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-test</artifactId>
    <version>3.1.2.RELEASE</version>
    <scope>test</scope>
</dependency>

Deveop Mockito, Spring and JUnit tests

The code source bellow presents a JUnit test using Spring-test and Mockito framework.

  • @RunWith(SpringJUnit4ClassRunner.class) runs the test with Spring custom runner that will load Spring application context.
  • @Autowire associate invoiceService reference to the InvoiceService instance.
  • @Before annotation executes the setup method before the test.
  • MockitoAnnotations.initMocks(this) scans the class annotation, instanciates invoiceDaoMock and inject it into the InvoiceService bean.
  • when(.(any())).thenReturn() associates a return value with method execution parameters.


import static org.mockito.Mockito.*; 

//Load Spring contexte
@ContextConfiguration(locations = {"classpath:/application-context.xml"})
@RunWith(SpringJUnit4ClassRunner.class)
public class InvoiceServiceTest {
	
	// Create Mock
	@Mock
	private IInvoiceDao invoiceDaoMock;
	
	@InjectMocks
	@Autowired
	private IInvoiceService invoiceService;
	
	
	@Before
	public void setUp() {
		MockitoAnnotations.initMocks(this);
	}

	
	@Test
	public void testProcessInvoice() throws SQLException {
		
		// specify mock behave when method called
		when(invoiceDaoMock.save(any(Invoice.class))).thenReturn(Long.valueOf(1));
		
		Assert.assertNotNull(invoiceService);
		Map<Product, Integer> products = new HashMap<Product, Integer>();
		products.put(new Product("labtop", BigDecimal.valueOf(1255.50)), 2);
		Invoice invoice = invoiceService.processInvoice(products);
		
		Assert.assertEquals(1255.50 * 2, invoice.getTotal().doubleValue(), 0);
		
	}
}

DbUnit – Test and populate database with DbUnit, Hibernate and Spring

In enterprise Java applications development we need to test applications with unit tests. Usually, running a test one time can change database data. This can block running the test a second time because of integrity constraints. There are many solutions to solve this problem like:

  • Running SQL script.
  • Restoring a database.
  • Creating and populating a database with test data.
   

Photo credit: Marta

I think there isn’t a better solution, but some of them are more appropriate for some kind of projects.

Creating a script for initializing database is good solution for project using a big database and which need a large range of data to run significant test, because creating or restoring a database can take a lot of time and machine resources. But it can be complicated to create the script because we need to respect data dependency and to have someone in a team who has good SQL knowledge.

Restoring a data base is a good solution for a project with a stable database schema. A frequent database changes costs a lot of time. At every change, we need to restore a database, to make changes and to create a new backup before running application tests

Creating and populating a database is used for testing applications with small database and for new application developments (Development from scratch). This can be done by creating SQL scripts and running them before executing tests. There is more elegant solution to create and populate database which are based on an ORM like Hibernate and a database testing framework like DbUnit.

DbUnit is a JUnit extension (also usable with Ant) targeted at database-driven projects that, among other things, puts your database into a known state between test runs. This is an excellent way to avoid the myriad of problems that can occur when one test case corrupts the database and causes subsequent tests to fail or exacerbate the damage. [DbUnit web site]

In this post I will present one way of creating, populating and testing a Java application by using Hibernate JPA, Spring and DbUnit.

1 – Creating a Hibernate JPA Project with Spring

In this article I use the same project created in the article Using Hibernate JPA in Spring. You can browse the project in this link or you can checkout the project code from Google code SVN repository from this URL https://project4example1.googlecode.com/svn/trunk. After you check out the project into your IDE, the project will be structured as shown in the picture.

To add DbUnit in your project, you need to add “dbUnit.jar” to the project library. If you are using Maven you need to add DbUnit dependency in your pom.xml as shown in the code source bellow.

<dependency>
	<groupId>org.dbunit</groupId>
	<artifactId>dbunit</artifactId>
	<version>2.4.7</version>
	<scope>test</scope>
</dependency>
   

2 – Populate the database with DbUnit

The code source bellow presents the content of the FlatXmlDataSet.xml used in this project. The structure of the file is easy to understand; Each XML element corresponds to a table row. Each XML element name corresponds to a table name. The XML attributes correspond to table columns.

<!DOCTYPE dataset SYSTEM "src/test/resources/my-dataset.dtd">
<dataset>
	<customer customer_id="1" tax_id="2" name="name1" adresse="adresse1"
		city="Paris" state="Paris" zip="75001" phone="0606060606" />
	<customer customer_id="2" tax_id="3" name="name2" adresse="adresse2"
		city="Paris" state="Paris" zip="75002" phone="0606060607" />
	<customer customer_id="3" tax_id="4" name="name3" adresse="adresse3"
		city="Paris" state="Paris" zip="75003" phone="0606060608" />

	<customer_order order_id="1" customer_id="1"
		date_placed="2008-01-01" date_promised="2008-02-02" terms="terms"
		status="done" />
	<customer_order order_id="2" customer_id="2"
		date_placed="2009-02-02" date_promised="2009-04-20" terms="terms"
		status="done" />
	<customer_order order_id="3" customer_id="2"
		date_placed="2010-03-03" date_promised="2010-05-24" terms="terms"
		status="done" />
	<customer_order order_id="4" customer_id="3"
		date_placed="2008-04-04" date_promised="2008-07-05" terms="terms"
		status="done" />
</dataset>

To control data format you can add DTD file. This file is optional if you don’t want to use a DTD file you have to replace the first line of your flat XML dataset by <?xml version='1.0' encoding='UTF-8'?>.

<!ELEMENT dataset (
    customer*,
    customer_order*)>

<!ELEMENT customer EMPTY>
<!ATTLIST customer
	customer_id  CDATA #REQUIRED
	tax_id  CDATA #REQUIRED
	name  CDATA #REQUIRED
	adresse  CDATA #REQUIRED
	city  CDATA #REQUIRED
	state  CDATA #REQUIRED
	zip  CDATA #REQUIRED
	phone  CDATA #REQUIRED   
>

<!ELEMENT customer_order EMPTY>
<!ATTLIST customer_order
	order_id CDATA #REQUIRED
	customer_id CDATA #REQUIRED
	date_placed CDATA #REQUIRED
	date_promised CDATA #REQUIRED
	terms CDATA #REQUIRED
	status CDATA #REQUIRED
>

The code source bellow presents a jUnit test used to test a DAO. Before test execution, the database will be created by Hibernate and it will be populated by DbUnit with XML dataset. In the “setup” method CLEAN_INSERT operation is executed; it deletes all rows in tables and insert data from the data set.

package com.mycompany.test.dao;

import java.io.InputStream;
import java.sql.Connection;
import java.util.Collection;

import junit.framework.TestCase;

import org.dbunit.database.DatabaseConnection;
import org.dbunit.database.IDatabaseConnection;
import org.dbunit.dataset.IDataSet;
import org.dbunit.dataset.xml.FlatXmlDataSet;
import org.dbunit.operation.DatabaseOperation;
import org.hibernate.SessionFactory;
import org.springframework.context.ApplicationContext;
import org.springframework.context.support.ClassPathXmlApplicationContext;
import org.springframework.orm.hibernate3.SessionFactoryUtils;

import com.mycompany.dao.ICustomerDao;
import com.mycompany.entity.Customer;

public class CustomerDaoTest extends TestCase {

	private static final String[] LOCATIONS = { "application-context.xml" };
	private static final String FLAT_XML_DATASET = "FlatXmlDataSet.xml";
	private ApplicationContext context;
	private ICustomerDao iCustomerDao;


	@Override
	protected void setUp() throws Exception {
		super.setUp();
		context = new ClassPathXmlApplicationContext(LOCATIONS);
		iCustomerDao = (ICustomerDao) context.getBean("customerDao");
		DatabaseOperation.CLEAN_INSERT.execute(getConnection(), getDataSet());

	}

	public void testGetAllCustomers() {
		Collection<Customer> listCustomers = iCustomerDao.getAll();
		assertFalse(listCustomers.isEmpty());
	}
	
	public void testSaveCustomer() {
		Collection<Customer> listCustomers1 = iCustomerDao.getAll();
		Customer customer = new Customer(1, "name","adresse", "city", "state", "123", "0606060606", null);
		iCustomerDao.save(customer);
		Collection<Customer> listCustomers2 = iCustomerDao.getAll();
		assertEquals(listCustomers2.size() - listCustomers1.size(), 1);
	}
	

	private IDataSet getDataSet() throws Exception {
		InputStream inputStream = this.getClass().getClassLoader().getResourceAsStream(FLAT_XML_DATASET);
		IDataSet dataset = new FlatXmlDataSet(inputStream);
		return dataset;
	}

	private IDatabaseConnection getConnection() throws Exception {
		SessionFactory sessionFactory = (SessionFactory) context.getBean("sessionFactory");
		Connection jdbcConnection = SessionFactoryUtils.getDataSource(sessionFactory).getConnection();
		IDatabaseConnection connection = new DatabaseConnection(jdbcConnection);
		return connection;
	}
}


To test java applications we need to know data at initial state to predict data evolution and to make JUnit assertion. DbUnit gives a smart solution to populate a database. DbUnit is dedicated for applications tests, but I think it could be useful in others contexts like application deployment when we need to fill reference data.

A tip for testing JQuery Autocomplete with Selenium

Selenium is a great tool for testing web application. It tests the client side by launching a web browser and executing functional tests. Developing a test is very easy; we need just to record the test one time by Selenium IDE (Firefox plug-in). The recorded test can be exported to a JUnit test.
But sometimes testing screens with Ajax components need some caution to wait for asynchronous communication and for DHTML to be changed.
The source code below can help testing a JQuery Autocomplete field using Selenium.

                selenium.typeKeys("??locator??", "a");

                int second = 0;
                while(!selenium.isElementPresent("//li[?num?]"))
                {
                    if(second >= 10)
                        break;
                    Thread.sleep(1000);
                    second++;
                }