Chapter 9. XMap And Logging [DRAFT]

Table of Contents

9.1. This is a DRAFT! Give your opinion!
9.2. A brief diversion from upcoming
9.3. A word from our sponsors at OSGi
9.4. XMap: the dirty little secret of extension points
9.5. Converting XML to Java
9.6. Logging
9.7. Exercises

Objective: To understand two technologies, Nuxeo's XMap and Apache Commons logging that are frequently used in Nuxeo development.

If our condition were truly happy, we would not seek diversion from it in order to make ourselves happy. -- Blaise Pascal, French Mathematician (1623-1662)

9.1. This is a DRAFT! Give your opinion!

If you have any comments, questions, or general-purpose harassment you would like give us about this book, then please use the comment form at the bottom of each page! We promise that we will try to incorporate any feedback you give (minus the profanity, of course), will respond to your questions, and credit you appropriately.

9.2. A brief diversion from upcoming

We have been working for several lessons with varying parts of the Nuxeo infrastructure towards the goal of providing a highly functional implementation that supports upcoming events. We are going to look at two parts of the Nuxeo system that are not directly related to the Upcoming document type, but are used throughout Nuxeo. You should familiarize yourself with both of these subsystems, XMap and Apache Common's logging, because they can aid you both in developing and debugging your own applications as well as when trying to understand the Nuxeo source code.

9.3. A word from our sponsors at OSGi

On a number of occasions we have created "components" with XML files and it has always been a little bit unclear exactly what the relationship was between an OSGi component and these XML tags labelled "component" that appeared in the files. This distinction has now become sufficiently important that we need to discuss it. The "names" of components declared with the component tag in an XML contribution, such as the one in the next listing, are in a separate namespace from Java code. We will refer to this as the XML component namespace. These XML components are, in the strictest sense, OSGi components but since their only function is to contribute to extension points, this is of little practical interest.

We are now going to "connect" an XML component to a Java component with the implementation tag. This creates an XML component, exactly as before in a separate namespace, but informs the OSGi infrastructure that this component has a Java implementation. Then we can do useful things in the Java code to interact with the OSGi infrastructure. The most important of these is become notified when the component is fully ready, or "activated" in the OSGi sense. Here is a new version of the file in src/main/resources/OSGI-INF/event-contrib.xml in the skeleton for this lesson (lesson-xmap in the svn repository):

<?xml version="1.0"?>
<component name="org.nuxeo.upcoming.DocumentCreationListener">
  <implementation class="org.nuxeo.upcoming.DocumentCreationListener" />
  <extension target="org.nuxeo.ecm.core.event.EventServiceComponent"
    point="listener">
    <listener name="documentCreationListener" async="false" postCommit="false"
      class="org.nuxeo.upcoming.DocumentCreationListener" priority="140">
    </listener>
  </extension>

</component>

There have only been two changes in this version, one to add the implementation tag to indicate to the runtime where the XML component object's Java code is located, and a change of the name of the component in the first, Component tag. The second change we made to try to make it more clear that the two namespaces, XML component and Java implementation, have been combined. We feel that this convention makes it a bit easier to see which XML components have Java "backing."

Now, we will update the code for DocumentCreationListener as shown in the listing below, with the already existing methods omitted to keep the listing at a reasonable size:

package org.nuxeo.upcoming;
//..imports..


public class DocumentCreationListener implements EventListener, Component {

    //event handling code elided for space


    public void activate(ComponentContext ctx) throws Exception {
        System.out.println("Wonder twin powers, activate!");
    }

    public void deactivate(ComponentContext ctx) throws Exception {
        System.out.println("Wonder twin powers, deactivate!");
    }

    public void registerExtension(Extension ext) throws Exception {
    }

    public void unregisterExtension(Extension ext) throws Exception {
    }

}

In the this new version of the DocumentCreationListener, we have added a new Java interface Component that the object implements. The implementation of the interface is the last four methods of the listing. For now, try running the tests and watching for the messages from the Wonder Twins. The activate and deactivate methods are called when the OSGi infrastructure has fully loaded or unloaded the component.

9.4. XMap: the dirty little secret of extension points

Steven Hawking (English Physicist, 1942- ) has pointed out that many times the Nobel Prize for physics is given for showing that the world is not as simple as we thought. Follwing the lead of this fine British scientist, we are going to explain that the world of extension points is not quite as simple as was explained it before! In particular, the XML files that we developed over the previous lessons are only an external representation for another layer of Nuxeo 5. XML was chosen because many developers are familiar with it and many tools exist to manipulate it.

In 2005, as work was beginning on Nuxeo 5, Nuxeo developed XMap a tool for mapping XML to Java objects. In the general case, an XML fragment is read in an this is processed into an instance of a (well-known in advance) Java type. We are going to reconsider the definition of our Upcoming document type in light of the XMap revelation. Here is the definition of the current version of the doctype-contrib.xml from this project's skeleton (in the usual place, http://svn.nuxeo.org/nuxeo/sandbox/ianmith/book/lesson-users):

<?xml version="1.0"?>
<component name="org.nuxeo.book.upcoming.doctype">
  <extension target="org.nuxeo.ecm.core.schema.TypeService" point="doctype">
  
    <doctype name="Upcoming" extends="Document">
      <schema name="common" />
      <schema name="dublincore" />
      <schema name="upcoming" />
      <schema name="file" />
      <schema name="uid" />
      <facet name="Commentable" />
      <facet name="Versionable" />
      <facet name="Indexable" />
    </doctype>
    
  </extension>
</component>

Via XMap, the Nuxeo infrastructure turns this into an instance of this Java object (slightly modified for clarity):

