How to Log and Analyze a Space-Based Distributed System

---

In Part I of this series of two articles, we examined how to build a simple Jini logging proxy for a JavaSpace. This technique let us log method level information to an output stream allowing us debug and get a better understanding of the flow of objects in and out of the space. For example, if a read operation had been performed where a take was expected, viewing the logging information could make finding these bugs simpler.

The simple Jini logging proxy we developed is a good starting point, but the approach is only viable for testing a single space client.

In this concluding part, we will examine how to build a full-blown Jini service to act as a centralized repository for the logging information, letting us examine method level data from multiple space clients.

JavaSpace Logging Service

In our second model, we retain the LoggingSpace interface (introduced in Part I), but we reimplement the proxy to provide its information to a remote service. To implement this we are going to design the logging service as a Jini Service.

The logging service is going to store the SpaceOperation information in a centralized repository. The repository could be a database, a file, or even another space. For simplicity, we will write the data to a CSV (comma- separated variable) file.

Figure 1 shows the overall structure of the architecture that uses the logging service.

Figure 1. A JavaSpace Logging Service Architecture.

In this second model, the logging proxy will perform two remote calls per JavaSpace method; one to the delegate space and one to the logging service. Obviously making two remote calls will slow down your system's overall performance. However, we only envisage the logging service being used for debugging or during development; that is, the service is not being used on a production system so overhead is acceptable.

Logging Service Interface

With this design in mind, we must first develop the interface for the remote logging service. This is actually quite simple—we just need a logOperation() method that takes a SpaceOperation parameter in the same way we did in Part I in the LocalLoggingProxy. However, in this instance, we define the method in a Remote interface so that later on, when we write the new proxy, it will delegate calls to the remote logging service.

import java.rmi.Remote;

public interface SpaceLogger extends Remote {

    public void logOperation(SpaceOperation op)
        throws RemoteException;
} 

Logging Strategies

Earlier we mentioned that we could use various strategies to store the SpaceOperation data, and for this example we would use a simple CSV file implementation. However, as other strategies exist, it makes sense to define an extra local interface LoggingStrategy to make changing strategies easier in the future.

In our design, we will use delegation to forward the logOperation() request from the SpaceLogger implementation to the appropriate LoggingStrategy. Not only does this simplify writing the SpaceLogger implementation, but it also lets us dynamically load the desired strategy when we start an instance of the logging service.

Here is our interface for LoggingStrategy, which is non-remote, but also defines a logOperation() method:

interface LoggingStrategy {
    public void logOperation(SpaceOperation op);
} 

Figure 2's UML diagram shows the relationship between the SpaceLogger and the LoggingStrategy interfaces. The diagram also shows how the SpaceLoggerImpl class (which we will develop next) delegates to one LoggingStrategy implementation.

Figure 2. The SpaceLogger uses a LoggingStrategy.

With the logging service's class model under our belts, we can finally start to get our hands dirty and write some real code!

Logging Implementation

First, we must write a class that implements the SpaceLogger interface and can load the appropriate LoggingStrategy.

