Applying interceptors to producer methods

Interceptors are really cool if you have a common problem and like to apply it to without making every single colleague copy the same code over again and again to apply a solution over the whole code base.

In my case it was the urge to log out SOAP and REST invocations to other systems. I also like to add a logCorrelationId via HTTP header to each outgoing SOAP call. You can read more about the background over in my other logCorrelation blog post.

I’ll focus on integrating SOAP clients, but you can easily do the same for REST clients as well.

Integrating a SOAP client in an EE project

Usually I create a CDI producer for my SOAP ports. That way I can easily mock them out with a local dummy implementation by just using CDI’s @Specializes or @Alternative. If you combine this with with Apache DeltaSpike @Exclude and the DeltaSpike Configuration system then you can even even enable those Mock via ProjectStage or a configuration setting.

Consider you have a WSDL and you create a SOAP client with the interface CustomerService.

What we like to get from a ‘consumer’ perspective is the following usage:

public class SomeFancyClass {
  private @Inject CustomerService customerService;
  ...
}

Which means you need a CDI producer method, e.g. something like:

@ApplicationScoped
public class CusomerServiceSoapClientProducer {
  @ConfigProperty(name = "myproject.customerService.endpointUrl")
  private String customerServiceEndpointUrl;

  @Produces
  @RequestScoped
  @LogTiming
  public CustomerService createSoapPort() {
    // generated from the WSDL, e.g. via CXF
    CustomerServiceService svc = new CustomerServiceService();
    CustomerServiceServicePort port = svc.getCustomerServiceServicePort();

    // this sets the endpoint URL during producing.
    ((BindingProvider) port).getRequestContext().
           put(BindingProvider.ENDPOINT_ADDRESS_PROPERTY, customerServiceEndpointUrl);

    return port;
  }
}

Side note: the whole class could also be @RequestScoped to get the endpoint URL evaluated on every request. We could of course also use the DeltaSpike ConfigResolver programmatically to gain the same. But the whole point of setting the endpoint URL manually is that we don’t need to change the WSDL and have to recompile the project on every server change. We can also use different endpoints for various boxes (test vs production environments, or different customers) that way.

What is this @LogTiming stuff?

Now it becomes interesting! We now have a SOAP client which looks like a regular CDI bean from a ‘user’ point of view. But we like to get more information about that outgoing call. After all it’s an external system and we have no clue how it behaves in terms of performance. That means we like to protocol each and every SOAP call and log out it’s duration. Of course since we not only have 1 SOAP service client but multiple dozen ones we like to do this via an Interceptor!

@Inherited
@InterceptorBinding
@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.METHOD, ElementType.TYPE})
public @interface LogTiming {
}

Applying an Interceptor on a producer method?

Of course the code written above DOES work. But it behaves totally different as many of you will guess.
If you apply an interceptor annotation to a producer method, then it will not intercept the calls to the produced bean!
Instead it will just intercept the invocation of the producer method. A producer method gets invoked when the Contextual Instance gets created. For a @Produces @RequestScoped annotated producer method this will happen the first time a method on the produced CDI bean gets called in the very request (or thread for non-servlet request based threads). And exactly this call gets intercepted.

If we would just apply a stopwatch to this interceptor then we would get the info about how long it took to create the soap client. That’s not what we want! We like to get the times from each and every usage of that CustomerService invocation! So what does our LogTiming interceptor do?

Proxying the Proxy

The trick we apply is to to use our LogTiming Interceptor to wrap the produced SOAP port in yet another proxy. And this proxy logs out the request times, etc. As explained before we cannot use CDI interceptors, but we can use java.lang.reflect.Proxy!:

@LogTiming
@Interceptor
public class WebserviceLoggingInterceptor {

    @AroundInvoke
    private Object wrapProxy(InvocationContext ic) throws Exception {
        Object producedInstance = ic.proceed();
        Class[] interfaces = producedInstance.getClass().getInterfaces();
        Class<?> returnType = ic.getMethod().getReturnType();
        return Proxy.newProxyInstance(ClassUtils.getClassLoader(null), interfaces, new LoggingInvocationHandler(producedInstance, returnType));
    }
}

This code will register our reflect Proxy in the CDI context and each time someone calls a method on the injected CustomerService it will hit the LogInvocationHandler. This handler btw can also do other neat stuff. It can pass over the logCorrelationId (explanation see my other blog post linked above) as HTTP header to the outgoing SOAP call.

The final LoggingInvocationHandler looks like the following:

public class LoggingInvocationHandler implements InvocationHandler {
    private static final long SLOW_CALL_THRESHOLD = 100; // ms
 
    private final Logger logger;
    private final T delegate;

    public LoggingInvocationHandler(T delegate, Class loggerClass) {
        this.delegate = delegate;
        this.logger = LoggerFactory.getLogger(loggerClass);
    }

