Venturous Logging Solution for ABAP OO: Vesna AOP Demo Case

[Former Member]

Quite recently I've been impressed by a blog post by Eric Petersen, describing a better logging solution for ABAP OO. However, while this approach definitely addresses quantitative part of the problem, in terms of squashing the code a bit, I could not help thinking that this is something like buying a better porcelain in a diarrhea case. It will simply not cure the illness, no matter how hard you try.

So, what's the cure then?

The first and most important question is, when writing an application, any application - are we really interested in logging? Yes, logging is something we must take care of at some point, just like authorization checks, possibly also tracing and lots of other stuff, but is this really supposed to be a concern of mine as an application author? Does the log handling really need to clutter my shiny application code?

The keyword is Concern

...Or, more precisely, separation of concerns. After all, logging presents such a brilliant example of a cross-cutting concern which bubbles all around the place. In fact, we can never be sure that we're not going to need logging at any specific point in code later, some time in the future. Neither can we predict that we might need to log some more stuff in certain cases while some places we have decided earlier in the project to do the logging are not really needed any more and could be cleaned up.

So what do we do? Refactor and refactor to death? Well, I don't know how about you but I hate such menial manual jobs, not to speak of the likelihood to do something wrong and be forced to come back to the same place in the code again and again. That's no fun.

C'mon, show me the solution!

Enough small talk. Besides, the RIGHT logging solution is not rocket science and only requires a tiny bit of AOP:

Yes? That ABAP does not support AOP? Maybe it does not, maybe it does... It depends mostly if you have Vesna Framework installed in your NetWeaver system (which needs to be at least 7.02 or higher).

You can download the demo source code attached to this blog post and see how you can get rid of logging code from your application altogether and yet, log anything you want, anywhere you want. Moreover, your decisions do not have to be final, neither you are bound to any specific implementation of the logger. Does it sound like a fairly tale? A good one, possibly? But you may wake up. Really. Vesna AOP does give you all this, and much more.

Download & Install

Don't just read. Try it. If you see the code in action and feel it, you will immediately embrace the power of an AOP programming model and it will give you wings.

The installation of the demo report is actually a breeze. I presume you'll be using SE80 rather than ADT. If you use ADT, you'll find it no problem to adapt the instruction below.

1. Download all files attached to this blog post.
2. Install them as follows:

Action	Image
Create a local class ZLOGGER. This will be our emulation of the logger wrapper implementation. In your productive application you'd use something more functional, like e.g. a BAL log wrapper proposed by Eric Petersen in his blog. Just accept default options and save it in $TMP.
Switch to source-code based edytor.
Copy-paste the source code from the appropriate section of the CLASSES.txt attachment to this blog and activate the class.
Repeat the same operations for the class ZLOG_ASPECT
...and for the class ZDEMO_APPLICATION
Finally, create report ZVESNA_AOP_LOG
Default options will do just fine. Confirm and save in $TMP.
Copy-paste the contents of the ZVESNA_AOP_LOG.txt source code file and activate the report.

All right, so what am I looking at?

What you have in front of you at this point is a simple AOP application, a small tribute to Mr. Masataka Taketsuru, the creator of Yoichi whisky brand, since 1940 known as Nikka. Personally, I'm not particularly fond of modern trends to die as virgin as you can, therefore I greatly appreciate the efforts of great masters of humanity to bring some colour to life. The small AOP app in front of you allows you to evaluate approximate distance in days between a chosen brand of whisky and reference brand which has been set to Yoichi, 1934 (it's just my personal taste, no philosophy behind it).

Btw: the appreciation for Japanese whisky appears seems to grow with time: Hochprozentige Rangliste: Der beste Whisky der Welt - Aus aller Welt - Panorama - Handelsblatt.

But we're here to see some nice and good logging, right? So let's get down to it.

As soon as you run the application you will see an output similar to this:

Application returned:
Yamazaki is 4018 days older than reference brand Yoichi.

