Difference between revisions of "SolvingClassLoaderProblems"

From Protege Wiki
Jump to: navigation, search
(New page: In order to apply the techniques of this section the developer will need to have the ability to capture and navigate the output of a run command and must be able to compile a knopflerfish ...)
 
(Debugging Class Loader Problems)
 
(17 intermediate revisions by the same user not shown)
Line 1: Line 1:
In order to apply the techniques of this section the developer will need to have the ability to capture and navigate the output of a run command and must be able to compile a knopflerfish distribution (''ant knopflerfish'')Given this I will describe how to debug class loader exceptions (if they cannot be easily figured out and they are giving you a headache).  So I recently saw the following exception:
+
== Debugging Class Loader Problems ==
<p>
+
 
<nowiki>
+
Note - since the first writing of this document - we have added [[SolvingClassLoaderProblems#Swing_Based_Visualization_of_OSGi_Class_Loading|a swing based  version]] of this tool.  While it does not generate all the information of the servlet based tool, it is easier to get working and it is more compelling and fun.  I also figure  that the graphical tool might be useful as an educational tool for discussing OSGi class loadingI will add some discussion of the swing based tool after the servlet based discussion.
 +
 
 +
=== Servlet Based Debug ===
 +
 
 +
I will describe how to debug class loader exceptions (if they cannot be easily figured out and they are giving you a headache).  Before starting, an important tip is the fact that class loader problems are often masked.  I usually have a good suspicion when this is the problem but it doesn't help that we don't know.  If you are not seeing a ClassNotFoundException or some like, put a breakpoint for ClassNotFoundException (which is what the class loader throws) and see what it turns up.  For example, consider the apple.* line in the bootdelegation configuration.  This line was inserted to fix a situation where the tree view did not come up properly.  The two exceptions that showed up were:
 +
<pre>
 +
  UIDefaults.getUI() failed: no ComponentUI class for:
 +
  org.protege.editor.owl.ui.tree.OWLModelManagerTree
 +
 
 +
  NullPointerException: null
 +
    java.util.Hashtable.get(Hashtable.java:336)
 +
    java.awt.Component.getFontMetrics(Component.java:2503)
 +
    javax.swing.JComponent.getFontMetrics(JComponent.java:1589)
 +
    org.protege.editor.owl.ui.tree.OWLObjectTree.updateUI(OWLObjectTree.java:249)
 +
</pre>
 +
Doesn't seem to have anything to do with class loading.  But putting the break point on ClassNotFoundException immediately turned up a class in the apple.laf package that wasn't being loaded.  Ok now for my example.
 +
 
 +
So I recently saw the following exception:
 +
 
 +
<pre>
 
java.lang.NoClassDefFoundError: org/apache/commons/lang/StringEscapeUtils
 
java.lang.NoClassDefFoundError: org/apache/commons/lang/StringEscapeUtils
at org.coode.xml.XMLWriterImpl.writeEntities(XMLWriterImpl.java:207)
+
        at org.coode.xml.XMLWriterImpl.writeEntities(XMLWriterImpl.java:207)
at org.coode.xml.XMLWriterImpl.startDocument(XMLWriterImpl.java:221)
+
        at org.coode.xml.XMLWriterImpl.startDocument(XMLWriterImpl.java:221)
at org.coode.owl.rdf.rdfxml.RDFXMLWriter.startDocument(RDFXMLWriter.java:135)
+
        at org.coode.owl.rdf.rdfxml.RDFXMLWriter.startDocument(RDFXMLWriter.java:135)
at org.coode.owl.rdf.rdfxml.RDFXMLRenderer.render(RDFXMLRenderer.java:87)
+
        at org.coode.owl.rdf.rdfxml.RDFXMLRenderer.render(RDFXMLRenderer.java:87)
at org.coode.owl.rdf.rdfxml.RDFXMLOntologyStorer.storeOntology(RDFXMLOntologyStorer.java:56)
+
        at org.coode.owl.rdf.rdfxml.RDFXMLOntologyStorer.storeOntology(RDFXMLOntologyStorer.java:56)
at uk.ac.manchester.cs.owl.OWLOntologyManagerImpl.saveOntology(OWLOntologyManagerImpl.java:370)
+
        at uk.ac.manchester.cs.owl.OWLOntologyManagerImpl.saveOntology(OWLOntologyManagerImpl.java:370)
at org.protege.editor.owl.model.OWLModelManagerImpl.save(OWLModelManagerImpl.java:368)
+
        at org.protege.editor.owl.model.OWLModelManagerImpl.save(OWLModelManagerImpl.java:368)
at org.protege.editor.owl.OWLEditorKit.handleSave(OWLEditorKit.java:185)
+
        at org.protege.editor.owl.OWLEditorKit.handleSave(OWLEditorKit.java:185)
at org.protege.editor.core.ProtegeManager.saveEditorKit(ProtegeManager.java:187)
+
        at org.protege.editor.core.ProtegeManager.saveEditorKit(ProtegeManager.java:187)
</nowiki>
+
</pre>
<p>
+
 
 
In this case the exception was caused by a trivial stupid typo in the org.protege.common manifest but I was confused at the time and did not figure this out.  So the first item of confusion here might be the question of which class loader is causing the problem.  One might somehow think that this is being caused by the class loader for the org.protege.editor.owl bundle because, in some vague and undefined sense, this sequence of events seemed to be triggered in that bundle.  But this is not how class loaders work.  Actually the class loader that got into trouble (before delegation is taken into account) is the class loader for the org.coode.xml.XMLWriterImp class.  This class loader is the org.semanticweb.owlapi bundle.
 
In this case the exception was caused by a trivial stupid typo in the org.protege.common manifest but I was confused at the time and did not figure this out.  So the first item of confusion here might be the question of which class loader is causing the problem.  One might somehow think that this is being caused by the class loader for the org.protege.editor.owl bundle because, in some vague and undefined sense, this sequence of events seemed to be triggered in that bundle.  But this is not how class loaders work.  Actually the class loader that got into trouble (before delegation is taken into account) is the class loader for the org.coode.xml.XMLWriterImp class.  This class loader is the org.semanticweb.owlapi bundle.
<p>
+
 
This should have been enough for me to figure out what happened because (at this time) the org.protege.editor.owl bundle imported the package org.apache.commons.lang and the org.protege.common bundle exportedthe package org.apache.commons.lang package.  There were very few things that could go wrong at this point but I didn't see it and I began to doubt my reasoning.
+
This should have been enough for me to figure out what happened because (at this time) the org.semanticweb.owlapi bundle imported the package org.apache.commons.lang and the org.protege.common bundle exported the package org.apache.commons.lang package.  There were very few things that could go wrong at this point but I didn't see it and I began to doubt my reasoning.
<p>
+
 
So I make a knopflerfish distributionI then modify the props.xargs file to set
+
To solve these types of problems I have created a bundle providing some servlets that debug class loading issuesThe source for this bundle can be
 +
found in the svn repository
 
<center>
 
<center>
      -Dorg.knopflerfish.framework.debug.classloader=true.
+
http://smi-protege/repos/protege/protege4/small-projects/org.protege.osgi.debug/trunk
 
</center>
 
</center>
In this mode knopflerfish spits out tons of output describing all its class loading workI work backwards in the resulting output from the exception and find the following log messages:
+
and once it is checked out it can be built with <i>ant dist</i>The result of <i>ant dist</i> will be a relatively minimal OSGi distribution in the directory <i>build/dist/equinox</i> which allows the org.protege.osgi.debug bundle to run.
<p><nowiki>
+
To use this with an equinox distribution copy the files
## DEBUG: BundleClassLoader(id=14,gen=0) Search for: org/apache/commons/lang/StringEscapeUtils.class
+
<pre>
## DEBUG: BundleClassLoader(id=14,gen=0) Import search: org/apache/commons/lang/StringEscapeUtils.class from #8
+
  javax.servlet_2.4.0.v200706111738.jar
## DEBUG: BundleClassLoader(id=8,gen=0) Search for: org/apache/commons/lang/StringEscapeUtils.class
+
  org.apache.commons.logging_1.0.4.v200706111724.jar
## DEBUG: BundleClassLoader(id=9,gen=0) Search for: org/protege/editor/core/ui/error/ErrorLog$ErrorLogEntry.class
+
  org.eclipse.equinox.http.jetty_1.0.1.R33x_v20070816.jar
</nowiki><p>
+
  org.eclipse.equinox.http.servlet_1.0.1.R33x_v20070816.jar
I am not including any of the other messages (involving class loaders to present the error to me) because there is no good news after thisThe first line
+
  org.eclipse.osgi.services_3.1.200.v20070605.jar
<p><nowiki>
+
  org.mortbay.jetty_5.1.11.v200706111724.jar
## DEBUG: BundleClassLoader(id=14,gen=0) Search for: org/apache/commons/lang/StringEscapeUtils.class
+
  org.protege.osgi.debug.jar
</nowiki><p>
+
</pre>
says that the class loader with the identity 14 initially tries to load the StringEscapeUtils.class.  So I need to figure out which class loader has the id 14. If I search forwards from the top of the log for the number14, I see the lines
+
into from the org.protege.osgi.debug distribution to the Protege 4 OWL editor's plugin directory.  (Note the exclusion of the    org.eclipse.osgi_3.3.1.R33x_v20070828.jar and org.eclipse.equinox.common_3.3.0.v20070426.jar files).  Now when the OWL editor is started  these bundles  will automatically be loaded.  One indicator that these bundles have been seen  are the following messages on the console:
<p><nowiki>
+
<pre>
## DEBUG: BundleClassLoader(id=14,gen=0) Created new classloader
+
Oct 25, 2007 11:35:46 PM org.mortbay.http.HttpServer doStart
Installed plugin The OWL API
+
INFO: Version Jetty/5.1.x
</nowiki><p>
+
Oct 25, 2007 11:35:46 PM org.mortbay.util.Container start
This means that during the installation of the OWL API the class loader 14 was created. So it was the OWL API bundle (org.semanticweb.owlapi) that initially tried to load the StringEscapeUtils class.  Just like it should have been.  The next two lines
+
INFO: Started org.mortbay.jetty.servlet.ServletHandler@c7e176
<p><nowiki>
+
Oct 25, 2007 11:35:46 PM org.mortbay.util.Container start
## DEBUG: BundleClassLoader(id=14,gen=0) Import search: org/apache/commons/lang/StringEscapeUtils.class from #8
+
INFO: Started HttpContext[/,/]
## DEBUG: BundleClassLoader(id=8,gen=0) Search for: org/apache/commons/lang/StringEscapeUtils.class
+
Oct 25, 2007 11:35:46 PM org.mortbay.http.SocketListener start
</nowiki><p>
+
INFO: Started SocketListener on 0.0.0.0:8080
says that the owl api bundle (#14) tries to get the definition of the StringEscapeUtils class from the bundle with the number 8.   As before I find out which bundle has the id 8 by searching down from the top of the logs:
+
Oct 25, 2007 11:35:46 PM org.mortbay.util.Container start
<p><nowiki>
+
INFO: Started org.mortbay.http.HttpServer@787144
Installed: file:jars/protege/org.protege.common.jar (id#8)
+
</pre>
</nowiki><p>
+
These message merely indicate that the http servlet code been initialized.
So the owl api bundle is delegating to org.protege.common just like I thought it shouldAt this point there is only one thing that could be wrong and I immediately go to checkIn the manifest the Bundle-Classpath includes an entry lib/commons-lang.jar.  This entry should be lib/commons-lang-2.2.jarIf I had trusted my logic better I would probably have saved myself some trouble but the knopflerfish debug statements allowed me to determine exactly what parts of my logic were right and what I did wrong.
+
 
 +
Now the rest is easyIf you go to the page
 +
<center>
 +
http://localhost:8080/debug/classloader
 +
</center>
 +
and enter the class org.apache.commons.lang.StringEscapeUtils we find that there is no bundle that can load this class.  But the plan was that the org.protege.common bundle should have seen this class.  This fact takes us directly to the typo in the classpath for org.protege.common in the org.protege.common MANIFEST.
 +
 
 +
Futher we can check the imports  and exports by going to the page
 +
<center>
 +
  http://localhost:8080/debug/package
 +
</center>
 +
and selecting the org.semanticweb.owlapi bunde.  We then see that this bundle imports the package org.apache.commons.lang from the org.protege.common bundle. This means that if org.protege.common can load the class  
 +
<center>
 +
org.apache.commons.lang.StringEscapeUtils
 +
</center>
 +
then so should the org.semanticweb.owlapi  bundle.
 +
 
 +
=== Swing Based Visualization of OSGi Class Loading ===
 +
 
 +
If you only want the swing visualization then the installation of this bundle is even easier than described above.  The only thing that needs to be added is the org.protege.osgi.debug bundle itself.  This tool is made possible by the [http://jung.sourceforge.net/ Jung Group] who have made it extremely easy to display graphs in swing.
 +
 
 +
Here is a recently generated visualization generated on a freshly built copy of protege4.
 +
 
 +
[[File:ClassLoadingDebug01.png]]
 +
 
 +
Don't be dismayed if the initial graph looks too complex when it first comes up on your OSGi society. When you restrict attention to a class or package the presentation will significantly simplify.
 +
 
 +
The vertices of the graph denote OSGi bundles.  This visualization is showing which bundles can load the EditorKit class.  The red vertices represent bundles that cannot load the class.  The blue vertex is the bundle that provides the class for the OSGi environment.  Often, but not always, having two blue vertices for an important class represents a problem because it means that there are two incompatible versions of the same class.  The green vertices indicate bundles that can load the class but have not provided the class themselves.  The highlighted edges represent ''wires'' which are connections allowing the provider of a class to provide the class definition to the consumer of the class.  When a vertex is green but there is no wire leading to it, it means that the bundle is loading the class through boot delegation.
 +
 
 +
Here is another example where I added the debug bundle to an OSGi society that I used to demonstrate how OSGi can resolve jar library conflicts.
 +
 
 +
[[File:ClassLoadingDebug02.png]]
 +
 
 +
The class being displayed is org.example.conflict.UtilThere are two incompatible versions of this class and the PluginBundle is choosing which class to use based on its version.  This example is discussed in more detail [[Embedding_OSGi|here]]Note that the system bundle is providing a class which was not obtained through boot delegation.  This example was intended to show how  OSGi will be embedded in a larger host applicationIn this case, it will be typical for classes from the host application to be made visible in this way.

Latest revision as of 16:42, August 23, 2009

Debugging Class Loader Problems

Note - since the first writing of this document - we have added a swing based version of this tool. While it does not generate all the information of the servlet based tool, it is easier to get working and it is more compelling and fun. I also figure that the graphical tool might be useful as an educational tool for discussing OSGi class loading. I will add some discussion of the swing based tool after the servlet based discussion.

Servlet Based Debug

I will describe how to debug class loader exceptions (if they cannot be easily figured out and they are giving you a headache). Before starting, an important tip is the fact that class loader problems are often masked. I usually have a good suspicion when this is the problem but it doesn't help that we don't know. If you are not seeing a ClassNotFoundException or some like, put a breakpoint for ClassNotFoundException (which is what the class loader throws) and see what it turns up. For example, consider the apple.* line in the bootdelegation configuration. This line was inserted to fix a situation where the tree view did not come up properly. The two exceptions that showed up were:

  UIDefaults.getUI() failed: no ComponentUI class for:
  org.protege.editor.owl.ui.tree.OWLModelManagerTree

  NullPointerException: null
    java.util.Hashtable.get(Hashtable.java:336)
    java.awt.Component.getFontMetrics(Component.java:2503)
    javax.swing.JComponent.getFontMetrics(JComponent.java:1589)
    org.protege.editor.owl.ui.tree.OWLObjectTree.updateUI(OWLObjectTree.java:249)

Doesn't seem to have anything to do with class loading. But putting the break point on ClassNotFoundException immediately turned up a class in the apple.laf package that wasn't being loaded. Ok now for my example.

So I recently saw the following exception:

java.lang.NoClassDefFoundError: org/apache/commons/lang/StringEscapeUtils
        at org.coode.xml.XMLWriterImpl.writeEntities(XMLWriterImpl.java:207)
        at org.coode.xml.XMLWriterImpl.startDocument(XMLWriterImpl.java:221)
        at org.coode.owl.rdf.rdfxml.RDFXMLWriter.startDocument(RDFXMLWriter.java:135)
        at org.coode.owl.rdf.rdfxml.RDFXMLRenderer.render(RDFXMLRenderer.java:87)
        at org.coode.owl.rdf.rdfxml.RDFXMLOntologyStorer.storeOntology(RDFXMLOntologyStorer.java:56)
        at uk.ac.manchester.cs.owl.OWLOntologyManagerImpl.saveOntology(OWLOntologyManagerImpl.java:370)
        at org.protege.editor.owl.model.OWLModelManagerImpl.save(OWLModelManagerImpl.java:368)
        at org.protege.editor.owl.OWLEditorKit.handleSave(OWLEditorKit.java:185)
        at org.protege.editor.core.ProtegeManager.saveEditorKit(ProtegeManager.java:187)

In this case the exception was caused by a trivial stupid typo in the org.protege.common manifest but I was confused at the time and did not figure this out. So the first item of confusion here might be the question of which class loader is causing the problem. One might somehow think that this is being caused by the class loader for the org.protege.editor.owl bundle because, in some vague and undefined sense, this sequence of events seemed to be triggered in that bundle. But this is not how class loaders work. Actually the class loader that got into trouble (before delegation is taken into account) is the class loader for the org.coode.xml.XMLWriterImp class. This class loader is the org.semanticweb.owlapi bundle.

This should have been enough for me to figure out what happened because (at this time) the org.semanticweb.owlapi bundle imported the package org.apache.commons.lang and the org.protege.common bundle exported the package org.apache.commons.lang package. There were very few things that could go wrong at this point but I didn't see it and I began to doubt my reasoning.

To solve these types of problems I have created a bundle providing some servlets that debug class loading issues. The source for this bundle can be found in the svn repository

http://smi-protege/repos/protege/protege4/small-projects/org.protege.osgi.debug/trunk

and once it is checked out it can be built with ant dist. The result of ant dist will be a relatively minimal OSGi distribution in the directory build/dist/equinox which allows the org.protege.osgi.debug bundle to run. To use this with an equinox distribution copy the files

   javax.servlet_2.4.0.v200706111738.jar
   org.apache.commons.logging_1.0.4.v200706111724.jar
   org.eclipse.equinox.http.jetty_1.0.1.R33x_v20070816.jar
   org.eclipse.equinox.http.servlet_1.0.1.R33x_v20070816.jar
   org.eclipse.osgi.services_3.1.200.v20070605.jar
   org.mortbay.jetty_5.1.11.v200706111724.jar
   org.protege.osgi.debug.jar

into from the org.protege.osgi.debug distribution to the Protege 4 OWL editor's plugin directory. (Note the exclusion of the org.eclipse.osgi_3.3.1.R33x_v20070828.jar and org.eclipse.equinox.common_3.3.0.v20070426.jar files). Now when the OWL editor is started these bundles will automatically be loaded. One indicator that these bundles have been seen are the following messages on the console:

Oct 25, 2007 11:35:46 PM org.mortbay.http.HttpServer doStart
INFO: Version Jetty/5.1.x
Oct 25, 2007 11:35:46 PM org.mortbay.util.Container start
INFO: Started org.mortbay.jetty.servlet.ServletHandler@c7e176
Oct 25, 2007 11:35:46 PM org.mortbay.util.Container start
INFO: Started HttpContext[/,/]
Oct 25, 2007 11:35:46 PM org.mortbay.http.SocketListener start
INFO: Started SocketListener on 0.0.0.0:8080
Oct 25, 2007 11:35:46 PM org.mortbay.util.Container start
INFO: Started org.mortbay.http.HttpServer@787144

These message merely indicate that the http servlet code been initialized.

Now the rest is easy. If you go to the page

http://localhost:8080/debug/classloader

and enter the class org.apache.commons.lang.StringEscapeUtils we find that there is no bundle that can load this class. But the plan was that the org.protege.common bundle should have seen this class. This fact takes us directly to the typo in the classpath for org.protege.common in the org.protege.common MANIFEST.

Futher we can check the imports and exports by going to the page

  http://localhost:8080/debug/package

and selecting the org.semanticweb.owlapi bunde. We then see that this bundle imports the package org.apache.commons.lang from the org.protege.common bundle. This means that if org.protege.common can load the class

org.apache.commons.lang.StringEscapeUtils

then so should the org.semanticweb.owlapi bundle.

Swing Based Visualization of OSGi Class Loading

If you only want the swing visualization then the installation of this bundle is even easier than described above. The only thing that needs to be added is the org.protege.osgi.debug bundle itself. This tool is made possible by the Jung Group who have made it extremely easy to display graphs in swing.

Here is a recently generated visualization generated on a freshly built copy of protege4.

ClassLoadingDebug01.png

Don't be dismayed if the initial graph looks too complex when it first comes up on your OSGi society. When you restrict attention to a class or package the presentation will significantly simplify.

The vertices of the graph denote OSGi bundles. This visualization is showing which bundles can load the EditorKit class. The red vertices represent bundles that cannot load the class. The blue vertex is the bundle that provides the class for the OSGi environment. Often, but not always, having two blue vertices for an important class represents a problem because it means that there are two incompatible versions of the same class. The green vertices indicate bundles that can load the class but have not provided the class themselves. The highlighted edges represent wires which are connections allowing the provider of a class to provide the class definition to the consumer of the class. When a vertex is green but there is no wire leading to it, it means that the bundle is loading the class through boot delegation.

Here is another example where I added the debug bundle to an OSGi society that I used to demonstrate how OSGi can resolve jar library conflicts.

ClassLoadingDebug02.png

The class being displayed is org.example.conflict.Util. There are two incompatible versions of this class and the PluginBundle is choosing which class to use based on its version. This example is discussed in more detail here. Note that the system bundle is providing a class which was not obtained through boot delegation. This example was intended to show how OSGi will be embedded in a larger host application. In this case, it will be typical for classes from the host application to be made visible in this way.