@XObject("doctype")
public class DocumentTypeDescriptor {

    @XNode("@name")
    public String name;

    @XNodeList(value = "schema", type = SchemaDescriptor[].class, componentType = SchemaDescriptor.class)
    public SchemaDescriptor[] schemas;

    @XNode("@extends")
    public String superTypeName;

    @XNodeList(value = "facet@name", type = String[].class, componentType = String.class)
    public String[] facets;

    @XNodeList(value = "subtypes/type", type = String[].class, componentType = String.class)
    public String[] childrenTypes;

    @XNode("prefetch")
    public String prefetch;

    public DocumentTypeDescriptor() {
    }

    public DocumentTypeDescriptor(String superTypeName, String name,
            SchemaDescriptor[] schemas, String[] facets) {
        this.name = name;
        this.superTypeName = superTypeName;
        this.schemas = schemas;
        this.facets = facets;
    }

    @Override
    public String toString() {
        return "DocType: "+name;
    }

}

The Java annotations beginning with @XNode indicate to the XML processing code how to handle the XML values given. For example, the root tag doctype in the XML is matched to the @XObject annotation on the type, DocumentTypeDescriptor. The attributes name and extends that are part of the XML element doctype have their values extracted - denoted by their designation as as @XNode with the appropriate parameter - and put into the Java fields that the annotations are associated with. Similarly, an @XNodeList annotation indicates to the XML processor to expect zero or more items in the XML text. The "value = " indicating which sub-part of the XML tag is to be placed into the array that will hold the result.

9.5. Converting XML to Java

It is also the case that the objects that are created by XMap when reading our XML configuration files can be created "by hand" in Java with no loss of descriptive power. Put another way, there is no advantage to using Java compared to XML and vice versa, they are equivalent in terms of functionality. So, to prove the point, we are going to remove the file doctype-contrib.xml from the OSGI-INF directory and implement the equivalent functionality. First, go ahead and delete the doctype-contrib.xml file and remove the reference to it from the MANIFEST.MF file. At this point, we have no document type declared! The next listing is a "by hand" creation of a DocumentTypeDescriptor and then registering it with code that exposes the extension point.

Where does this code go? In the activate method we just got working in section 3 (that's why we did it). This means that roughly when your budle gets loaded - really when the Event Listener component gets activated - this code will run, creating the document type before any user gets wise to the fact that we are use Java not XML to do this work.

    public void activate(ComponentContext ctx) throws Exception {
        // create the equivalent of the XML file that was doctype-contrib
        DocumentTypeDescriptor descriptor = new DocumentTypeDescriptor();
        descriptor.name = "Upcoming";
        descriptor.superTypeName = "Document";
        // this is done automatically by the infostructure normally when it
        // converts strings to schema descriptors
        SchemaDescriptor[] schemaDescriptor = new SchemaDescriptor[] {
                new SchemaDescriptor("common"),
                new SchemaDescriptor("dublincore"),
                new SchemaDescriptor("file"), new SchemaDescriptor("uid"),
                new SchemaDescriptor("upcoming") };

        descriptor.schemas = schemaDescriptor;
        descriptor.facets = new String[] { "Commentable", "Versionable",
                "Indexable" };

        // this is sad that we have to do this
        SchemaManagerImpl implementation = (SchemaManagerImpl) TypeService.getSchemaManager();

        //do the work of registration
        implementation.registerDocumentType(descriptor);
    }

You will need to go through the usual process of running maven and copying this bundle (lesson-xmap-0.0.1.jar) into the plugins directory of the server. With that done you can run this new version of the bundle and ... nothing new happens! Woo-hoo!

9.6. Logging

There are few developers alive with a few years of experience that have not written a logging package of one form or another. Logging is a ubiquitous problem and, worse, in the Java community there are a plethora of solutions. To somewhat ameliorate this problem, the fine folks at the Apache foundation have created a package called Commons Logging. This package, strangely, provides no logging functionality! Commons Logging is a meta-logging package (were that the world were such that we would never write the words "meta-logging" package) that papers over the differences between many popular logging tools. So by using the Commons Logging package you can ignore the actual logging implementation - at least until you have to run your program. At that point you have to choose a java logging package and actually configure it.

We have already shown you some configurations for log4j, the true logging package, used by Nuxeo EP. This means that Apache Commons Logging is bridging to Apache Log4J. For most developers, though, the only thing that they care about is how to actually generate a log message. You can do this with the Logger object. We'll keep working with the DocumentCreationListener. It is customary to make the logger be a private static final variable and to use a logger name that is the same as the class doing the logging since this makes the output easier to understand. This is the line you should add to the top of file:

    private static final Log log = LogFactory.getLog(DocumentCreationListener.class);

At point in the file you can call methods on the log objects to generate output. The log level of the output depends on which method you call. For example:

    log.debug("the activate() method is running!");

This message will only be output if the log level is set to debug, the lowest level. If you have forgotten, you can control the log level that you actually get when running tests via the file src/test/resources/log4j.properties. The first line is probably something like this if you have just gotten the basic skeleton:

log4j.rootLogger=WARN, CONSOLE

If you change WARN to DEBUG, you'll be able to see all the logged output since DEBUG is the lowest level and everything above the currently set level is displayed. Beware there is a lot of it! If you have log messages at the DEBUG level, like we showed above you will have to pick through a lot of Nuxeo's own debugging messages to see your own. You may find the INFO level a good compromise in terms of the amount of output you have to look through to find our own messages.

9.7. Exercises

  1. In the class DocumentCreationListener change the debugging output from println calls to calls on the logger. Most of them should probably be at level DEBUG.