If you have multiple versions of your code in production, it is extremely useful for the log to include the version of the classes when producing a stacktrace, otherwise it is very hard to match the lines in the stacktrace with the lines of the source code (sidenote: there is an optimization in the Sun JVM where – if an exception is thrown “too much” – the JVM stops providing stacktrace – see this article about it and to learn how to disable this feature).
If you are using Log4J as your logging framework, with a little magic you can turn the following stacktrace:
17:47:40,208 ERROR [main] [TestLog4jExtendedStacktrace] An exception has occurred! java.lang.IllegalArgumentException: Test exception at ...Callee.called(TestLog4jExtendedStacktrace.java:144) at ...Caller.call(TestLog4jExtendedStacktrace.java:136) ...
Into this (note the class versions at the bottom):
java.lang.IllegalArgumentException: Test exception at ...Callee.called(TestLog4jExtendedStacktrace.java:144) at ...Caller.call(TestLog4jExtendedStacktrace.java:136) ... Callee: $Revision: 56 $ Caller: $Revision: 56 $
The main mechanism is as follows:
- Each class contains a static String field called “VCS_VERSION”. This field is set (trough the magic keyword substitution – see the documentation for SVN, CVS) to the last version when the file was committed to your VCS.
- When a stacktrace is sent to the logger, it will look at the classes and if they have the “VCS_VERSION” field, it will output it at the end (it doesn’t annotate the stacktrace itself, because some tools – like IDEs – depend on the stacktrace having a certain format for them to be able to process it – like adding one-click “go-to-line” shortcuts)
As usual, the source can be found in the repository.
Some more implementation details: the current way of modifying the stacktrace is quite hackish (adding a filter and trough reflection modifying the passed in LoggingEvent object). However it has the advantage of being usable without modifying your config files (ie. if you have many config files, but can modify it in only one place in the code, this is a good solution. More “proper” alternatives would be to implement a “wrapper” appender (like AsyncAppender) or a wrapper around Layout, however both of these require you to modify your configuration files.
One response to “Augmenting Log4J stack traces with class versions”
I also had to solve this (be aware of the exact SCM version running on production) for Java projects. My approach was a bit different:
1. I use Maven to build the projects
2. My project has a multi-module structure
3. I use the maven-buildnumber-plugin to write the SCM (SVN in my case) revision in own of Java module's MANIFEST file (details here http://mojo.codehaus.org/buildnumber-maven-plugin/usage.html)
4. I created a page (or a small section in the footer of the application) which shows the version of as read from the manifest file at runtime.
For snapshot versions (on test environments) I show both the maven POM version and SCM revision, while for released versions I only show the POM version (because I use the maven-release-plugin so I have a SCM TAG created for each released version)