AJS_Logger Motivation

Instrumenting Method Calls

One of the oft-cited applications of Aspect-Oriented Programming is the logging of method-calls in order to trace call-chains through an application, and to study the way in which critical objects change as an application's code executes. The traditional approach to logging has obvious disadvantages, and this page explores these in the context of JavaScript, thus establishing the motivation behind AJS_Logger, which is a client of the AJS object that enables method-call logging without the traditional drawbacks.

Contents Instrumenting Method Calls
Clutter
Conditional Comments
Using a Logging-Object
AJS_Logger

Clutter

The most-primitive approach to logging method-calls in JavaScript requires the insertion of explicit calls to logging function into those methods whose execution one wishes to record. Example 1 demonstrates this (using the console object, and it is clear that this suffers from three problems:

  • Inserting such calls clutters the code, which harms readability and therefore comprehension.
  • If we log a set of methods, we must log each method directly and explicitly. If ten methods of a given object require logging, we must insert logging-instrumentation ten times over, once for each method. We cannot simply express the desire to log all methods of a given object with a single directive, which renders the insertion of logging instrumentation tedious and time-consuming.
  • We must state how the logging functionality should be implemented. Ideally, we would use a scheme akin to Regular Expressions where we state what to log without having to worry about how the logging is actually performed.
  • The approach is terribly inflexible. It provides no simple way to disable logging instrumentation selectively on those occasions when we wish to study only a small portion of the application's execution. Nor is it easy to turn logging off completely when we do not need it or when the time comes to deploy the application.

One approach to the third problem is to comment-out the logging statements, but this again is tedious and time consuming, as each statement must be commented-out individually. Moreover, it still leaves us with the clutter-factor; now our functions are weighed down with superfluous comments that serve no central purpose.

An alternative therefore is to delete the logging instrumentation completely before deployment, but this is adds yet more time-consuming tedium, and we risk removing instrumentation that we will need again in future.


 // -- Example 1 --------------------------------------------------------------

 function someFunc (SomeNum, SomeString, SomeBoolean)
    {
    console.log ("someFunc entered. SomeNum: "     + SomeNum
                                + " SomeString: "  + SomeString
                                + " SomeBoolean: " + SomeBoolean);

    //
    // Normal processing...
    //

    console.log ("someFunc returned. Return value: " + Value);

    return Value;

    }
      

Conditional Comments

One solution to these problems is to use some form of special-comment scheme, and to rely on a pre-processor to elide the logging instrumentation. Example 2 demonstrates this, where the code between the REMOVE_ME_START and REMOVE_ME_END comments is the same as in Example 1, but where those comments act as a signal to a pre-processor that they and the code they enclose should be removed. While this allows us to disable the logging-code at a stroke, it is an all-or-nothing approach – logging is turned on or off, with no selectivity.

To address this, we could refine the commenting scheme to qualify different REMOVE_ME_START-REMOVE_ME_END blocks in some way, but this requires extra thought in terms of devising a set of qualifiers, and it still leaves us with the problem of clutter. Imagine the situation if you adopt this approach in conjunction with run-time argument checking, which you also implement by means of explicit conditional logic (instead of using something like AJS_Validator). This approach could cause a relatively-simple function to become bloated beyond recognition with a mass of instrumentation.

The fact is that such special-comment schemes are the equivalent of preprocessor-macros in languages like C/C++ and, as Bjarne Stroustroup (its creator) once-observed: 'Almost every macro demonstrates a flaw in the programming language, the program, or the programmer' [The C++ Programming Language - Third Edition].


 // -- Example 2 --------------------------------------------------------------

 function someFunc (SomeNum, SomeString, SomeBoolean)
    {
    // REMOVE_ME_START

    console.log ("someFunc entered. SomeNum: " + SomeNum
               + " SomeString: "               + SomeString
               + " SomeBoolean: "              + SomeBoolean);

    // REMOVE_ME_END

    //
    // Normal processing...
    //

    // REMOVE_ME_START

    console.log ("someFunc returned. Return value: " + Value);

    // REMOVE_ME_END

    return Value;

    }
      

Using a Logging-Object

A more-sophisticated alternative to conditional comments is to call the methods of a logging object from within the functions that we wish to instrument, rather than invoking the log-writing mechanism directly at those points.

Example 3 demonstrates this, where we assume the existence of an object called 'Logger' that provides two methods called onMethodEntry and onMethodExit. By calling these methods at the beginning and end respectively of a call to a function, passing the name of that function along with the arguments array or the value that the function returns, we lift the actual log-writing technicalities out of the code under consideration.

This has the advantage of reducing the clutter-factor, and it allows us to turn off the logging functionality by putting extra logic into the logger object. We can even enable/disable logging selectively, if need be, by testing the name of the method that invokes the logger's services. However, it does not eliminate the clutter completely, and we must still apply logging by editing the application's code on a per-function basis – those damaging time- and tedium-factors remain.

Furthermore, this scheme has a palpable disadvantage from which preprocessor-based schemes are free. While we can disable logging globally from within the logger object, each function that possesses calls to the logger will still execute those calls (wherein nothing will happen), and those executions take time and waste CPU cycles. Moreover, when transmitting JavaScript code across a network, the code that implements those calls remains in place redundantly but consumes bandwidth during transmission.


 // -- Example 3 --------------------------------------------------------------

 var Logger =                                          // Skeletal definition of Logger object.
    {
    onMethodEntry : function (FuncName, Args)      {  },
    onMethodExit  : function (FuncName, RtnValue)  {  }
    };

  /*

  .
  .
  .

  */

 function someFunc (SomeNum, SomeString, SomeBoolean)
    {
    Logger.onMethodEntry ("someFunc", arguments);

    //
    // Normal processing...
    //

    Logger.onMethodExit  ("someFunc", Value);

    return Value;

    }
      

AJS_Logger

However, all the concerns detailed above can be addressed completely and decisively by using method-call interception. In a scheme that mirrors the paradigm that AJS_Validator observes, we can create an object that nominates another object, and which nominates those methods of that object to which logging instrumentation must be applied.

We can then pass that 'logging-descriptor' to a logging manager, which can use the AJS object to apply a prefix and suffix to each of the methods described in the descriptor. Those affixes can implement whatever logging functionality we desire, entirely transparently from the point of view of the logged-method and its callers, and this approach has the following advantages:

  • It leaves logged methods free of extraneous clutter, thus improving readability and comprehension.
  • It does not leave redundant code in the deployed version of the application.
  • It obviates the need for conditional comments, and thus obviates the need for an extra pre-processing stage.
  • In a manner akin to Regular Expressions, we can state what should be logged, without needing to state explicitly how the logging process should be implemented.
  • Logging can be turned on and off en-masse by a simple call to the logging manager, or it can be enabled and disabled selectively by (un)commenting calls that apply specific logging-directives.
  • Given that the AJS object allows the application of multiple prefixes and suffixes to a given method, we can combine logging functionality with the use of both AJS_Validator and AJS_ODL transparently, where application of either technique occurs in ignorance of the other.

This then is the rationale behind AJS_Logger. It implements fully the scheme described above and supports a number of extra features that the method-call-interception approach permits. It does not require that you understand the AJS object in any depth, and like AJS_Validator you pay only for that which you use.

To learn how to use AJS_Logger, go now to the user guide.