Main target audience of a metracer are meant to be enterprise Java applications – metracer must enhance logging of such applications. As such I’ve tried to adopt metracer to a production level Java EE application which runs under WildFly AS. Speaking in terms of RPG games – tons of experience was earned :-). Results of my experiments are below.
I’ve decided to test metracer on Odin Service Automation (OSA for brevity) – large Jave EE application. Following were the test conditions:
- Linux CentOS 6 x86_64
- WildFly AS 8.2 in a standalone mode
- product (OSA) contains one static deployment module and couple of top-level deployment units (.ear + .war)
- metracer was meant to deal with unannotated code so I’ve decided to use a ‘=pattern’ option described here
It took me several days of struggling but I finally did it – metracer was succeeded in adding tracing to methods of an enterprise Java EE application! Below are problems which arose during experiments and how they were solved.
|1||Supplying -javaagent option to JVM started by AS launch script||Decided to put -javaagent into JAVA_OPTS variable of standalone.sh of WildFly for simplicity.
Also it made for me sense to add -verbose:class to JAVA_OPTS – eases troubleshooting of instrumentation
|2||Error during AS startup:
Caused by: java.lang.ClassNotFoundException: javassist.NotFoundException
|javassist.jar is missing on application server.
N.B.: actually javassist is bundled with WildFly but at the moment of bootstraping it’s missing
|Decided to put javassist right into metracer.jar – created an uberjar via maven-shade-plugin|
|3||Error during AS startup:
Error opening zip file or JAR manifest missing : <path-to-metracer.jar>
|AS is running under ‘jboss’ user which lacks permissions to metracer.jar. Alas, JVM doesn’t report precise error message, so one should guess. I’ve personally ought to strace program to find out the root cause||Put metracer.jar on a path available to ‘jboss’ user.
Easy way to check:
#sudo -u jboss jar tf <path-to-metracer.jar
|4||Errors related to code verification, e.g.:
java.lang.VerifyError: StackMapTable error: bad offset
|Since Java 7 Oracle introduced a ‘Stack Map Frames’ notion within compiled class files (version 51 of classfile). These stackmaps in theory must increase speed of code verification. As a side effect they greatly embarrass code instrumentation by javassist or ASM means (some interesting thoughts).
Seems approach to code instrumentation implemented within metracer (we insert prolog and epilog entries into traced methods) sometimes breaks code validation. Also there are tons of similar bug in Javassist bugtracker – link.
|1) In Java 7 this could be workarounded by specifying -XX:-UseSplitVerifier option to JVM (see here). This will disable strict code checker and let the things to go on
2) In Java 8 -XX:-UseSplitVerifier is not working. The only option is to change approach of code instrumentation – since metracer 1.0.4 a wrapper methods are created (which contains tracing logic) instead of code injection into existing methods
|5||Errors during bootstrap of deployment units (.ear):
|Due to use of dedicated class loaders in WildFly the latter refuses to discover classes within metracer.jar when using patched classes from deployment units (.ear)||As a workaround I was forced to create a new WildFly metracer module with metracer.jar included within. I’ve then marked this module as a global one. Also due to presence of a static module in a product I was also forced to put metracer module to the dependency list of this static module.
Such manipulations seems to be very heavy and cumbersome. Need to somehow get rid of injection of TracingStateThreadLocal into code of classes. This way there will be no need for any external dependencies
|6||Error during services bootstrap:
java.lang.NoClassDefFoundError: Could not initialize class java.lang.invoke.CallSite
|Seems happens due to class loaders isolation – we load CallSite too early during instrumentation in a different class loader and thus breaking a normal flow||Hardcoded to skip instrumentation for all classes which start from java.lang. Need to think about configurable list of a “blacklisted” classes|
|7||Hangup of an instrumented method from OSA||In OSA we establish stdout / stderr redirection to a file. However during instrumentation we inject calls to System.out.println right into the method which does such redirection! As such we got an infinite recursion||Need to change the way we report entry / exit tags – System.out.println is too naive and not suitable for a production level applications. Such reporting must be configurable somehow|
|8||Lots of error like:
Failed to add tracing to method <method-name>: javassist.CannotCompileException: [source error] javassist.NotFoundException: <some-class-name>
|Seems due to use of difference class loaders we fail to discover some of the classes during instrumentation||Need to check and revise code which loads classes to javassist.ClassPool. At least documentation to javassist says that we must somehow handle class loaders isolation in AS servers like WildFly|
Despite listed problems even such naive implementation of metracer proved its viability. Based on experiments new version 1.0.4 of metracer was prepared which solves some of the problems: svn co https://github.com/kocherovms/develorium.com/tags/metracer_1.0.4/metracer.
As a conclusion following directions of further development are designated:
- need to get rid of dependency on TracingStateThreadLocal within patched methods
- need support for classes blacklisting, e.g. no need to touch classes from java.lang, since it may break crucial parts of a whole JVM
- need configurable way of reporting of entry / exit tags – present way of doing this via System.out.println is far from an enterprise level
- need to fix problem when some of the method could be not instrumented due to ClassNotFoundException (class loaders isolation)
- increased memory footprint due almost all classes are put into javassist.ClassPool