[Hawkular-dev] New Hawkular Blog Post: OpenTracing EJB instrumentation

Friday, 28 July 2017

New Hawkular blog post from noreply(a)hawkular.org (Juraci Paixão Kröhling):
http://ift.tt/2u3KYMP

OpenTracing features more and more framework integrations, allowing for transparent
instrumentation of applications with minimal effort. This blog post will show how to use
the EJB instrumentation to automatically trace EJB invocations.

For this demo, we’ll generate a project using the Wildfly Swarm project generator, which
allows us to have a seed project with the appropriate OpenTracing support in place. The
concrete OpenTracing solution we will use is provided by the Jaeger project, which is also
provided as a Wildfly Swarm Fraction.

With that, we’ll create a simple JAX-RS endpoint with an EJB facet, invoking a set of EJB
services in different ways to demonstrate all the features of this integration.

Our application has one endpoint called /order, responsible for receiving requests to
place orders in our system. When we call this endpoint, we also call some other EJB
services, like

AccountService to send a notification that an order has been placed

OrderService to effectively place the order

InventoryService to change our inventory

InventoryNotificationService, to notify other backend systems.

As we are only interested in the tracing parts, we’ll not implement the business code
itself, only the scaffolding.

Our demo project is heavily based on the opentracing-ejb-example from the repository
opentracing-contrib/java-ejb. We have also prepared an archive with the final outcome of
this demo, which you can use as reference.

The seed project

To generate the seed project, open the Wildfly Swarm generator and create a project with
the &quot;Group ID&quot; io.opentracing.contrib.ejb and &quot;Artifact
ID&quot; demo-example. Add the dependencies EJB, CDI, JAX-RS, OpenTracing, and
Jaeger.

Make sure to select all listed dependencies and confirm that they are shown in the
&quot;Selected dependencies&quot; section, otherwise, you might not have all the
required fractions for this demo.

Click on Generate Project and you’ll get a ZIP file with the seed project. Uncompress it
and add the following dependency to the pom.xml, within the dependencies node and after
the WildFly Swarm Fractions dependencies:

    &lt;dependency&gt;
      &lt;groupId&gt;io.opentracing.contrib&lt;/groupId&gt;
      &lt;artifactId&gt;opentracing-ejb&lt;/artifactId&gt;
      &lt;version&gt;0.0.2&lt;/version&gt;
    &lt;/dependency&gt;

It’s now a good time to perform a sanity build, to make sure everything is in place. The
first build might take a few minutes:

$ mvn wildfly-swarm:run
...
...
2017-07-26 12:02:19,154 INFO  [org.wildfly.swarm] (main) WFSWARM99999: WildFly Swarm is
Ready

If it looks good, stop the server with Ctrl+C and let’s start coding our application!

The application

Let’s start by defining a JAX-RS endpoint that also acts as a stateless EJB. This is a
common trick to get JAX-RS endpoints to be managed as EJBs, so that they can be invoked
via JMX or get monitoring features. Or, in our case, to get traced via EJB interceptors.

This endpoint is where we get our HTTP requests from and where our transaction starts,
from the tracing perspective. Once we receive an HTTP request, we call the
AccountService#sendNotification method and then the OrderService#processOrderPlacement.

Note that we annotate the class with @Interceptors(OpenTracingInterceptor.class), which
means that all methods on this class are to be traced.

src/main/java/io/opentracing/contrib/ejb/demoexample/Endpoint.java:

package io.opentracing.contrib.ejb.demoexample;

import io.opentracing.contrib.ejb.OpenTracingInterceptor;

import javax.ejb.Stateless;
import javax.inject.Inject;
import javax.interceptor.Interceptors;
import javax.ws.rs.POST;
import javax.ws.rs.Path;
import java.util.logging.Logger;

/**
 * This is a regular JAX-RS endpoint with EJB capabilities. We use the EJB capability to
specify an interceptor,
 * so that every method on this class is wrapped on its own span. If the OpenTracing
JAX-RS integration is being used,
 * it would be a good idea to not have the interceptor at this level, to avoid having too
much &quot;noise&quot;.
 *
 * @author Juraci Paixão Kröhling
 */
