On my current project we are using Spring MVC and we try to use autowiring as much as possible. I personally strongly prefer constructor injection, since this gives me the luxury of working with final fields. I also like being able to inject all things a class needs – including loggers. Most of the time I don’t really want to use custom loggers from tests, but sometimes I do want to make sure something gets logged correctly, and being able to inject a logger seems like a natural way of doing that. So, with that preamble out of the way, my problem was that this seemed quite hard to achieve in Spring. Specifically, I use SLF4J, and I want to inject the equivalent of doing LoggerFactory.getLogger(MyBusinessObject.class). Sadly, Spring doesn’t give access to the place where something is going to be injected in any of the hooks available. Most solutions I found to this problem relies on using a BeanPostProcessor to set a field on the object after it’s been created. This defeats three of my purposes/principles – I can’t use the logger in the constructor, the field will be mutable and I won’t get told by Spring if I’ve made a mistake in my wiring.
There was however one solution I found in a StackOverflow post – sadly it wasn’t complete. Specifically, I needed to use it in a Spring MVC setting and also from inside of tests. So this blog post is mainly to provide the complete solution for something like this. It’s a simple problem, but it was surprisingly tricky to get working correctly. But now that I have it, it will be very convenient. This code is for Spring 3.1, and I haven’t tested it on anything else.
The first part of this injection is to create our own custom BeanFactory – which is what Spring uses internally to manage beans and dependencies. The default one is called DefaultListableBeanFactory and we will just subclass it like this:
public class LoggerInjectingListableBeanFactory extends DefaultListableBeanFactory {
public LoggerInjectingListableBeanFactory() { setParameterNameDiscoverer( new LocalVariableTableParameterNameDiscoverer()); setAutowireCandidateResolver( new QualifierAnnotationAutowireCandidateResolver());
} public LoggerInjectingListableBeanFactory( BeanFactory parentBeanFactory) { super(parentBeanFactory); setParameterNameDiscoverer( new LocalVariableTableParameterNameDiscoverer()); setAutowireCandidateResolver( new QualifierAnnotationAutowireCandidateResolver()); } @Override public Object resolveDependency( DependencyDescriptor descriptor, String beanName, Set<String> autowiredBeanNames, TypeConverter typeConverter) throws BeansException { Class<?> declaringClass = null; if(descriptor.getMethodParameter() != null) { declaringClass = descriptor.getMethodParameter() .getDeclaringClass(); } else if(descriptor.getField() != null) { declaringClass = descriptor.getField() .getDeclaringClass(); } if(Logger.class.isAssignableFrom(descriptor.getDependencyType())) { return LoggerFactory.getLogger(declaringClass); } else { return super.resolveDependency(descriptor, beanName, autowiredBeanNames, typeConverter); } } }
The magic happens inside of resolveDependency where we can figure out the declaring class by checking either the method parameter or the field – and then see whether the thing asked for is a Logger. Otherwise we just delegate to the super implementation.
In order to use this from anything we need an actual ApplicationContext that uses it. I didn’t find any hook to set the BeanFactory after the application context was created, so I ended up creating two new ApplicationContext implementations – one for tests and one for the Spring MVC purpose. They are slightly different, but try to do so little as possible while retaining the behavior of the original. The application context for the tests look like this:
public class LoggerInjectingGenericApplicationContext extends GenericApplicationContext { public LoggerInjectingGenericApplicationContext() { super(new LoggerInjectingListableBeanFactory()); } }
This one just calls the super constructor with an instance of our custom bean factory. The application context for Spring MVC looks like this:
public class LoggerInjectingXmlWebApplicationContext extends XmlWebApplicationContext { @Override protected DefaultListableBeanFactory createBeanFactory() { return new LoggerInjectingListableBeanFactory( getInternalParentBeanFactory()); } }
The XmlWebApplicationContext doesn’t have a constructor that takes a bean factory, so instead we override the createBeanFactory method to return our custom instance. In order to actually use these implementations some more things are needed. In order to get our tests to use it, a test.context.support.ContextLoader implementation is necessary. This code is mostly just copied from the default implementation – sadly it doesn’t provide any extension points and the place I want to override are in the middle of two final methods. It feels quite ugly to just copy the implementations, but there are no hooks for this…
public class LoggerInjectingApplicationContextLoader extends AbstractContextLoader { public final ApplicationContext loadContext( MergedContextConfiguration mergedContextConfiguration) throws Exception { String[] locations = mergedContextConfiguration.getLocations(); GenericApplicationContext context = new LoggerInjectingGenericApplicationContext(); context.getEnvironment().setActiveProfiles( mergedContextConfiguration.getActiveProfiles()); loadBeanDefinitions(context, locations); AnnotationConfigUtils.registerAnnotationConfigProcessors(context); context.refresh(); context.registerShutdownHook(); return context; } public final ConfigurableApplicationContext loadContext(String... locations) throws Exception { GenericApplicationContext context = new LoggerInjectingGenericApplicationContext(); loadBeanDefinitions(context, locations); AnnotationConfigUtils.registerAnnotationConfigProcessors(context); context.refresh(); context.registerShutdownHook(); return context; } protected void loadBeanDefinitions( GenericApplicationContext context, String... locations) { createBeanDefinitionReader(context). loadBeanDefinitions(locations); } protected BeanDefinitionReader createBeanDefinitionReader( final GenericApplicationContext context) { return new XmlBeanDefinitionReader(context); } @Override public String getResourceSuffix() { return "-context.xml"; } }
The final thing necessary to get your tests to use the custom Bean Factory is to specify the loader to use in the ContextConfiguration on your test class, like this:
@RunWith(SpringJUnit4ClassRunner.class) @ContextConfiguration(value = "file:our-app-config.xml", loader = LoggerInjectingApplicationContextLoader.class) public class SomeTest { }
In order to get Spring MVC to pick this up, you can edit your web.xml and add a new init-param for the DispatcherServlet, like this:
<servlet> <servlet-name>Spring MVC Dispatcher Servlet</servlet-name> <servlet-class> org.springframework.web.servlet.DispatcherServlet </servlet-class> <init-param> <param-name>contextConfigLocation</param-name> <param-value>WEB-INF/our-app-config.xml</param-value> </init-param> <init-param> <param-name>contextClass</param-name> <param-value> com.example.LoggerInjectingXmlWebApplicationContext </param-value> </init-param> <load-on-startup>1</load-on-startup> </servlet>
This approach seems to work well enough. Some of the code is slightly ugly and I would definitely love to have a better hook for injection points to know where it will get injected. Having factory methods be able to take the receiver object might be very convenient, for example. Being able to customize the bean factory seems like it also should be much easier than this.
6 Comments, Comment or Ping
Hi Ola
I think I’ve understood that the reason you need to go to this trouble is in order to have a class-specific logger created automatically. Is that right?
I have given up on the practice of creating class-specific loggers for most purposes. I find that they give too-fine-grained control over logging and leak implementation details into what is effectively a user interface (the logs).
I prefer instead to have a small number of loggers which reflect the higher-level design of the system. For instance you might have one logger used by multiple classes to record significant domain events, one to record the details of user interactions with the system and one each for providing detailed logging of interactions with each integration point.
If you arrange your logging like this then it is natural to treat your loggers just like other dependencies you classes and a DI container can take care of instantiation and injection as normal.
-Ben
August 11th, 2011
Hi Ola,
funnily enough I have also done some logger injection using spring mvc.
I am all with Ben on logging being about events. Actually we are only using one logger at the moment, however we have one instance per request, so we can change log levels on a per request basis and also optionally output the log entries with the request, by passing a debug parameter into the request (obviously we had to protect this a bit).
We are using spring’s java config, which essentially means we barely use spring at all. We also don’t use autowiring, because I find it leads to poor structuring of the system and proliferation of classes.
Logging on the request level gives you another interesting feature (which we haven’t implemented yet). If your request processing fails, you can (retroactively) change the loglevel if your logger first accumulates everything in memory (which is fairly cheap if it’s only spanning a request). This is really neat as it gives you low noise for regular operation and high detail for the error case.
Cheers,
Felix
August 16th, 2011
Did you discount the usage of AOP as a possible solution? Be interested to know if you did and if you were able to identify the short comings.
August 17th, 2011
I go along the same lines as Ben, and prefer coarser logging. All the same, I appreciate this post – it is a useful technique.
August 20th, 2011
Hi,
It seems interesting, I was thinking on something similar. But I think that a BeanPostProcessor approach should be more accurate to the Spring Bean Lifecycle. If I have time, I’ll try this other way and let you know the results.
– Alvaro
August 23rd, 2011
Sorry, forget my previous message.
August 23rd, 2011
Reply to “Injecting loggers using Spring”