Java Performance

I found an interesting article about Java Performance, definitely worth reading it: http://www.infoq.com/articles/9_Fallacies_Java_Performance.

The essence is, that performance optimization of Java applications is anything but straightforward. Naive, intuitive approaches might make things rather worse (something that is by the way often the case for architectural concerns). Also interesting, the actual impact of algorithm efficiency (or shall we say code quality in general?) on overall performance seems very low. Something that is perhaps particularly true for enterprise applications.

Spring autowire performance improvement in version 3.1.2

Spring finally fixed a long known problem with the autowire (by type) performance, or generally spoken, with the performance of bean lookup by type. The background is, that determination of the actual type of a Spring bean is not done with a simple instanceof, because most beans might be proxies. A Spring bean could even have multiple proxies. So, to determine the type it is necessary to iterate through all PostProcessors and ask them for the original type:

protected Class predictBeanType(String beanName, RootBeanDefinition mbd, Class... typesToMatch) {
	Class beanClass;
	if (mbd.getFactoryMethodName() != null) {
		beanClass = getTypeForFactoryMethod(beanName, mbd, typesToMatch);
	}
	else {
		beanClass = resolveBeanClass(mbd, beanName, typesToMatch);
	}
	// Apply SmartInstantiationAwareBeanPostProcessors to predict the
	// eventual type after a before-instantiation shortcut.
	if (beanClass != null && !mbd.isSynthetic() && hasInstantiationAwareBeanPostProcessors()) {
		for (BeanPostProcessor bp : getBeanPostProcessors()) {
			if (bp instanceof SmartInstantiationAwareBeanPostProcessor) {
				SmartInstantiationAwareBeanPostProcessor ibp = (SmartInstantiationAwareBeanPostProcessor) bp;
				Class processedType = ibp.predictBeanType(beanClass, beanName);
				if (processedType != null) {
					return processedType;
				}
			}
		}
	}
	return beanClass;
}

This process can take astonishing long. And if you use autowiring in huge web-applications, with a lot of scoped beans, this can easily take a big part of the request time. Which has already been reported two years ago: SPR-6870

It was fixed now by simply caching all calls to DefaultListableBeanFactory.getBeansOfType(). See: SPR-9448

I recommend to update to Spring 3.1.2 if you’re using autowiring in scoped beans (especially request beans)!

Automatically logging slow Hibernate queries

When you’re using Hibernate you can either set the property hibernate.show_sql to true or enable the logger org.hibernate.SQL to display the generated SQL statements. But the generated log output does not include the (named) parameter values or – rather more interesting – the execution time.

This is where jdbcdslog comes in, it enables logging at the JDBC level and has some quite nice features:

  • Simple configuration with Spring as a proxy data source that wraps the actual data source
  • Outputs the execution time
  • Comes with a special logger for “slow” statements with a configurable threshold time
  • “Inlines” the parameter values, hence you can simply copy the outputted SQL into your DB administration tool and execute it manually

Here the few steps necessary to enable a slow statement logger in your application:

Add the maven dependency:

<dependency>
	<groupId>com.googlecode.usc>/groupId>
	<artifactId>jdbcdslog</artifactId>
	<version>1.0.6.2</version>
<dependency>

Use the jdbcdslog proxy datasource in your Spring context:

<bean id="dataSource" class="org.jdbcdslog.ConnectionPoolDataSourceProxy">
    	<property name="targetDSDirect">
    	  <jee:jndi-lookup resource-ref="true" jndi-name="jdbc/myDatasource">
    	</property>
</bean>

Add a property file jdbcdslog.properties to /src/main/resources with the following content:

jdbcdslog.showTime=true
jdbcdslog.logText=true
jdbcdslog.slowQueryThreshold=500</pre> 

With this properties all SQL statements that last longer than 500 ms are outputted to the logger org.jdbcdslog.SlowQueryLogger at info level.

When you’re using logback as logging facility you would enable the slow statements like below:

<logger name="org.jdbcdslog.SlowQueryLogger">
	<level value="info" />
	<appender-ref ref="STDOUT" />
	<appender-ref ref="FILE_SLOW_SQL" />
</logger>

And now you’ll see all slow SQL statements in the console during development. Pretty cool, isn’t it?