    @Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        if (EXCLUDED_METHODS.contains(method.getName())) {
            // don't log toString(), hashCode() etc...
            return method.invoke(delegate, args);
        }

        long start = System.currentTimeMillis();

        try {
            // setting log correlation header if any logCorrelationId is set on the thread.
            String logCorrelationId = LogCorrelationUtil.getCorrelationId();
            if (StringUtils.isNotEmpty(logCorrelationId) && delegate instanceof BindingProvider) {
                BindingProvider port = (BindingProvider) delegate;
                Map<String, List> headers = (Map<String, List>) port.getRequestContext().get(MessageContext.HTTP_REQUEST_HEADERS);
                if (headers == null) {
                    headers = new HashMap<>();
                }
                headers.put(LogCorrelationUtil.REQUEST_HEADER_CORRELATION_ID, Collections.singletonList(logCorrelationId));
                port.getRequestContext().put(MessageContext.HTTP_REQUEST_HEADERS, headers);
            }

            // continue with the real call
            return method.invoke(delegate, args);
        }
        finally {
            long duration = System.currentTimeMillis() - start;
            if (duration <= SLOW_CALL_THRESHOLD) {
                logger.info("soapRemoteCall took={} ms service={} method={}", duration, delegate.getClass().getName, method.getName());
            }
            else {
                // log a more detailed msg, e.g. with params
            }
        }
    }

Limitations

Of course this trick only works if the producer method returns an interface! That’s caused by the reflect Proxies are only available for pure interfaces.

I’m trying to remove this limitations by bringing intercepetors for produced instances to CDI-2.0 as well on working on a interceptors spec change to introduce ways to create subclassing proxies as easy as interface proxies. Stay tuned!

CDI in EARs

Foreword

I was banging my head against the wall for the last few days when trying to solve a few tricky issues we saw with EAR support over at Apache DeltaSpike. I’m writing this up to clean my mind and to share my knowledge with other EAR-pig-wrestlers…

The EAR ClassLoader dilemma

EARs are a constant pain when it comes to portability amongst servers. This has to do with the fact that JavaEE still doesn’t define any standards for visibility. There is no clear rule about how the ClassLoaders, isolation and visibility has to be set up. There is just as single paragraph (JavaEE7 spec 8.3.1) about which classes you might probably see.

There are 2 standard ClassLoader setups we see frequently in EARs.
For the sake of further discussion we assume an EAR with the following structure:

sample.ear
├── some-ejb.jar
├── lib
│   ├── some-shared.jar
│   └── another-shared.jar
├── war1.war
│   └── WEB-INF
│       ├── classes 
│       └── lib
│           └── war1-lib.jar
└── war2.war
    └── WEB-INF
        ├── classes 
        └── lib
            └── war2-lib.jar

Flat ClassLoader

The whole EAR is served by just a single flat ClassLoader. If you have 2 WARs inside your application then the classes in each of it can see each other. And also the classes in the shared EAR lib folder can see. This is e.g. used in JBoss-4 (though not from the beginning). You can also configure most of the other containers to use this setup for your EAR. But nowadays it’s hardly a default anymore (and boy is that good!)

Hierarchic ClassLoader

This is the setup used by most containers these days – but it’s still not a mandated by the spec! The Container will provide a shared EAR Application ClassLoader which itself only contains the shared ear libs. This is the parent ClassLoader of all the ClassLoaders in the EAR. Each WAR and ejb-jar inside your EAR will get an own child WebAppClassLoader.

This means war2 doesn’t see any classes or resources from war1 and the other way around. It further means that the shared libs do not see the classes of war1 nor war2, etc!

If you need some caches in your shared libs, then you need to rely on the ThreadContextClassLoader (TCCL) as outlined in JavaEE 7 paragraph 8.2.5. While this section is about “Dynamic Class Loading” it also is valid for caches and storing other dynamic information in static variables. Otherwise you end up mixing values from war1 and probably re-use them in war2 (where you will get a ClassNotFound exception). Even if your 2 WARs contain the same jar (e.g. commons-lang.jar) the Class instances are different as they come from a different ClassLoader. If you store those in a shared-lib jar then you most probably end up with the (in)famous “Cannot cast class Xxx to class Xxx”.

One common solution to this problem will look something like:

public class MyInfoStore {
  private Map<ClassLoader, Set<Info>> infoMap;

  public void storeInfo(Info info) {
    ClassLoader tccl = Thread.currentThread().getContextClassLoader(); // probably guarded for SecurityManager
    infoMap.put(tccl, info);
  }
...
}

Of course you must really be careful to clean up this Map during shutdown. In CDI Applications you can use the @Observes BeforeShutdown event to trigger the cleanup.

The impact on us programmers