@Path(&quot;/order&quot;)
@Stateless
@Interceptors(OpenTracingInterceptor.class)
public class Endpoint {
    private static final Logger log = Logger.getLogger(Endpoint.class.getName());

    @Inject
    AccountService accountService;

    @Inject
    OrderService orderService;

    @POST
    @Path(&quot;/&quot;)
    public String placeOrder() {
        log.info(&quot;Request received to place an order&quot;);
        accountService.sendNotification();
        orderService.processOrderPlacement();
        return &quot;Order placed&quot;;
    }

}

Our AccountService is a simple stateless EJB, responsible for sending a notification about
the new order to the owner of the account. Here, we could call another service, or send an
email, SMS or any other form of message.

As this is a regular EJB, we are able to automatically join the span context from the
JAX-RS endpoint, making this call a child span of the main transaction. This is all
transparent to you as developer.

Note again that we annotate the bean with @Interceptors(OpenTracingInterceptor.class). As
our interceptor is just like any other EJB interceptor, you could use a ejb-jar.xml to
automatically use this inteceptor on all available beans. Whether or not to trace all
beans is a per-deployment decision, so, no ejb-jar.xml is provided by the integration.

src/main/java/io/opentracing/contrib/ejb/demoexample/AccountService.java:

package io.opentracing.contrib.ejb.demoexample;

import io.opentracing.contrib.ejb.OpenTracingInterceptor;

import javax.ejb.Stateless;
import javax.interceptor.Interceptors;
import java.util.logging.Logger;

/**
 * This is a simple synchronous EJB, without any knowledge about span context or other
OpenTracing semantics. All it
 * does is specify an interceptor and it's shown as the child of a parent span.
 *
 * @author Juraci Paixão Kröhling
 */
@Stateless
@Interceptors(OpenTracingInterceptor.class)
public class AccountService {
    private static final Logger log = Logger.getLogger(AccountService.class.getName());

    public void sendNotification() {
        log.info(&quot;Notifying the account owner about a new order&quot;);
    }
}

Our OrderService is responsible for actually placing the order: it’s where the business
knowledge resides. We’ll later look into details at the InventoryService, but for now, we
need to know that this service requires a SpanContext to be explicitly passed. We can get
this context from the EJBContext, stored under a context data entry that can be retrieved
with the constant io.opentracing.contrib.ejb.OpenTracingInterceptor.SPAN_CONTEXT.

src/main/java/io/opentracing/contrib/ejb/demoexample/OrderService.java:

package io.opentracing.contrib.ejb.demoexample;

import io.opentracing.SpanContext;
import io.opentracing.contrib.ejb.OpenTracingInterceptor;

import javax.annotation.Resource;
import javax.ejb.EJBContext;
import javax.ejb.Stateless;
import javax.inject.Inject;
import javax.interceptor.Interceptors;
import java.util.logging.Logger;

import static io.opentracing.contrib.ejb.OpenTracingInterceptor.SPAN_CONTEXT;

/**
 * This is a regular synchronous stateless EJB. It demonstrates how to get the span
context for the span it's wrapped
 * on. This can be used to pass down the call chain, create child spans or add baggage
items.
 *
 * @author Juraci Paixão Kröhling
 */
@Stateless
@Interceptors(OpenTracingInterceptor.class)
public class OrderService {
    private static final Logger log = Logger.getLogger(OrderService.class.getName());

    @Resource
    EJBContext ctx;

    @Inject
    InventoryService inventoryService;

    public void processOrderPlacement() {
        log.info(&quot;Placing order&quot;);
        Object ctxParentSpan = ctx.getContextData().get(SPAN_CONTEXT);
        if (ctxParentSpan instanceof SpanContext) {
            inventoryService.changeInventory((SpanContext) ctxParentSpan);
            return;
        }

        inventoryService.changeInventory(null);
    }
}

