When problems occur in open source software users tend to get stack traces. They often fire them off to some open source mailing list or forum asking for help; often without providing much in the way of detail. One of the first questions asked by support teams is often 'OK, what version are you using'.
Given that its possible to figure out the actual version being used of each class - either using the package information from the MANIFEST or by finding the jar the class came from, it seems logical to include the version information into a stack trace at the end of the line.
One day the JVM might actually do this for us :)
In the meantime, I've created a patch for log4j to add this feature; it appends an optional String to stack traces printed via log4j which includes the jar file name if it can be deduced plus the Java Package version the line of code comes from.
Here's an example...
e.g.
Am hoping one day this gets into some log4j release! You can find the patch here if you're interested.
Given that its possible to figure out the actual version being used of each class - either using the package information from the MANIFEST or by finding the jar the class came from, it seems logical to include the version information into a stack trace at the end of the line.
One day the JVM might actually do this for us :)
In the meantime, I've created a patch for log4j to add this feature; it appends an optional String to stack traces printed via log4j which includes the jar file name if it can be deduced plus the Java Package version the line of code comes from.
Here's an example...
org.apache.log4j.config.PropertySetterException: HelloSo you can see what version of junit is being used (despite there being no manifest information) along with the JDK implementation version.
at org.apache.log4j.spi.ThrowableInformationTest.testStackTracePackageName(ThrowableInformationTest.java:306)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [1.5.0]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [1.5.0]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [1.5.0]
at java.lang.reflect.Method.invoke(Method.java:585) [1.5.0]
at junit.framework.TestCase.runTest(TestCase.java:154) [junit-3.8.1.jar]
at junit.framework.TestCase.runBare(TestCase.java:127) [junit-3.8.1.jar]
at junit.framework.TestResult$1.protect(TestResult.java:106) [junit-3.8.1.jar]
at junit.framework.TestResult.runProtected(TestResult.java:124) [junit-3.8.1.jar]
at junit.framework.TestResult.run(TestResult.java:109) [junit-3.8.1.jar]
at junit.framework.TestCase.run(TestCase.java:118) [junit-3.8.1.jar]
at junit.textui.TestRunner.doRun(TestRunner.java:116) [junit-3.8.1.jar]
at com.intellij.rt.execution.junit.IdeaTestRunner.doRun(IdeaTestRunner.java:94) [idea_rt.jar]
at junit.textui.TestRunner.doRun(TestRunner.java:109) [junit-3.8.1.jar]
at com.intellij.rt.execution.junit.IdeaTestRunner.startRunnerWithArgs(IdeaTestRunner.java:22) [idea_rt.jar]
at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:118) [idea_rt.jar]
at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:40) [idea_rt.jar]
e.g.
at java.lang.reflect.Method.invoke(Method.java:585) [1.5.0]means we found the package number but couldn't find the jar file but we found the implementation version of java.lang.reflect to be 1.5.0. Whereas
at junit.framework.TestCase.run(TestCase.java:118) [junit-3.8.1.jar]means we found the jar file but the jar file has no manifest version information.
Am hoping one day this gets into some log4j release! You can find the patch here if you're interested.
19 comments:
Hi James,
cool!
BR,
~A
Brilliant!
Assuming the version number is the more valuable information, the patch works if either the "ImplementationVersion" is set in the manifest, or if the jar file name includes a version suffix. ImplementationVersion is rarely set and most jars do not have a version suffix, unless they are from a Maven repository.
I have the nagging feeling that extracting the version data will not always work, even if the general idea is pretty brilliant.
It's things like this that will get ImplementationVersion set though :) Hoping it gets in log4j.
I am puzzled why this hasn't been added for 3-5 years ago? But very helpful. +1 to get it in log4j.
What about OSGi bundles? Any help there to get the version also?
OMG, this is the solution to classloader issues! Brilliant! Now, this will be even more brilliant if it could somehow work without needing to patch log4j. =)
Ceki - you're right; if folks don't put the version in the jar name or in the manifest, this patch won't help.
However it will work for all jars created via Maven or hosted in a maven repository today (which is quite a large amount of java code) - plus its a great encouragement to anyone using Ant or Eclipse to start filling in that manifest - or including the version number in the jar.
Jon - there's no real reason that the JVM itself can't include this in stack traces; I just figured getting a JVM change in might take a long time :) In the meantime its trivial to take the patch and use it in any Java project; basically whenever a stack trace is created, we can generate a nice versioned stack trace.
Maybe its worth spinning up the code in a little project on google code so folks can easily embed the same feature inside their apps if they like - though I figured including it in the various logging frameworks was probably the simplest route which given how prolific the various logging libraries are - would generally not introduce a new dependency.
Thanks everyone for your comments!
Very cool patch. Very sharp thinking on your part. Amazing no one did this before.
I do agree with the commenter on the bug though that it would be nice to be configurable.
But I will definitely keep this patch handy.
Have attached another patch that makes it configurable :)
James are you saying that the following method in the patch accurately determines the class for a method on the callstack? Yes or No?
William
private Class findClass(String className) {
+ try {
+ return Thread.currentThread().getContextClassLoader().loadClass(className);
+ } catch (ClassNotFoundException e) {
+ try {
+ return Class.forName(className);
+ } catch (ClassNotFoundException e1) {
+ try {
+ return getClass().getClassLoader().loadClass(className);
+ } catch (ClassNotFoundException e2) {
+ return null;
+ }
+ }
+ }
+ }
William - unfortunately the JVM's StackTrace doesn't expose the actual Class objects which would make the patch pretty trivial. Given the plenthora of different class loader tricks that take place, its the best attempt at finding the class that caused the exception from the stack trace I could think of - typically the thread context class loader is gonna be the active one in most app servers for example.
There's a risk though - it might not be the correct class loader in all cases - but in most cases it should be. (Its certainly better from giving no versioning information ever for any stack trace! :).
Do you have a better way this could be done?
Yes I do have a solution. I will post it on my blog later as I do not want to get abushed by anti-commercial software and/or logging fanatics.
I just thought I would at least draw attention to the issue which should be noted in the patch (if it is not already).
Am looking forward to hearing your solution :)
I didn't realise there were any anti-commercial software or logging fanatics reading my blog comments. I'll keep on the look out for them & try keep them off your back if they do show up! :)
William - could you post your blog URL here when you've posted it, so we can see it?
am wondering if this is your blog William?
William Louth:
The findClass(String) method as implemented by James is not guaranteed to get the correct results, especially if the class in question can be found in multiple classloaders that James searches. I think that there is no way to determine with certainty which classloader loaded the class in question given its name (the class' name). AFAIK, only the name of the class is available in StackTraceElement, not the actual class.
There are ways to alleviate this problem. See the logback project,
and in particular http://jira.qos.ch/browse/LBGENERAL-23 for more details.
williamlouth.wordpress.com is a new blog.
I am just preparing the entry but I can tell you that there is no way of doing this from within the Java runtime itself in an efficient and correct manner. You have to go native. But at least it is possible and it can work with Java 1.2+ runtimes and on all major OS platforms.
StackTraceElement was a design mistake especially as developers are already so comfortable with java.lang.reflect.Method.
By the way I think we need to abandon logging. Sorry.
It has served it purposes but we need to move beyond the dark ages and consider having a proper diagnostics API as well as dynamic runtime configuration management model that can describe the state pertinent to many different software execution aspects.
Dumping stack traces to a log file is simply wasteful and unproductive when the light shines.
James, great work yet again.
Love the lateral on that one. Many times I have hunted an issue where this would have helped.
nice.
Post a Comment