These various scenarios make it really hard to write any form of portable framework who runs fine inside of EARs. This is not only true for client frameworks but also for container frameworks itself like CDI and Spring.

Integrating CDI containers in EARs

It is pretty obvious that – mostly due to the lack of a guaranteed default isolation scenario in JavaEE – CDI containers have a hard time in finding a nice and portable handling of CDI beans and Extensions in EARs. I got involved in CDI in late 2008 when the name of the spec still was WebBeans. And that name was taken literally – it originally was only targetting web applications and not EARs. The EAR support only got roughly added (according to some interpretations) shortly before the EE-6 specification got published. So there are multiple reasons why CDI in EARs is not really a first class citizen yet.

To my knowledge there are 3 sane ways how a container can integrate CDI in ears. And of those 3 sane ways, 5 are used in various containers 😉

A.) 1 BeanManager per EAR

All the EAR is handled via 1 BeanManager. This is the way JBoss WildFly seems to handle things. First the BeanManager gets created and all it’s CDI Extensions get loaded (TODO research: all or only the ones from the shared libs?).

In reality it’s a bit more complicated. Weld uses a single BeanManager for each and every JAR in your EAR. Don’t ask me why, but that’s what I’ve seen. Still you only get one set of Extensions for your whole EAR. Keep this in mind.

The TCCL always seems to stay the shared EAR ApplicationClassLoader during boot time. Even while processing the classes of the WAR files. Thus the TCCL during @Observes ProcessAnnotatedType will be the shared EAR ApplicationClassLoader. But if you access your Extensions (or the information collected by them) later at runtime you might end up with a different TCCL. This is especially true for all servlet requests in your WARs. This makes it really hard to store anything with the usual Map<ClassLoader, Set<Info>> trick.

B.) 1 BeanManager per WAR + 1 ‘shared’ BeanManager

Each WAR fully boots up his own BeanManager. The shared EAR libs also get an own BeanManager to serve non-servlet requests like JMS and remote EJB invocations. Classes in shared EAR-libs simply get discovered over again for each WAR. Each WAR also has it’s own set of Extensions (they are usually 1:1 to the BeanManager). This is what I’ve seen in Apache Geronimo, IBM WebSphere and early Apache TomEE containers.

This is a bit tricky when it comes to handling of the @ApplicationScoped context (see CDI-129 for more information) or if you handle EJBs (which are by nature shared across the EAR). WebSphere e.g. seems to solve this by having an own Bean<SomeSharedEarLibClass> instance for each BeanManager (and thus for each WAR) but they share a single ApplicationContext storage and those beans are equals(). Probably they just compare the PassivationCapable#getPassivationId()?

It usually works fairly nice and it allows the usage of most common programming patterns. This also allows to modify classes from shared libs via Extensions you register in a single WAR. The downside is that you have to scan and process all the shared classes over and over again for each WAR. This obviously slows down the application boot time.

Oh this mode strictly seen also conflicts with the requirements for modularity of section 5 of the CDI specification. Overall I’m not very happy with section 5 but it should be mentioned.

C.) Hierarchic BeanManagers

In this case we have an 1:1 relation between a ClassLoader and the BeanManager. The shared EAR libs will get scanned by an EAR-BeanManager. Then each of the WARs get scanned via their own WebAppBeanManager. In contrast to scenario B. these WebAppBaenManagers will only scan the classes of the local WARs WEB-INF/lib and WEB-INF/classes and not the shared ear lib over again. If you need information from shared EAR lib classes then the WebAppBeanManger simply delegates to it’s ‘parent’ EAR-BeanManager. Apache TomEE uses this mode since 1.7.x

There are a few tricks the container vendor need to do in this case. E.g. propagating events and Bean lookups to the parent BeanManager, etc. Or to suppress sending CDI Extension Events to the parent (we recently learned this the hard way – is fixed in TomEE-1.7.2 which is to be released soon).

It also has an important impact on CDI Extension programmers: As your Extensions are 1:1 to the BeanManager we now also have the ClassPath split up into different Extension instances. This works fine for ProcessAnnotatedType but can be tricky in some edge cases. E.g. the DeltaSpike MessageBundleException did collect info about a certain ProducerBean and stored in in the Extension for later usage in @Observes AfterBeanDiscovery. Too bad that in my case this certain ProducerMethod was in a shared ear lib and thus gets picked up by the Extension-instance of the EAR-BeanManager but the ‘consumer’ (the interface annotated with @MessageBundle is in some WARs. And the WebAppBeanManager of this WAR obviously is not the one scanning the ProducerMethod of the class in the shared ear lib. Thus the Extension created a NullPointerException. This will be fixed in the upcoming Apache DeltaSpike-1.2.2 release.

The Impact on poor CDI Extension programmers

TODO: this is a living document. I’ll add more info and put it up review.