Troubleshooting Tomcat deployment problem for jaxws-2.2 application : The Sherlock Holmes way

I just spent my last 3 hour trying to deploy my perfect JAXWS-2.2 application in tomcat 6.0.26. Again I felt so great and thanked God that I took programming as a profession. Sure you don’t get to solve mysterious murder cases like Sherlock Homes, but the things we do are not much different! Where else can you go to work, get a problem with a set of clues, judge / discard / follow each and every clue, follow the trails to come to identify the problem and fix it and get paid for it!

Background:

The application was running happily in Jetty ever since I wrote it three months ago but my client wants to run it in tomcat. It was a standard web application so I thought it will be a child’s play to deploy it in tomcat. Ah! As if I have learned nothing from history! Nothing is child’s play when it comes to deploy an application in a new container, no matter how standard it is! I have learned this lesson hard way from deploying application in tomcat, jetty, jboss, weblogic, glassfish (yeah..i’v been fortunate/unfortunate enough to play with them all) , yet I tend to forget.

Problem 1:
First time I tried to run the app, I ran into the ClassNotFoundException:

SEVERE: WSSERVLET11: failed to parse runtime descriptor: java.lang.NoClassDefFoundError: javax/xml/ws/soap/AddressingFeature$Responses
java.lang.NoClassDefFoundError: javax/xml/ws/soap/AddressingFeature$Responses
	at com.sun.xml.ws.policy.PolicyWSDLGeneratorExtension.loadConfigurators(PolicyWSDLGeneratorExtension.java:459)
	at com.sun.xml.ws.policy.PolicyWSDLGeneratorExtension.start(PolicyWSDLGeneratorExtension.java:111)

..........................

I remember this! This was due to the jaxws-2.2 libraries conflicting with jaxws-2.1 libraries shipped with jdk-1.6! But I had it fixed by placing the latest jaxb-api.jar & jaxws-api.jar into the JDK_HOME/jre/lib/endorsed folder!

Hmm…here is a clue…the library is setup properly in JDK , app is running fine with Jetty with the same JDK, but wouldn’t load in tomcat!! Who is the ‘Usual Suspect’ ? Of course the tomcat classloading framework! Its ignoring the ‘endorsed’ jars configured in JDK ! Ah, at this point I begin to miss my old complex Tomcat 5.5, there was this ‘endorsed’ directory in the ‘common/endorsed’ folder. Where is it in tomcat 6? Luckily I had some old trick under my belt…Quickly Added a ServletContextListener like this:

public class WebappLoadListener implements ServletContextListener {
	private static final Log log = LogFactory.getLog(WebappLoadListener.class);
	public void contextDestroyed(ServletContextEvent arg0) {
	}

	public void contextInitialized(ServletContextEvent arg0) {
		log.info("\n\n\n ENDORSED DIR: " +System.getProperty("java.endorsed.dirs"));		
	}
}

And the output was:

ENDORSED DIR:  /usr/local/development/servers/apache-tomcat-6.0.26/endorsed

How the hack am I supposed to know that, the directory is not even there! Come on tomcat guys, I understand you want to make things simple for the new tomcat adopters, but why screw us – the old 5.5 users!!! Created folder “/usr/local/development/servers/apache-tomcat-6.0.26/endorsed” and copied the latest jars (jaxb-api.jar jaxws-api.jar) in there, got rid of the ClassNotFoundException.

Problem 2:
As soon as I got rid of problem 1, I ran into this:

SEVERE: WSSERVLET11: failed to parse runtime descriptor: java.lang.NoSuchMethodError: com.sun.istack.logging.Logger.getLogger(Ljava/lang/Class;)Lcom/sun/istack/logging/Logger;
java.lang.NoSuchMethodError: com.sun.istack.logging.Logger.getLogger(Ljava/lang/Class;)Lcom/sun/istack/logging/Logger;
	at com.sun.xml.ws.api.config.management.policy.ManagementAssertion.<clinit>(ManagementAssertion.java:87)
	at com.sun.xml.ws.server.MonitorBase.createManagedObjectManager(MonitorBase.java:121)
	at com.sun.xml.ws.server.WSEndpointImpl.<init>(WSEndpointImpl.java:143)
	at com.sun.xml.ws.server.EndpointFactory.createEndpoint(EndpointFactory.java:232)
	at com.sun.xml.ws.api.server.WSEndpoint.create(WSEndpoint.java:505)
	at com.sun.xml.ws.transport.http.DeploymentDescriptorParser.parseAdapters(DeploymentDescriptorParser.java:253)
	at com.sun.xml.ws.transport.http.DeploymentDescriptorParser.parse(DeploymentDescriptorParser.java:147)

