...
Java Logging versus Aspect Oriented Programming (AOP) Approach
There are type two types of logging embeded in the Tuscany runtime: explicit and implicit. The explicit logging is implimented implemented by the Java 2 SE core logging facilities such as java.util.logging.Logger. This is the logging that many Java programmers are familiar with, and the logging requires calls to the Logger programming interface. Throughout the Tuscany code base you see call calls to this facility such as this call in Tuscany org.apache.tuscany.sca.node.launcher.NodeLauncher.
| Code Block |
|---|
| title | Java Logging in Tuscany |
|---|
| borderStyle | solid |
|---|
|
logger.info("Apache Tuscany SCA Node is starting...");
|
...
| Code Block |
|---|
| title | Java Logging Output |
|---|
| borderStyle | solid |
|---|
|
INFO: Apache Tuscany SCA Node is starting...
|
...
| Code Block |
|---|
| title | Java AOP Agent |
|---|
| borderStyle | solid |
|---|
|
java -javaagent:"<path to aspectjweaver.jar>" calculator.CalculatorClient
|
...
| Code Block |
|---|
| title | Tuscany AOP Output |
|---|
| borderStyle | solid |
|---|
|
Running org.apache.tuscany.sca.aspectj.TracingTestCase
Timing Around timedSection jp=call(void java.util.logging.Logger.info(String))
Oct 21, 2008 9:26:36 AM org.apache.tuscany.sca.aspectj.TracingTestCase info_aroundBody0
Timing Around timedSection Roundtrip is 32ms for jp.getSignature=void java.util.logging.Logger.info(String)
|
...
| Code Block |
|---|
| title | Example Aspect |
|---|
| borderStyle | solid |
|---|
|
@Aspect
public class LoggingAspect {
@Pointcut("call(* org.apache.tuscany.sca..*(..)) && (!within(org.apache.tuscany.sca.aspectj.*Aspect))")
public void anyMethodCall() {
}
@Before("anyMethodCall()")
public void before(JoinPoint jp) {
System.out.println("Logging Before anyMethodCall jp.getSignature=" + jp.getSignature());
}
}
|
...
Following the approach of AspectJ, Tuscany provide provides two concrete aspects for logging and tracing. org.apache.tuscany.sca.aspectj.LoggingAspect provides logging for methods, constructors, and static initializers in Tuscany. org.apache.tuscany.sca.aspectj.SimpleTracingAspect provide tracing into user methods, constructors, and static initializers. Both provide detailed information when an Exception or Throwable is thrown by the Tuscany runtime or user SCA program.
Both LoggingAspect and SimpleTracingAspect are run by naming the AspectJ runtime agent aspectjweaver.jar at launch. This is shown in the command line example above, and an example is provided in launcher.bat int he in the tracing-aspectj module.
The runtime configuration file aop.xml has references to these aspects. Uncomment one or both of these in aop.xml to run with this logging enabled. Following is an example logging run with the verbose weaver option specified. Note the verbose output of class names, build times, etc. The logging statements too are quite verbose stating the name of the join point, the point cut, and various signatures and arguments.
| Code Block |
|---|
| title | Example Logging in Tuscany |
|---|
| borderStyle | solid |
|---|
|
[INFO] Configured Artifact: org.aspectj:aspectjweaver:1.6.1:jar
[INFO] Copying aspectjweaver-1.6.1.jar to E:\t\java\sca\modules\tracing-aspectj\target\dependency\aspectjweaver-1.6.1.jar
[AppClassLoader@92e78c] info AspectJ Weaver Version 1.6.1 built on Thursday Jul 3, 2008 at 18:35:41 GMT
[AppClassLoader@92e78c] info register classloader sun.misc.Launcher$AppClassLoader@92e78c
[AppClassLoader@92e78c] info using configuration /E:/t/java/sca/modules/tracing-aspectj/target/classes/META-INF/aop.xml
[AppClassLoader@92e78c] info register aspect org.apache.tuscany.sca.aspectj.LoggingAspect
[AppClassLoader@92e78c] info define aspect org.apache.tuscany.sca.aspectj.UserTimingAspect
-------------------------------------------------------
T E S T S
-------------------------------------------------------
Logging Before anyMethodCall jp.getSignature=SCANodeFactory org.apache.tuscany.sca.node.SCANodeFactory.newInstance()
Logging Before anyConstructor jp.getSignature=org.apache.tuscany.sca.extensibility.ServiceDiscovery()
Logging Before anyConstructor jp.getSignature=org.apache.tuscany.sca.extensibility.ServiceDiscovery.1(ServiceDiscovery, Class)
Logging Before anyConstructor jp.getArgs=[org.apache.tuscany.sca.extensibility.ServiceDiscovery@ceb6dd,
class org.apache.tuscany.sca.node.SCANodeFactory]
Logging Before anyMethodCall jp.getSignature=ServiceDiscoverer org.apache.tuscany.sca.extensibility.ServiceDiscovery.getServiceDiscoverer()
Logging Before anyConstructor jp.getSignature=org.apache.tuscany.sca.extensibility.ContextClassLoaderServiceDiscoverer()
Logging AfterReturning anyMethodCall jp=call(ServiceDiscoverer org.apache.tuscany.sca.extensibility.ServiceDiscovery.getServiceDiscoverer()),
result=org.apache.tuscany.sca.extensibility.ContextClassLoaderServiceDiscoverer@17574b9
Logging Before anyMethodCall jp.getSignature=Set org.apache.tuscany.sca.extensibility.ServiceDiscoverer.discover(String, boolean)
Logging Before anyMethodCall jp.getArgs=[org.apache.tuscany.sca.node.SCANodeFactory, true]
|
...
| Code Block |
|---|
| title | Tuscany AOP Timing Output |
|---|
| borderStyle | solid |
|---|
|
Running org.apache.tuscany.sca.aspectj.TracingTestCase
Timing Around timedSection jp=call(void java.util.logging.Logger.info(String))
Oct 21, 2008 9:26:36 AM org.apache.tuscany.sca.aspectj.TracingTestCase info_aroundBody0
Timing Around timedSection Roundtrip is 32ms for jp.getSignature=void java.util.logging.Logger.info(String)
|
Unlike LoggingAspect and SimpleTracingAspect, the pointcut for UserTimingAspect is settable at runtime via the aop.xml runtimg runtime configuration file. Look for the UserTimingAspect name, and note the expression in the pointcut element. You may change the name of expression to any valid AspectJ pointcut expression. Here calls to any Logger.info methods, regardless of arguments or return types are logged. For instance you may change this to "call( * calculator.CalculatorServiceImpl.multiply(..))" to time calls in your SCA application.
| Code Block |
|---|
| title | Dynamic PointCut for UserTimingAspect |
|---|
| borderStyle | solid |
|---|
|
<concrete-aspect name="org.apache.tuscany.sca.aspectj.UserTimingAspect"
extends="org.apache.tuscany.sca.aspectj.TimingAspect"
precedence="org.apache.tuscany.sca.aspectj.UserTimingAspect, *">
<pointcut name="timedCall"
expression="call(* java.util.logging.Logger.info(..))"/>
</concrete-aspect>
|
...