Monday, September 2, 2013

Read the whole stacktrace/Be careful when using spring

As a disclaimer, I am critical of a lot of Spring frameworks. Don't get me wrong, they're often useful and can save a lot of time when they're used right. But it's really easy to shoot yourself in the foot (or the head) when using a lot of them. For this post, exhibit A will be Spring DI. I recently had a developer forward me the following exception:

                               org.springframework.beans.factory.BeanCreationException: Error creating bean with name '****************' defined in class path resource [*****************************************************************]: Cannot resolve reference to bean '************************' while setting bean property 'senders' with key [TypedStringValue: value [03], target type [null]]; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name '************************' defined in class path resource [*****************************************************************]: Cannot resolve reference to bean '***********************************' while setting bean property 'connectionFactory'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name '***********************************': Invocation of init method failed; nested exception is javax.naming.NameNotFoundException: Context: ***************/*****/***********/***************, name: jms/MQ/*****************/*******: First component in name jms/MQ/*****************/Primary not found. [Root exception is org.omg.CosNaming.NamingContextPackage.NotFound: IDL:omg.org/CosNaming/NamingContext/NotFound:1.0]
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:328)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:106)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveManagedMap(BeanDefinitionValueResolver.java:378)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:161)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1360)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1118)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:517)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:585)
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:913)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:464)
at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:384)
at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:283)
at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)
at com.ibm.ws.webcontainer.webapp.WebApp.notifyServletContextCreated(WebApp.java:1717)
at com.ibm.ws.webcontainer.webapp.WebApp.commonInitializationFinish(WebApp.java:384)
at com.ibm.ws.webcontainer.webapp.WebAppImpl.initialize(WebAppImpl.java:299)
at com.ibm.ws.webcontainer.webapp.WebGroupImpl.addWebApplication(WebGroupImpl.java:100)
at com.ibm.ws.webcontainer.VirtualHostImpl.addWebApplication(VirtualHostImpl.java:166)
at com.ibm.ws.webcontainer.WSWebContainer.addWebApp(WSWebContainer.java:732)
at com.ibm.ws.webcontainer.WSWebContainer.addWebApplication(WSWebContainer.java:617)
at com.ibm.ws.webcontainer.component.WebContainerImpl.install(WebContainerImpl.java:376)
at com.ibm.ws.webcontainer.component.WebContainerImpl.start(WebContainerImpl.java:668)
at com.ibm.ws.runtime.component.ApplicationMgrImpl.start(ApplicationMgrImpl.java:1127)
at com.ibm.ws.runtime.component.DeployedApplicationImpl.fireDeployedObjectStart(DeployedApplicationImpl.java:1319)
at com.ibm.ws.runtime.component.DeployedModuleImpl.start(DeployedModuleImpl.java:611)
at com.ibm.ws.runtime.component.ApplicationMgrImpl.startModule(ApplicationMgrImpl.java:1572)
at com.ibm.ws.runtime.component.ApplicationMgrImpl._startModule(ApplicationMgrImpl.java:1520)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:49)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:256)
at javax.management.modelmbean.RequiredModelMBean.invokeMethod(RequiredModelMBean.java:1085)
at javax.management.modelmbean.RequiredModelMBean.invoke(RequiredModelMBean.java:966)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:848)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:773)
at com.ibm.ws.management.AdminServiceImpl$1.run(AdminServiceImpl.java:1331)
at com.ibm.ws.security.util.AccessController.doPrivileged(AccessController.java:118)
at com.ibm.ws.management.AdminServiceImpl.invoke(AdminServiceImpl.java:1224)
at com.ibm.ws.management.application.sync.StartDeploymentTask.startDeployment(StartDeploymentTask.java:246)
at com.ibm.ws.management.application.sync.StartDeploymentTask.fineGrainUpdate(StartDeploymentTask.java:197)
at com.ibm.ws.management.application.sync.StartDeploymentTask.performTask(StartDeploymentTask.java:104)
at com.ibm.ws.management.application.sync.AppBinaryProcessor$ExpandApp.expand(AppBinaryProcessor.java:1682)
at com.ibm.ws.management.application.sync.AppBinaryProcessor.postProcessSynchronousExt(AppBinaryProcessor.java:723)
at com.ibm.ws.management.bla.sync.BLABinaryProcessor.postProcess(BLABinaryProcessor.java:575)
at com.ibm.ws.management.bla.sync.BLABinaryProcessor.onChangeCompletion(BLABinaryProcessor.java:452)
at com.ibm.ws.management.repository.FileRepository.postNotify(FileRepository.java:1916)
at com.ibm.ws.management.repository.FileRepository.update(FileRepository.java:1425)
at com.ibm.ws.management.repository.client.LocalConfigRepositoryClient.update(LocalConfigRepositoryClient.java:189)
at com.ibm.ws.sm.workspace.impl.WorkSpaceMasterRepositoryAdapter.update(WorkSpaceMasterRepositoryAdapter.java:665)
at com.ibm.ws.sm.workspace.impl.RepositoryContextImpl.update(RepositoryContextImpl.java:1954)
at com.ibm.ws.sm.workspace.impl.RepositoryContextImpl.synch(RepositoryContextImpl.java:1902)
at com.ibm.ws.sm.workspace.impl.WorkSpaceImpl.synch(WorkSpaceImpl.java:511)
at com.ibm.ws.management.configservice.ConfigServiceImpl.save(ConfigServiceImpl.java:702)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:49)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:256)
at javax.management.modelmbean.RequiredModelMBean.invokeMethod(RequiredModelMBean.java:1085)
at javax.management.modelmbean.RequiredModelMBean.invoke(RequiredModelMBean.java:966)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:848)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:773)
at com.ibm.ws.management.AdminServiceImpl$1.run(AdminServiceImpl.java:1331)
at com.ibm.ws.security.util.AccessController.doPrivileged(AccessController.java:118)
at com.ibm.ws.management.AdminServiceImpl.invoke(AdminServiceImpl.java:1224)
at com.ibm.ws.management.connector.AdminServiceDelegator.invoke(AdminServiceDelegator.java:181)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
at java.lang.reflect.Method.invoke(Method.java:611)
at com.ibm.ws.management.connector.soap.SOAPConnector.invoke(SOAPConnector.java:453)
at com.ibm.ws.management.connector.soap.SOAPConnector.service(SOAPConnector.java:288)
at com.ibm.ws.management.connector.soap.SOAPConnection.handleRequest(SOAPConnection.java:65)
at com.ibm.ws.http.HttpConnection.readAndHandleRequest(HttpConnection.java:733)
at com.ibm.ws.http.HttpConnection.run(HttpConnection.java:532)
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1646)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name '************************' defined in class path resource [*****************************************************************]: Cannot resolve reference to bean '***********************************' while setting bean property 'connectionFactory'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name '***********************************': Invocation of init method failed; nested exception is javax.naming.NameNotFoundException: Context: ***************/*****/**********/***************, name: jms/MQ/*************************: First component in name jms/MQ/******************************found. [Root exception is org.omg.CosNaming.NamingContextPackage.NotFound: IDL:omg.org/CosNaming/NamingContext/NotFound:1.0]
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:328)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:106)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1360)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1118)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:517)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:322)
... 91 more
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name '************************': Invocation of init method failed; nested exception is javax.naming.NameNotFoundException: Context: ************************, name: jms/MQ/************************: First component in name jms/MQ/************************ not found. [Root exception is org.omg.CosNaming.NamingContextPackage.NotFound: IDL:omg.org/CosNaming/NamingContext/NotFound:1.0]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1455)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:322)
... 101 more
Caused by: javax.naming.NameNotFoundException: Context: ************************, name: jms/MQ/RequestManagement/Primary: First component in name ************************ not found. [Root exception is org.omg.CosNaming.NamingContextPackage.NotFound: IDL:omg.org/CosNaming/NamingContext/NotFound:1.0]
at com.ibm.ws.naming.jndicos.CNContextImpl.mapNotFoundException(CNContextImpl.java:4378)
at com.ibm.ws.naming.jndicos.CNContextImpl.doLookup(CNContextImpl.java:1807)
at com.ibm.ws.naming.jndicos.CNContextImpl.doLookup(CNContextImpl.java:1762)
at com.ibm.ws.naming.jndicos.CNContextImpl.lookupExt(CNContextImpl.java:1513)
at com.ibm.ws.naming.jndicos.CNContextImpl.lookup(CNContextImpl.java:645)
at com.ibm.ws.naming.util.WsnInitCtx.lookup(WsnInitCtx.java:166)
at com.ibm.ws.naming.util.WsnInitCtx.lookup(WsnInitCtx.java:180)
at javax.naming.InitialContext.lookup(InitialContext.java:436)
at org.springframework.jndi.JndiTemplate$1.doInContext(JndiTemplate.java:154)
at org.springframework.jndi.JndiTemplate.execute(JndiTemplate.java:87)
at org.springframework.jndi.JndiTemplate.lookup(JndiTemplate.java:152)
at org.springframework.jndi.JndiTemplate.lookup(JndiTemplate.java:178)
at org.springframework.jndi.JndiLocatorSupport.lookup(JndiLocatorSupport.java:104)
at org.springframework.jndi.JndiObjectLocator.lookup(JndiObjectLocator.java:105)
at org.springframework.jndi.JndiObjectFactoryBean.lookupWithFallback(JndiObjectFactoryBean.java:201)
at org.springframework.jndi.JndiObjectFactoryBean.afterPropertiesSet(JndiObjectFactoryBean.java:187)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1514)
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1452)
... 108 more
Caused by: org.omg.CosNaming.NamingContextPackage.NotFound: IDL:omg.org/CosNaming/NamingContext/NotFound:1.0
at com.ibm.ws.naming.ipcos.WsnOptimizedNamingImpl.handleNameNotFound(WsnOptimizedNamingImpl.java:2519)
at com.ibm.ws.naming.ipcos.WsnOptimizedNamingImpl.getNextWsnOptimizedNamingContext(WsnOptimizedNamingImpl.java:1270)
at com.ibm.ws.naming.cosbase.WsnOptimizedNamingImplBase$3.run(WsnOptimizedNamingImplBase.java:4738)
at com.ibm.ws.naming.cosbase.WsnOptimizedNamingImplBase$3.run(WsnOptimizedNamingImplBase.java:4733)
at com.ibm.ws.naming.util.CommonHelpers.retry(CommonHelpers.java:771)
at com.ibm.ws.naming.cosbase.WsnOptimizedNamingImplBase.getTargetContext(WsnOptimizedNamingImplBase.java:4732)
at com.ibm.ws.naming.cosbase.WsnOptimizedNamingImplBase$LeafOperationData.<init>(WsnOptimizedNamingImplBase.java:5311)
at com.ibm.ws.naming.cosbase.WsnOptimizedNamingImplBase.resolve_complete_info(WsnOptimizedNamingImplBase.java:2155)
at com.ibm.WsnOptimizedNaming._NamingContextStub.resolve_complete_info(_NamingContextStub.java:538)
at com.ibm.ws.naming.jndicos.CNContextImpl$2.run(CNContextImpl.java:2810)
at com.ibm.ws.naming.jndicos.CNContextImpl$2.run(CNContextImpl.java:2806)
at com.ibm.ws.naming.util.CommonHelpers.retry(CommonHelpers.java:771)
at com.ibm.ws.naming.jndicos.CNContextImpl.cosResolve(CNContextImpl.java:2804)
at com.ibm.ws.naming.jndicos.CNContextImpl.doLookup(CNContextImpl.java:1803)
... 124 more
I include the entire stack-trace to give you a little perspective (and to keep myself from looking like an idiot). Like most good trouble shooters, I skimmed the bottom of the trace and then looked more closely at the top three or four exceptions that got thrown. They were Spring bean related and there was something goofy about a classpath. I started to look at the classpath and buildpath for the project and actually spent a few weeks on and off trying to figure out what was going on before I noticed what should've jumped out at me right away: The middle of the trace.


Caused by: javax.naming.NameNotFoundException: Context: ************************, name: jms/MQ/RequestManagement/Primary: First component in name ************************ not found. [Root exception is org.omg.CosNaming.NamingContextPackage.NotFound: IDL:omg.org/CosNaming/NamingContext/NotFound:1.0]

There's the issue, plain as day. I could've solved this problem in five minutes of going through WebSphere config panels and realizing that the JNDI name it was looking for didn't exist. Instead, I ran down a bunny trail  before really examining the situation.

This story has two morals:

First, read the entire stack-trace before you start trying to figure out the problem. If you don't want to read it all, at least skim the exceptions, especially if you notice anything that looks odd.

Second, when you're working with Spring (or any other framework that has a tendency to throw lots of runtime exceptions) keep in mind that the framework may be an attention hog, and hiding the actual problem that you are encountering.