Now this got my head spinning! All the clue I got from Google was pointing to ‘Problem 1’…I was also a little confused and headed that way, placed the ‘jaxb-api.jar jaxws-api.jar’ in various locations, with no luck ! Ok, time to give up that trail and think clear. So, it was not a ClassNotFoundException, the class is there, but the Method is not. Why do this sounds familier? Because I have seen it countless times! Its because of two version of same class staying in the classpath and the faulty one getting preference by Tomcat ClassLoader! If you know about tomcat classloading, you know that it creates a ClassLoader for each webapp and the jars in “WEB-INF/lib” are loaded first (by the child classloader). So I must have some jar in my dependency which should not be there…Hmm..how do I know which jar? Wait, I know a way, infact I even blogged about it HERE.

So quickly added this method in my WebappLoadListener:

public static String getClassLocation(Class clazz) {
		if(clazz == null) {
			return null;
		}

		try {
			ProtectionDomain protectionDomain = clazz.getProtectionDomain();
			CodeSource codeSource = protectionDomain.getCodeSource();
			URL location = codeSource.getLocation();
			return location.toString();
		} catch (Throwable e) {
			e.printStackTrace();
			return "Not found";
		}
	}

	public void contextInitialized(ServletContextEvent arg0) {		
		log.error("jar file: " + getClassLocation(com.sun.istack.logging.Logger.class));		
	}

OUTPUT:

ERROR WebappLoadListener:21 - jar file: file:/home/sajid/workspace_test/.metadata/.plugins/org.eclipse.wst.server.core/tmp0/wtpwebapps/jaxws-sample/WEB-INF/lib/istack-commons-runtime-1.1-SNAPSHOT.jar

I got you “Professor Moriarty” (in case you are not familiar with Sherlock Holmes, Professor Moriarty is the common villain)! How did you got in my LIB folder ! The very name “istack-commons-runtime-1.1-SNAPSHOT.jar” suggests that I should not bundle it in my app! I deleted the jar manually and ran the code. Ah! Sweet. At last my code deployed in tomcat and all my SOAP-UI tests(only Three to be honest) are passed! And where is the class loaded from now?

ERROR WebappLoadListener:21 - jar file: file:/home/sajid/workspace_test/.metadata/.plugins/org.eclipse.wst.server.core/tmp0/wtpwebapps/jaxws-sample/WEB-INF/lib/jaxb-impl-2.2.jar

See! The right class is supplied with the jaxb-impl Jar.

Now, back to the old question, how did istack-commons-runtime-1.1-SNAPSHOT.jar ended up in my library? Did a quick ‘Dependency Graph’ in eclipse

So I added an exclusion rule in the dependency of jaxws-rt:

		<dependency>
			<groupId>com.sun.xml.ws</groupId>
			<artifactId>jaxws-rt</artifactId>
			<version>2.2</version>
			<exclusions>
				<exclusion>
					<groupId>com.sun.istack</groupId>
					<artifactId>istack-commons-runtime</artifactId>
				</exclusion>
			</exclusions>
		</dependency>

Ran all the tests and everything seemed to be OK. I feel so lucky that I spent time writing those SOAP-UI test cases (at the time it felt like complete waste of time)! Otherwise, I’d have to test the application manually to see if anything was broken by this.

Conclusion:
I see now why newbies like to adopt those exotic Ruby framework instead of Java. Imagine someone trying to build a webservice using JAX-WS. As if the api specs are not confusing enough, he has to go through all these pain to run the app! I feel sorry for the poor guy if he starts with tomcat, he would have no clue that its not his code’s fault that the app is not running. Luckily I started with Jetty, not because I was wise but because the client wanted it in Jetty.

But did I have fun going through all these pain? I sure did 🙂 . Good to know that I still get a kick out of fixing these weird problems, no matter how many times I did it before.