Skip to content

Money In Action

Cleary, Paul edited this page Nov 9, 2015 · 1 revision

Cut to the chase

So if you want to skip this, or just start up the sample, then simply go to Running the App

Breaking down the Sample Application

This sample application demonstrates a complete implementation of Money using Spring MVC 4.0. This particular application is "xml-less", so all of the configuration happens in code (yay).

This application uses several modules: money-core, money-aspectj, money-http-client, and money-java-servlet. To highlight the usage, let's walk the application.

Project Setup

In the pom file, you will notice that I explicitly import all of the individual dependencies that I need. This is purely for demonstration purposes so you can see the artifact names.

        <dependency>
            <groupId>com.comcast.money</groupId>
            <artifactId>money-core_2.10</artifactId>
            <version>${money.version}</version>
        </dependency>
        <dependency>
            <groupId>com.comcast.money</groupId>
            <artifactId>money-http-client_2.10</artifactId>
            <version>${money.version}</version>
        </dependency>
        <dependency>
            <groupId>com.comcast.money</groupId>
            <artifactId>money-spring3_2.10</artifactId>
            <version>${money.version}</version>
        </dependency>
        <dependency>
            <groupId>com.comcast.money</groupId>
            <artifactId>money-java-servlet_2.10</artifactId>
            <version>${money.version}</version>
        </dependency>

It might look a bit odd to see this _2.10 business. The reason is that Money is built on Scala, and we cross-compile; which means that Money will work with Scala 2.10 and 2.11. This example works with money built with Scala 2.10.

In addition to money-core, we also bring in the following:

  • money-spring3 - we use this for some aop fun-ness
  • money-http-client - we use this to instrument all of our HTTP calls, and add the X-MoneyTrace header to outbound HTTP requests
  • money-java-servlet - we use this to setup a Servlet Filter that will parse the X-MoneyTrace header from inbound HTTP requests and auto propagate traces. This is how we propagate traces across distributed systems.

We currently added first-class support for Spring 3 and Spring 4. With these changes, you can use the same annotations in this document without AspectJ. Visit the Spring 3 and Spring 4 module documentation for more information.


1. An HTTP Request arrives

This is a Spring MVC application, as such it handles inbound HTTP traffic. The endpoint that is exposed is at http://localhost:8080/hello/. That is the only endpoint, and functionally, there isn't much going on.

When an HTTP GET is made against our endpoint, we pass in a name that we want to say hello to, like http://localhost:8080/hello/Jonas. The application responds with a message saying hello to Jonas. I know, I know, we have written an application that does it all, what more could you ever need!

This endpoint is exposed via the SampleController class. However, before the HTTP request makes it to the controller, we first inspect the HTTP Request for the presence of the X-MoneyTrace header. This is setup using the TraceFilter that comes with the money-java-servlet module.

To see how this is setup, open up the ServletInitializer class file, and you can see there that it is quite easy to add our filter by placing it in the array returned from the getServletFilters method.

You can also add the trace filter using the standard web.xml as well.

    @Override
    protected Filter[] getServletFilters() {
        CharacterEncodingFilter charFilter = new CharacterEncodingFilter();
        charFilter.setEncoding("UTF-8");
        charFilter.setForceEncoding(true);
        
        // See, we put our TraceFilter as the last element in the array, easy!
        return new Filter[] { 
            new HiddenHttpMethodFilter(), 
            charFilter,
            new HttpPutFormContentFilter(), 
            new TraceFilter() 
        };
    }

If the TraceFilter finds the X-MoneyTrace request header, it will put it in context, so that any spans created downstream will automatically inherit the incoming trace! Nothing mysterious there.

I will not go into detail here about what it means to put the trace in context, just know that it uses thread local behind the scenes, and the tracing code manages the propagation of that context across threads and executors.

2. The request hits our controller

Once the HTTP Request has made it past our filters, it will find its way via Spring Magic to our SampleController. The contents of the controller are rudimentary:

    @Autowired
    private AsyncRootService rootService;

    @Traced("SAMPLE_CONTROLLER")
    @RequestMapping(method = RequestMethod.GET, value = "/{name}")
    public String hello(@PathVariable("name") String name) throws Exception {

        return rootService.doSomething(name).get();
    }