Log output:
20.10.2014 21:30:11,5160000: Starting whisky age evaluation app...
20.10.2014 21:30:11,7510000: About to evaluate Yamazaki dated 01.01.1923.
20.10.2014 21:30:11,7510000: Evaluation result for Yamazaki: Yamazaki is 4018 days older than reference brand Yoichi.
20.10.2014 21:30:11,7510000: Whisky evaluation app finished.

Now, what's so special about it?

Logging AOP style

If you take a look at the actual application code of the class ZDEMO_APPLICATION you'll see no trace of logging. Nowehere. There are no traces of any logger bindings. So how come that we do have some logger entries (marked green in the listing above) somewhere right in the middle of the application?

The answer is AOP configuration

In the upper part of the demo app screen, when you run it, you'll see Vesna config for the application. Please take a closer look at the part marked blue:

<?xml version="1.0" encoding="UTF-8" ?>

<beans xmlns="http://www.vesnaframework.org" xmlns:aop="http://www.vesnaframework.org/schema/aop">

  <bean id="application" class="ZDEMO_APPLICATION">

    <!-- Date established: -->

    <constructor-arg name="REFERENCE_DATE" value="1934-01-01" />

    <!-- Reference whisky brand: -->

    <constructor-arg name="REFERENCE_NAME" value="Yoichi" />

  </bean>

  <bean id="logAspect" class="ZLOG_ASPECT" >

    <constructor-arg name="LOGGER" ref="logger" />

  </bean>

  <aop:config autoproxy-mode="default">

    <aop:aspect ref="logAspect">

      <aop:around pointcut="execution(*)" method="PROCESS"/>

    </aop:aspect>

  </aop:config>

</beans>

What you're looking at is aspect weaving configuration, instructing our tiny Vesna app that it needs an around advice for every method call since pointcut expression is set to wildcard (*). Also, it tells Vesna framework that the advice is implemented by the method PROCESS of the bean referenced to as logAspect. If you're unfamiliar with AO terms, please consult the documentation for any aspect-enabled language. Java Spring documentation will do for that purpose.

How does it work?

Well, really simple, in fact. Vesna Framework uses advanced proxying mechanism that allows for runtime aspect weaving, based upon defined pointcuts. This mechanism is very similar to what is being used in other AOP-enabled evironments.

Ultimate separation of concerns

I might have resisted from this boisterous heading for this paragraph but it was too tempting, really... Since AOP really does give you exactly what you'd wish for your application: being able to inject the logging anywhere you'd want, without changing a single line of your code.

The logging functionality itself is encapsulated in the class ZLOG_ASPECT. Needless to say, you can use more aspects calling specialized logs for various functional contexts in your application. Logging aspect uses logger bean, encapsulating actual log wrapper of some kind.

Since our aspect is of an around kind, its signature of the logging method PROCESS must contain at least the reference to the join point of type ref to /ARCONA1/PROCEEDING_JOIN_POINT. The parameter name is meaningless. This parameter allows the aspect to make a decision to pass the call further down the call chain, by the means of using the PROCEED( ) method, or not. In our logging case we don't want to interfere with application logic itself so we'll call that.

Apart from that, the signature of the ZLOG_ASPECT->PROCESS( ) method may contain also same parameters as captured method. In our case these are: DATE, NAME and RESULT. In such a way we can easily use original paremetr values of the method call at runtime, e.g. to do better logging.

There's more than just logging to AOP

I hope I got you interested... In Japan's whisky heritage! :wink:

But - as regards AOP - the logging is just the beginning. Do you think that changing the parameters of a method's call on-the-fly could be fun? Then stay tuned to the next part of the Vesna blog!

The small print

Needless to say, all whisky brand names used in this blog belong to their proprietary holders. The author of this blog is in no way associated with any of them. However, let the mastery of Japanese whisky creators never be forgotten, howgh.