public class SpaceLoggerImpl extends UnicastRemoteObject
        implements SpaceLogger {
    private LoggingStrategy _impl;

    public LoggingServiceImpl(String strategyClassName)
            throws RemoteException {
        super();
        try {
            Class c = Class.forName(strategyClassName);
            _impl = (LoggingStrategy) c.newInstance();
        }
        catch (Exception ex) {
            throw new
                    RemoteException("Failed to load
            
            LoggingStrategy:",ex);
        }
    }

    public Object logOperation(SpaceOperation op)
            throws java.rmi.RemoteException {
        return _impl.logOperation(op);
    }
}

As the code shows, because SpaceLoggerImpl will be used as a remote service, it extends java.rmi.server.UnicastRemoteObject to receive remote calls from the proxy. Most of the interesting stuff occurs in the constructor, which uses the argument strategyClassName as LoggingStrategy's class name. The method continues by using Class.forName() to load the strategy class and uses newInstance() on the Class object to instantiate it. Here, we assume that all LoggingStrategy implementations have a public no-arg constructor.

Finally, in the logOperation() method, we forward the op parameter to the LoggingStrategy class that was loaded and instantiated in the constructor.

As you can see, by breaking the design down into a logging service and logging strategies, we arrive at a simple service that is extensible and easier to maintain. This is because the detail of how the logging occurs is specific to the concrete LoggingStrategy classes rather than embedded in the service class.

CSV Logging Strategy

A simple strategy for logging space-based operations is to write them to a CSV file. This lets us easily view the log file by opening it in a spreadsheet application. Most spreadsheets will open CSV files, use the comma delimiter to determine where each column ends/starts, and parse a carriage return as a marker for the end of a row.

Previously, we implemented the toString() method in the SpaceOperation class to return a CSV-formatted string, so we can quickly develop a basic LoggingStrategy implementation as shown below:

public class CSVStrategy
        implements LoggingStrategy {

    public synchronized void logOperation(SpaceOperation op) {
        try {
            String msg = op.toString();
            RandomAccessFile raf =
                    new RandomAccessFile("spacelog.csv", "rw");
            FileOutputStream fos =
                    new FileOutputStream(raf.getFD());
            raf.seek(raf.length());
            PrintWriter pw = new PrintWriter(fos);
            pw.println(msg);
            pw.flush();
            fos.close();
        }
        catch (Exception ex) {
            ex.printStackTrace();
        }
    }
}

Although our simple implementation will work, we must synchronize the logOperation() method to avoid corrupting the log file or miss writing data to the file due to IOExceptions. This implementation's obvious problem is lock contention caused by multiple clients (or threads in the same client) blocking the wait to write to the log file.

A simple, yet effective, solution to reduce the lock contention is to use a guarded queue to store the SpaceOperation objects as they arrive. In addition, we have a separate thread processing the head of the queue, thus writing the SpaceOperation object out to disk.

Using a guarded queue only causes contention when we add or remove data from the queue, which in almost all cases is shorter than the length of time it takes to write the data to the file. If you're not familiar with how a guarded queue works, then you can download the source code for this article and other examples in our book JavaSpaces in Practice (see Resources).

Below is a revised version of the CSVStrategy class using a queue. The dump() method has the same code as the previous version's logOperation() method:

public class CSVStrategy
        implements LoggingStrategy, Runnable {
    private jsip.util.Queue _queue
            = new jsip.util.Queue();

    public CSVStrategy() {
        Thread t = new Thread(this);
        t.start();
    }

    public void logOperation(SpaceOperation op) {
        _queue.add(op);
    }

    public void run() {
        while (!Thread.currentThread().isInterrupted()) {
            SpaceOperation op =
                    (SpaceOperation) _queue.getNext();
            //Write the SpaceOperation to disk
            dump(op);
        }
    }
}

Now that we have a LoggingStrategy implementation, we can start to assemble the final pieces of the jigsaw: the proxy and service starter classes.

Remote Logging Proxy

Earlier we looked at the LocalLoggingProxy class, which implemented our LoggingSpace interface and simply wrote the logging information to the local VM console. Much of the code in the LocalLoggingProxy is the same as we'll need for our logging service, except that the call to logOperation() will delegate to the SpaceLogger rather than writing to disk. For this reason, we should define an abstract class that both the LocalLoggingProxy and LoggingServiceProxy can extend:

public abstract class AbstractLoggingProxy
        implements LoggingSpace, Externalizable {

    private JavaSpace _delegateSpace;

    //readExternal() same as in original code
    //writeExternal() same as in original code

    public abstract
            void logOperation(SpaceOperation op);

    public Lease write(Entry entry,
                       Transaction txn, long lease)
            throws TransactionException,
            RemoteException {
        logOperation(
                new SpaceOperation("write", entry, txn, lease));
        return _delegateSpace.write(entry, txn, lease);
    }
    //All the other JavaSpaces methods
}    

The LocalLoggingProxy would then simply look as follows, as its superclass handles finding the delegate space and forwarding the calls:

public class LocalLoggingProxy extends AbstractLoggingProxy{

    public void logOperation(SpaceOperation op) {
        System.out.println(op.toString());
    }
} 

Our new LoggingServiceProxy looks like this:

public class LoggingServiceProxy extends AbstractLoggingProxy
        implements Serializable {
    private SpaceLogger _logger;

    public void readExternal(ObjectInput in)
            throws IOException, ClassNotFoundException {
        //Will find the JavaSpace
        super.readExternal(in);
        try {
            //Now locate the logging service's proxy
            _logger =
                    ServiceLocator.getService(SpaceLogger.class);
        }
        catch (Exception exp) {
            throw new IOException(
                    "Can't find logging service " + exp.toString());
        }
    }

    public void writeExternal(ObjectOutput out)
            throws IOException {
        super.writeExternal();
    }

    public void logOperation(SpaceOperation op)
            throws RemoteException {
        _logger.logOperation(op);
    }
}

We use the same technique of locating the delegate services in the LoggingServiceProxy class (i.e. when the proxy is deserialized) as we did in the LocalLoggingProxy in Part I. This technique allows us register the proxy without having to locate and bind to the delegate services at that time.

In both logging models, we have used this late binding technique to find the delegate services at the point the proxy is deserialized in the client. As an alternative approach, you could have the RegisterProxy class locate the required service or services and initialize the proxies with them. This approach has the advantage that a proxy will only be registered if the delegate services can be found. However, if any delegate service stops and restarts after the proxy has been registered, the remote reference (to the delegate service(s)) would become invalid, unless of course, they are activatable services with persistent remote references.

The final stage is to write the class that registers the logging service.

Server and Client

In Part I, we saw how to register the LocalLoggingProxy to the Jini lookup service. As the code for registering the LoggingServiceProxy is identical, except the proxy's class and name attribute, we won't repeat it here.

The client code to use the logging service also follows the same steps as the LocalLoggingProxy did in part 1, so again we wont repeat that code here.

Analyzing the logging data

Now that we have built a Jini service for logging information showing what methods have been invoked on the space and by whom, how do we go about using it?

Well this really depends on whether we're trying to identify a bug or just analyze the space's usage patterns. For example, one of the most common errors we encounter is where a client has been written to perform a read() when it should have used take() or visa-versa, thus leaving or removing entries from the space that other clients are dependent on.

To identify this type of bug quickly, stop the logging service, rename or delete the previous log file and then run the client against the logging service. Once you have the logging data, say in CSV format, you can open it in a spreadsheet application and count up the reads, writes and takes to determine what interactions actually occurred within the space between the client programs. If on the other hand you go ahead and implement a JDBC strategy then querying the logging data becomes much simpler—in fact you could go even further and write another Jini service with a Service UI that provides analytics and ad hoc querying of the logging data.

Enhancements

The code we have presented here needs few important enhancements/improvements for use in real-world cases. The most obvious enhancement is to pass the space name and logging service names to the proxies to identify the correct services. This will let you have multiple logging services and spaces running within a Jini environment.

A more advanced enhancement is to make the logging service a "well-behaved Jini service;" thus, supporting the JoinAdmin interface, which allows remote configuration of groups, look up locators, and attributes.

Logging information based on the toString() representation of parameters passed to the JavaSpaces API may not be sufficient. You may therefore build on this article's concepts by adding fields to the SpaceOperation class that contain the actual parameters as objects, such as transactions and entries. This would allow an advanced LoggingStrategy to log transaction IDs and use reflection on the entries to store more descriptive information.

You could also record the time taken to execute a method on the JavaSpace and store it in the SpaceOperation class. Another option would be to examine the return value from the call to the JavaSpace, which could a useful logging enhancement for determining whether a read or take succeeded, that is, a non-null value was returned.

Overview and tips

Although using JavaSpaces simplifies many aspects of writing and deploying distributed systems, debugging can be tricky. Therefore, we provide the following review of tips and suggestions:

1. Some space implementations have both debugging modes and debugging tools. If you have these tools available, we suggest you use whatever you find the easiest and most informative.
2. Always build a small subset of the system that you intend to deploy in order to test your assumptions of its behavior against what you can observe.
3. A simple local logging proxy can be useful for single client testing, but is more trouble than it's worth when multiple clients are involved.
4. Using a JavaSpaces (Jini) Logging Service along the lines described in this article can help to identify problems more quickly than writing application-specific debugging code.
5. Implementing a JDBC (Java Database Connectivity) strategy lets you use SQL to query the log and filter on particular method types, hosts, or template parameters.

So there you have it. We have used Jini's ability to export proxies into a remote system to allow us to remotely observe the behavior of any number of remote JavaSpace clients. Of course you can also use this technique to observe the behavior of other systems, or to develop a generalized 'observer' for Jini has whole. If you found this information useful and have developed any of the ideas or idioms further please let us know. Good luck and happy debugging.

Resources

Observing JavaSpace-Based Systems, Part I, by Philip Bishop & Nigel Warren, is the first part of this two part series on logging and analyzing JavaSpace-based distributed systems:
http://www.artima.com/jini/jiniology/obspaceA.html

JavaSpaces in Practice, a new book by by Philip Bishop and Nigel Warren, is at Amazon.com at:
http://www.amazon.com/exec/obidos/ASIN/0321112318/

The website for JavaSpaces in Practice is here:
http://www.jsip.info/

JavaSpaces: Principles, Patterns, and Practice by Eric Freeman, Susanne Hupfer, and Ken Arnold, an introduction to JavaSpaces, is at Amazon.com at:
http://www.amazon.com/exec/obidos/ASIN/0201309556/

The source code for the examples appearing in this article can be downloaded here:
http://www.djip.co.uk/downloads.html#artima

The Jini Community, the central site for signers of the Jini Sun Community Source License to interact:
http://www.jini.org

Download JavaSpaces from:
http://java.sun.com/products/javaspaces/

Make Room for JavaSpaces, Part I - An introduction to JavaSpaces, a simple and powerful distributed programming tool:
http://www.artima.com/jini/jiniology/js1.html

Make Room for JavaSpaces, Part II - Build a compute server with JavaSpaces, Jini's coordination service:
http://www.artima.com/jini/jiniology/js2.html

Make Room for JavaSpaces, Part III - Coordinate your Jini applications with JavaSpaces:
http://www.artima.com/jini/jiniology/js3.html

Make Room for JavaSpaces, Part IV - Explore Jini transactions with JavaSpaces:
http://www.artima.com/jini/jiniology/js4.html

Make Room for JavaSpaces, Part V - Make your compute server robust and scalable with Jini and JavaSpaces:
http://www.artima.com/jini/jiniology/js5.html

Make Room for JavaSpaces, Part VI - Build and use distributed data structures in your JavaSpaces programs:
http://www.artima.com/jini/jiniology/js6.html

Talk back!

Have an opinion? Readers have already posted 4 comments about this article. Why not add yours?

About the author

Nigel Warren is cofounder and director of technology at IntaMission Ltd., where he researches and designs agile and evolvable software infrastructures for next-generation distributed systems.

Philip and Nigel are also the joint authors of JavaSpaces in Practice and Java in Practice, both published by Addison-Wesley.