Spring MVC maps the inbound HTTP Request onto our controller method. It passes the name as a path variable into our method (that is the thing we put in the URL after hello, call http://localhost:8080/hello/Joe and Spring will set our name to Joe when it calls this method.

Here, we see the first time we are using our @Traced annotation. This annotation is made available via the money-core module. The indication here is that we want to start and stop a span around the execution of this method. Here are some notes:

  • The value passed in "SAMPLE_CONTROLLER" is used as the name of the span when it is logged
  • The duration on the span that is generated is the time just before the execution of the method, to the time when the method completes execution.
  • If an exception is thrown from this method, the span will record a span-success=false
  • If the method finishes normally, the span will record a span-success=true
  • If there was an X-MoneyTrace header on the inbound request, the span will be started as a child span of that request (that is how we do distributed tracing in HTTP land)

The controller method does nothing interesting except calling the AsyncRootService.doSomething method. We will continue our journey there. It's funny that it is an "async" service, yet we do a .get on the Future which blocks, oh well.

In order to Activate the @Traced annotations that you use, you must perform the following:

  1. Configure the DefaultAdvisorAutoProxyCreator bean
  2. Added component scanning to com.comcast.money.spring3

The following is an example Annotation based configuration. The significant bits being the @ComponentScan and the bean that will do the advising. You must have the component scan and the auto proxy creator configured or you will not be tracing anything!

@Configuration
@ComponentScan(basePackages = {"com.comcast.money.samples.springmvc", "com.comcast.money.spring3"})
public class AopConfig {

    @Bean
    public DefaultAdvisorAutoProxyCreator defaultAdvisorAutoProxyCreator() {
        final DefaultAdvisorAutoProxyCreator defaultAdvisorAutoProxyCreator = new DefaultAdvisorAutoProxyCreator();
        defaultAdvisorAutoProxyCreator.setProxyTargetClass(true);
        return defaultAdvisorAutoProxyCreator;
    }
}

3. Making an asynchronous call to the root service

So, if you don't know, an asynchronous call is one whereby the method invocation happens on a separate thread of execution. What we are demonstrating here is how Money manages the trace context even across threads and different executors. Before popping into the service call itself, let's see how that is setup.

Open up the AppConfig class, and you will see that the demo provides two different Thread Pools for servicing requests. It has all of the Spring annotations, so it is magically all wired together.

public class AppConfig {

    @Bean(destroyMethod = "shutdown")
    public ExecutorService asyncRootService() {
        return TraceFriendlyExecutors.newCachedThreadPool();
    }

    @Bean(destroyMethod = "shutdown")
    public ExecutorService asyncNestedService(){
        return TraceFriendlyExecutors.newCachedThreadPool();
    }
}

The most significant part of this code is the use of TraceFriendlyExecutors.newCachedThreadPool();. This is provided by the money-core module, and ensures that all threads run under the correct trace context. Here, we create two separate thread pools, one for our AsyncRootService, and another for the AsyncNestedService, which we will cover later.

So back to our AsyncRootService, what does it do? Well, actually nothing except synchronously call another server inside of the Thread Pool we just looked at:

    @Autowired
    private RootService rootService;

    @Async("rootServiceExecutor")
    public Future<String> doSomething(String name) throws Exception {
        return new AsyncResult<String>(rootService.doSomething(name));
    }

The @Async("rootServiceExecutor") annotation is significant here. This is how we tell Spring to run this code in the Thread Pool that we configured in the AppConfig file we just covered. Essentially, this code runs asynchronously on a separate calling thread, and returns a java Future that allows you to get the result.

Let's open up the RootService here and see what it does.

    @Autowired
    private AsyncNestedService nestedService;

    @Traced("ROOT_SERVICE")
    public String doSomething(String name) throws Exception {

        int wait = RandomUtil.nextRandom(100, 500);
        Thread.sleep(wait);
        String message = name + ", made you wait " + wait + " milliseconds.";
        Money.tracer().record("wait", wait);

        timeIntensiveTask();

        return nestedService.doSomethingElse(message).get();
    }

    @Timed("ROOT_TIMED_TASK")
    private void timeIntensiveTask() throws Exception {
        Thread.sleep(50);
    }

Not a whole lot of interesting things in there, just some random thread waits. But lets review the Money stuff.

First, we once again see the @Traced annotation. This indicates that we are going to create a new child span of the span that we started in the SampleController. So here is what is happening:

  • A new trace span will be created with the name "ROOT_SERVICE".
  • The trace span will be linked to the span we created in the SampleController. We determine linkage because the new span will have a parentSpanId of its parent
  • The "ROOT_SERVICE" trace span will stop automatically once the method completes

One other significant line of code is the Money.tracer().record call. This is how we will attach an arbitrary piece of data to the "ROOT_SERVICE" trace span. The effect of this call is that a Note is recorded on the span with the value "wait", set to the random number that we generate.

But wait, there's more! Here, we also demonstrate the use of the @Timed annotation. Here is a description of what happens here:

  • Before the method starts, a timer will be started with the name "ROOT_TIMED_TASK"
  • Once the method completes, the timer will be stopped, and a new Note will be added to the trace span capturing the duration of the method invocation. As you can see here, it will be approximately 50 milliseconds.

Let's follow our journey to the AsyncNestedService call.

4. Calling to an external service using Http

I won't bore you with the details of the AsyncNestedService call. It is exactly the same as the AsyncRootService we saw earlier. The important takeaway is that we are going across yet another Thread of execution, in yet another executor. Money maintains the trace context across trace spans for you, so you can do this freely (assuming that you follow the same setup).

Let's open up the nested service and check it out.

private HttpClient httpClient = new DefaultHttpClient();

    @Traced("NESTED_SERVICE")
    public String doSomethingElse(String message) throws Exception {

        int wait = RandomUtil.nextRandom(100, 500);
        Money.tracer().record("wait", wait);

        // invoking the http client will activate the http tracing...
        callHttpClient();
        return message + ".  Nested service made you wait an additional " + wait + " milliseconds.";
    }

    // here, we will test that the http tracing works as expected
    private void callHttpClient() {

        try {
            // it doesn't really matter if it all works for sample purposes
            HttpResponse response = httpClient.execute(new HttpGet("http://www.google.com"));

            // need to call EntityUtils in order to tie into the http trace aspect
            // if you sniff the request, you will also see the X-MoneyTrace request header in the HTTP request
            String result = EntityUtils.toString(response.getEntity());
            Thread.sleep(1);
        } catch(Exception ex) {
            // just eat it
            ex.printStackTrace();
        }
    }

We see another @Traced annotation. This means that we are starting a new trace span, that will be a child span of the root trace span, and a grandchild of the Controller trace span. Money manages the lineage for you automagically.

We see another instance where we are recording data value. This value is captured on the "NESTED_SERVICE" span.

The most interesting item shown here is how we are using the Apache HTTP Client to make a call out to Google. Money is busy doing a lot of things behind the scenes for you to capture statistics on your outbound HTTP calls.

Money will track the following items:

  • How long it took for the external service to respond
  • The HTTP Status code of the response

These metrics are stored as additional Notes for you automatically by Money, without you needing to write any code!

But wait, it gets better. The money-http-client module will also attach the X-MoneyTrace request header to the outbound request, sending the current span id. Now, this is google, but if it was another system instrumented with Money being called, we would be able to continue tracking the lineage of the trace!

Go to samples/samples-springmvc and from the terminal run:

>mvn clean jetty:run-forked

Once it has started, go to http://localhost:8080/hello/Sam in your browser to run a request and view the output.

The following output is generated (or something similar)

[money-akka.actor.default-dispatcher-3] [akka://money/user/emitter/log-emitterr] 
Span: [ span-id=-931713569499083109 ][ trace-id=314e14fe-bf91-489a-bcad-5286c824bd6b][ parent-id=-931713569499083109 ]
[ span-name=SAMPLE_CONTROLLER ][ start-time=1412649895390 ][ span-success=true ]
[ span-duration=1103.0 ][STDOUT] [WARN] [10/06/2014 22:44:57.585] 

[money-akka.actor.default-dispatcher-3] [akka://money/user/emitter/log-emitterr] 
Span: [ span-id=-1898818534231861520 ][ trace-id=8e46b05d-32c1-476a-819d-4cf1f1d64512][ parent-id=-5722794285453614155 ]
[ name=NESTED_SERVICE ][ start-time=1412649895906 ]
[ http-call-duration=549.0 ][ http-call-with-body-duration=572.0 ]
[ http-process-response-duration=3.0 ][ http-status-code=200 ]
[ nested-wait=167.0 ][ span-success=true ][ span-duration=586.0 ]
[STDOUT] [WARN] [10/06/2014 22:44:57.586] 

[money-akka.actor.default-dispatcher-3] [akka://money/user/emitter/log-emitterr] 
Span: [ span-id=-5722794285453614155 ][ traceId=aff70843-3ab6-4722-a6e3-e469fb90d44b][ parent-id=-931713569499083109 ]
[ name=ROOT_SERVICE ][ start-time=1412649895404 ][ ROOT_TIMED_TASK=51 ]
[ span-success=true ][ span-duration=1089.0 ][ wait=444.0 ]

Here are some takeaways:

  • The parent-ids link together to establish the trace lineage. The parent-id of NESTED_SERVICE is the span-id value of ROOT_SERVICE.
  • Further, the parent-id of the ROOT_SERVICE is the span-id of the SAMPLE_CONTROLLER
  • Check out all of those metrics stored in the NESTED_SERVICE. Those are generated by the money-http-client.
  • The ROOT_TIMED_TASK has a value of 51, which is how long it took to complete that little method where we did a Thread.sleep(50)
  • Every span captures how long each span took, in the span-duration

Wrapping up

Hopefully, you have seen how to setup and use money in an application. Here we covered:

  • How do pull Money into a Maven project
  • How to setup a Servlet Filter so that you can participate in a distributed system instrumented with Money
  • How to use Tracing annotations to capture trace spans
  • How to setup Thread Pools to allow us to maintain a consistent trace context across threads
  • How to use Apache HTTP Client so that key metrics are captured