Our InventoryService is responsible for interfacing with backend systems dealing with
inventory control. We don’t want to block the parent transaction while interacting with
those systems, so, we make this an asynchronous EJB. When dealing with asynchronous
objects, it’s a good idea to be explicit about the span context, as there are potential
concurrency issues when sharing a context between a synchronous and an asynchronous bean.

The OpenTracing EJB integration is able to intercept the method call and detect if there
is a span context among the parameters, which is the case of the
changeInventory(SpanContext) method. In this situation, the following happens behind the
scenes:

The caller makes a method call, passing the SpanContext

The interceptor is activated, creating a new child span using the SpanContext as the
parent

The interceptor replaces the original SpanContext with this new child span on the method
call

The intercepted method is finally invoked, wrapped by the new child span.

Note that the SpanContext passed by the OrderService is not the same as the one received
by InventoryService. While this might cause some confusion, we believe this is the right
semantic for this use case, as it allows for a complete tracing picture, without any
explicit tracing code, apart from passing the context around.

src/main/java/io/opentracing/contrib/ejb/demoexample/InventoryService.java

package io.opentracing.contrib.ejb.demoexample;

import io.opentracing.SpanContext;
import io.opentracing.contrib.ejb.OpenTracingInterceptor;

import javax.ejb.Asynchronous;
import javax.ejb.Stateless;
import javax.inject.Inject;
import javax.interceptor.Interceptors;
import java.util.logging.Logger;

/**
 * This is an asynchronous stateless EJB with spans created automatically by the
interceptor. Note that the span context
 * that this method sees is &lt;b&gt;not&lt;/b&gt; the same as the span
context sent by the caller: the interceptor wraps this
 * method call on its own span, and replaces the span context by the context of this new
span. This is done so that this
 * span context can be passed along to the next service &quot;as is&quot;.
 *
 * @author Juraci Paixão Kröhling
 */
@Asynchronous
@Stateless
@Interceptors({OpenTracingInterceptor.class})
public class InventoryService {
    private static final Logger log = Logger.getLogger(InventoryService.class.getName());

    @Inject
    InventoryNotificationService inventoryNotificationService;

    public void changeInventory(SpanContext context) {
        log.info(&quot;Changing the inventory&quot;);
        inventoryNotificationService.sendNotification(context);
    }
}

And finally, our last service, InventoryNotificationService: in this case, we notify
another set of backend systems that a new order has been placed. Again, this is an
asynchronous EJB and works like the one above, but additionally, we wanted to manually
create a &quot;business span&quot;, called sendNotification. This method could
send several notifications, wrapping each one into a span of its own. As we manually
started it, we manually finish it as well.

src/main/java/io/opentracing/contrib/ejb/demoexample/InventoryNotificationService.java

package io.opentracing.contrib.ejb.demoexample;

import io.opentracing.Span;
import io.opentracing.SpanContext;
import io.opentracing.util.GlobalTracer;

import javax.ejb.Asynchronous;
import javax.ejb.Stateless;
import java.util.logging.Logger;

/**
 * This is the final call in the chain. This is an asynchronous stateless EJB, which
obtains the span context
 * via a method parameter. This bean is not intercepted in any way by us, so, the span
context received is exactly
 * the same as what was sent by the caller.
 *
 * @author Juraci Paixão Kröhling
 */
@Stateless
@Asynchronous
public class InventoryNotificationService {
    private static final Logger log =
Logger.getLogger(InventoryNotificationService.class.getName());

    public void sendNotification(SpanContext context) {
        Span span =
GlobalTracer.get().buildSpan(&quot;sendNotification&quot;).asChildOf(context).startManual();
        log.info(&quot;Sending an inventory change notification&quot;);
        span.finish();
    }

}

Now, let’s do a final sanity check and see if everything is in the right place: mvn
wildfly-swarm:run . As before, the final message should be WildFly Swarm is Ready. Hit
Ctrl+C and let’s setup our tracing backend.

The tracing backend

