program instrumentation 专栏收录该内容
11 篇文章 0 订阅

Aspectj implements the functionality also using the asm tool.

As it provides neat aspect grammars and is supported extensively by the community, I would like to switch to it. Better than Btrace , right?

Now let us see the details （shown later）.

Basically， there are two steps:

1) make aspect agent jar with the command ajc.

2) run it with aspectjweaver.jar as the javaagent, and with the aspectjrt.jar and agent jar as the classpath (also the path of the main class).

you can unzip the aspect agent jar with the command "jar xvf the aspect agent jar" and modify the aop-ajc.xml to modify options.

then use  the command "jar cvfm time.jar META-INF/MANIFEST.MF META-INF/aop-ajc.xml Simple.class"  to repack the aspect agent jar.

Detailed commands are attached as a screenshot.

[copy from others' blog]

Today I'm going to show a basic AspectJ load-time weaving setup and which configuration options can be used to debug a scenario that just doesn't seem to be working as expected.

Here is a trivial application:

public class Simple {

public static void main(String[]argv) {
countFast(1000);
countSlow(1000);
}

public static void countSlow(int value) {
count(value,5);
}

public static void countFast(int value) {
count(value,0);
}

private static void count(int value, int delay) {
for (int i=0;i<value;i++) {
try {Thread.sleep(delay);} catch (Exception e) {}
}
}
}


Awesome eh? Rather contrived, but I've introduced a delay down one of the execution paths so I can do some LTW profiling and pinpoint the problematic code.

Pure java so it can be compiled and run normally:
javac Simple.java
java Simple

Now to build a suitable profiling aspect.
aspect WhereDoesTheTimeGo {

pointcut methodsOfInterest(): execution(* *(..)) &&
!within(WhereDoesTheTimeGo);

private int nesting = 0;

Object around(): methodsOfInterest() {
nesting++;
long stime=System.currentTimeMillis();
Object o = proceed();
long etime=System.currentTimeMillis();
nesting--;
StringBuilder info = new StringBuilder();
for (int i=0;i<nesting;i++) {
info.append("  ");
}
info.append(thisJoinPoint+" took "+(etime-stime)+"ms");
System.out.println(info.toString());
return o;
}
}


This aspect could be compiled and woven at source time, but it is more likely something to only be used occasionally when the code is run. To include at source time:


ajc WhereDoesTheTimeGo.java Simple.java
java Simple

execution(void Simple.count(int, int)) took 2ms
execution(void Simple.countFast(int)) took 4ms
execution(void Simple.count(int, int)) took 5049ms
execution(void Simple.countSlow(int)) took 5049ms
execution(void Simple.main(String[])) took 5054ms


But I want to show load-time weaving. Now load time weaving needs me to do two things:

- launch the VM with the AspectJ agent registered
- provide an xml file to configure the weaver

The AspectJ agent is a simple JVMTI agent that can get involved in the class loading process and weave any types before they are defined in the VM. In either source compilation or binary weaving, the AspectJ compiler knows the set of aspects involved, either by being given the source for them or the jars containing them. In a load time weaving setup they could be anywhere on the classpath and so to save a very costly scan of all the classpath contents, it relies on an xml config file to name the aspects it should use. There are a lot of potential options that can be specified in the xml file, but a minimal one suitable for my needs here is:
<aspectj>
<aspects>
<aspect name="WhereDoesTheTimeGo"/>
</aspects>
</aspectj>


It just defines one aspect called WhereDoesTheTimeGo (the weaver will expect to find the class for this type on the classpath). In fact for a simple case like this, the compiler can produce suitable xml just by specifying a flag at compile time. So now I'll use that flag and build the aspect into a reusable aspect library jar.
ajc WhereDoesTheTimeGo.java -outxml -outjar timing.jar


The timing.jar will now contain an aop-ajc.xml (in a META-INF directory) and the class file for the compiled aspect.

jar -tvf timing.jar
55 Wed Feb 25 22:06:30 GMT 2009 META-INF/MANIFEST.MF
5149 Wed Feb 25 22:06:32 GMT 2009 WhereDoesTheTimeGo.class
85 Wed Feb 25 22:06:32 GMT 2009 META-INF/aop-ajc.xml


The one generated by -outxml is called META-INF/aop-ajc.xml (being in the META-INF folder is important!). That name is chosen for the generated one so it does not clash with (or overwrite) any aop.xml I might be working on separately that contains more advanced options. The agent is going to merge together the contents of all the xml config files it finds and use the combination to configure the weaver.

It is ready to go, I just need to launch the VM with the AspectJ agent, see the -javaagent option here:


java -javaagent:<pathToAspectj>/lib/aspectjweaver.jar
-classpath "code;timing.jar;<pathToAspectj>/lib/aspectjrt.jar" Simple

execution(void Simple.count(int, int)) took 1ms
execution(void Simple.countFast(int)) took 6ms
execution(void Simple.count(int, int)) took 5114ms
execution(void Simple.countSlow(int)) took 5114ms
execution(void Simple.main(String[])) took 5121ms


The Simple class is woven as the VM loads it. The classpath requires: my Simple class (now in the code directory), the aspect library (containing the aspect .class and the xml) and finally the aspectj runtime jar. Running without either the agent specified or the aspect library on the classpath will execute Simple program normally.

Now that's a nice simple scenario, but what about when things aren't going so well... What on earth should I do if just don't see the aspect weaving anything? How do I know what is going on at load time?

To explore what the system is doing, I need to expand my aop-ajc.xml file. Firstly I just want to know the basics about what AspectJ is up to. The xml file can have a weaver section where various options can be configured - many of which match the options that can be specified when calling the compiler on the command line. AspectJ will merge together any suitable aop xml files it discovers on the classpath in order to define the behaviour of a weaver, so I can either modify my existing aop-ajc.xml inside the jar or create another one just for trying out some options.

For now I will modify the existing one - so I extract it from the jar, update it and pack it back into the jar. Here is the new one:
<aspectj>
<aspects>
<aspect name="WhereDoesTheTimeGo"/>
</aspects>
<weaver options="-verbose"/>
</aspectj>


I've turned on verbose mode for the weaver. Now on running it I will see:

[AppClassLoader@9fbe93] info AspectJ Weaver Version DEVELOPMENT
built on Wednesday Feb 25, 2009 at 21:17:03 GMT
[AppClassLoader@9fbe93] info register classloader sun.misc.Launcher$AppClassLoader@9fbe93 [AppClassLoader@9fbe93] info using configuration file:/C:/blog/timing.jar!/META-INF/aop-ajc.xml [AppClassLoader@9fbe93] info register aspect WhereDoesTheTimeGo [AppClassLoader@9fbe93] info processing reweavable type WhereDoesTheTimeGo: WhereDoesTheTimeGo.java execution(void Simple.count(int, int)) took 0ms execution(void Simple.countFast(int)) took 3ms execution(void Simple.count(int, int)) took 5003ms execution(void Simple.countSlow(int)) took 5003ms execution(void Simple.main(String[])) took 5007ms  What does it all mean? Firstly all weaver messages are prefixed with the classloader the weaver instance is attached to - in a multi classloader setup this can really help me understand the mixed up verbose output. The first message gives the version number of the weaver being used then it tells me the xml configuration file that will be used for this weaver ( file:/C:/blog/timing.jar!/META-INF/aop-ajc.xml) and then the messages tell me which aspects have been defined based on that configuration. Running with the verbose option can at least tell me if the weaver is being created and that the agent setup is correct. But it still will not tell me if any weaving is occurring. For that I would use the additional option ' -showWeaveInfo' exactly the same as I would on the command line. <aspectj> <aspects> <aspect name="WhereDoesTheTimeGo"/> </aspects> <weaver options="-verbose -showWeaveInfo"/> </aspectj>   [AppClassLoader@9fbe93] info AspectJ Weaver Version DEVELOPMENT built on Wednesday Feb 25, 2009 at 21:17:03 GMT [AppClassLoader@9fbe93] info register classloader sun.misc.Launcher$AppClassLoader@9fbe93
file:/C:/blog/timing.jar!/META-INF/aop-ajc.xml
'method-execution(void Simple.main(java.lang.String[]))'
from 'WhereDoesTheTimeGo' (WhereDoesTheTimeGo.java:7)
'method-execution(void Simple.countSlow(int))'
from 'WhereDoesTheTimeGo' (WhereDoesTheTimeGo.java:7)
'method-execution(void Simple.countFast(int))'
from 'WhereDoesTheTimeGo' (WhereDoesTheTimeGo.java:7)
'method-execution(void Simple.count(int, int))'
from 'WhereDoesTheTimeGo' (WhereDoesTheTimeGo.java:7)
[AppClassLoader@9fbe93] info processing reweavable type WhereDoesTheTimeGo:
WhereDoesTheTimeGo.java
execution(void Simple.count(int, int)) took 1ms
execution(void Simple.countFast(int)) took 3ms
execution(void Simple.count(int, int)) took 5005ms
execution(void Simple.countSlow(int)) took 5005ms
execution(void Simple.main(String[])) took 5016ms


See the new messages prefixed 'weaveinfo' - just as I would expect to see on the command line if weaving via ajc.

The weaver section of the xml configuration can also define which types should be included in or excluded from weaving. Although pointcuts can limit where aspects apply, it is sometimes useful to write these specifications in the xml configuration. As a simple example I can exclude my Simple class from being woven:
<aspectj>
<aspects>
<aspect name="WhereDoesTheTimeGo"/>
</aspects>
<weaver options="-verbose -showWeaveInfo">
<exclude within="Simple">
</weaver>
</aspectj>


Running with that configuration, I can see no weaving messages. Although it might have been nice for the weaver to tell me it excluded my class... and that brings us to the '-debug' option. If it looked like my code was not getting woven even though the right aspects were being defined - I would use the debug option:

<aspectj>
<aspects>
<aspect name="WhereDoesTheTimeGo"/>
</aspects>
<weaver options="-debug">
<exclude within="Simple">
</weaver>
</aspectj>


Now when I run it (notice I've removed -verbose and -showWeaveInfo to limit the output):



This message indicates the load time weaving infrastructure chose not to weave  Simple - and that is due to the include/exclude constraints specified. Finally I will remove my exclude section from the xml and re-run:


[AppClassLoader@9fbe93] debug generating class 'Simple$AjcClosure1' [AppClassLoader@9fbe93] debug generating class 'Simple$AjcClosure3'
[AppClassLoader@9fbe93] debug generating class 'Simple$AjcClosure5' [AppClassLoader@9fbe93] debug generating class 'Simple$AjcClosure7'
[AppClassLoader@9fbe93] debug cannot weave 'org.aspectj.runtime.reflect.SignatureImpl$Cache' [AppClassLoader@9fbe93] debug cannot weave 'org.aspectj.runtime.reflect.JoinPointImpl$StaticPartImpl'
execution(void Simple.count(int, int)) took 1ms
execution(void Simple.countFast(int)) took 5ms
execution(void Simple.count(int, int)) took 5001ms
execution(void Simple.countSlow(int)) took 5002ms
execution(void Simple.main(String[])) took 5008ms


Due to the weaver now actually doing something, a few more types got loaded during the application run. The debug output is telling me important information:

[AppClassLoader@9fbe93] debug cannot weave 'org.aspectj.lang.ProceedingJoinPoint'
'cannot weave' - indicates the type is in a package for which weaving is forbidden. By default org.aspectj, java. and javax. are all forbidden (so I don't need to exclude them myself). The latter two packages can be woven by the use of extra options in the weaver section.

[AppClassLoader@9fbe93] debug weaving 'Simple'
- the weaver got a chance to process the specified type. IT DOES NOT MEAN THE WEAVER ACTUALLY CHANGED IT (I ought to change that message really, to indicate this). To also see if the type was modified during weaving, I would use -showWeaveInfo in addition to -debug

Armed with those 3 options I can investigate any basic wierdness I see when trying to get started with load time weaving. Even more advanced options can involve turning on weaver trace or dumping the bytecode (before and after it is woven) - but those tend to be used when an AspectJ compiler developer is asking for diagnostics.

- load time weaving configuration documentation: http://www.eclipse.org/aspectj/doc/released/devguide/ltw-configuration.html
- enabling weaving of java. and javax. packages: https://bugs.eclipse.org/bugs/show_bug.cgi?id=149261#c11

• 0
点赞
• 0
评论
• 0
收藏
• 一键三连
• 扫一扫，分享海报

09-11 1729
09-11 336

06-14 2万+
06-29 3604
02-26 161
03-06 4274
06-09 475
06-19 2454
01-09 48