Instrumenting our code is one part of the story. The other part is to plug in an actual
OpenTracing implementation that is capable of capturing the spans and submitting them to a
backend service. For our demo, we’ll use Jaeger. If you don’t have a Jaeger server running
yet, one can be started via Docker as follows:

docker run \
    --rm \
    -p5775:5775/udp \
    -p6831:6831/udp \
    -p6832:6832/udp \
    -p5778:5778 \
    -p16686:16686 \
    -p14268:14268 \
    --name jaeger \
    jaegertracing/all-in-one:latest

Tying everything together

Now that we have our code ready and a tracing backend, let’s start Wildfly Swarm passing a
service name, which is the only property required by the Jaeger client. By default,
Jaeger’s Java tracer will attempt to send traces via UDP to a Jaeger Agent located on the
local machine. If you are using a different architecture, refer to the Jaeger’s
documentation on how to use environment variables to configure the client, or refer to the
Jaeger’s fraction for Wildfly Swarm.

For our demo, we’ll use a property that is recognized by the Jaeger’s Wildfly Swarm
Fraction. The other two properties are telling Jaeger that every request should be
sampled.

mvn wildfly-swarm:run -Dswarm.jaeger.service-name=order-processing
-Dswarm.jaeger.sampler-type=const -Dswarm.jaeger.sampler-parameter=1

Watch the logs for an entry containing com.uber.jaeger.Configuration: if everything is
correctly set, it should show the complete configuration of the Jaeger client, like this:

2017-07-26 12:03:09,139 INFO  [com.uber.jaeger.Configuration] (ServerService Thread Pool
-- 6) Initialized tracer=Tracer(version=Java-0.20.0, serviceName=order-processing,
reporter=RemoteReporter(queueProcessor=RemoteReporter.QueueProcessor(open=true),
sender=UdpSender(udpTransport=ThriftUdpTransport(socket=java.net.DatagramSocket@7270de22,
receiveBuf=null, receiveOffSet=-1, receiveLength=0)), maxQueueSize=100,
closeEnqueueTimeout=1000), sampler=ConstSampler(decision=true, tags={sampler.type=const,
sampler.param=true}), ipv4=-1062731153, tags={hostname=carambola,
jaeger.version=Java-0.20.0, ip=192.168.2.111}, zipkinSharedRpcSpan=false)

Once the message WildFly Swarm is Ready is seen, we can start making requests to our
endpoint:

$ curl -X POST localhost:8080/order
Order placed

And this can be seen on the server’s log:

2017-07-26 12:03:19,302 INFO  [io.opentracing.contrib.ejb.demoexample.Endpoint] (default
task-2) Request received to place an order
2017-07-26 12:03:19,304 INFO  [io.opentracing.contrib.ejb.demoexample.AccountService]
(default task-2) Notifying the account owner about a new order
2017-07-26 12:03:19,307 INFO  [io.opentracing.contrib.ejb.demoexample.OrderService]
(default task-2) Placing order
2017-07-26 12:03:19,314 INFO  [io.opentracing.contrib.ejb.demoexample.InventoryService]
(EJB default - 1) Changing the inventory
2017-07-26 12:03:19,322 INFO 
[io.opentracing.contrib.ejb.demoexample.InventoryNotificationService] (EJB default - 2)
Sending an inventory change notification

At this point, the complete trace with its 6 spans can be seen on Jaeger’s UI, located at
http://localhost:16686/search , if you are using the Docker command we listed before.

Conclusion

EJBs are a very important part of Java EE and we expect the OpenTracing EJB framework
integration to complement the other Java EE related integrations, like the Servlet and
JAX-RS. In this blog post, we’ve shown how tracing EJBs can be accomplished by
transparently tracing synchronous stateless EJBs, intercepting span contexts in
asynchronous EJBs and by exposing the span context via EJB contexts, as well as manually
starting spans to include specific business logic into the trace.

from Hawkular Blog

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

[Hawkular-dev] New Hawkular Blog Post: OpenTracing EJB instrumentation