DDevelopment & Design

Deep dive into Spring Boot Actuator HTTP metrics

Actuator Metrics

As reported in Michał Bobowski post, we heavily use Spring Boot Actuator metrics system based on Micrometer. It provides a set of practical metrics regarding JVM stats like CPU or memory utilization. Our applications have to meet the most sophisticated needs of our clients thus we try to take advantage of http.server.request endpoint.

Introduction

By default, Spring Boot Actuator gathers endpoint statistics for all classes annotated with @RestController. It registers a WebMvcMetricsFilter bean, which is responsible for timing a request. A special TimingContext attribute is attached to the request so that Spring Boot knows when the request started.

Actuator metrics model

When you call http://localhost:8080/actuator/metrics/http.server.request endpoint you will get something similar to this:

{
  "name": "http.server.requests",
  "description": null,
  "baseUnit": "milliseconds",
  "measurements": [
    {
      "statistic": "COUNT",
      "value": 12
    },
    {
      "statistic": "TOTAL_TIME",
      "value": 21487.256644
    },
    {
      "statistic": "MAX",
      "value": 2731.787888
    }
  ],
  "availableTags": [
    {
      "tag": "exception",
      "values": [
        "None",
        "RuntimeException"
      ]
    },
    {
      "tag": "method",
      "values": [
        "GET"
      ]
    },
    {
      "tag": "uri",
      "values": [
        "/example/success"
      ]
    },
    {
      "tag": "outcome",
      "values": [
        "SERVER_ERROR",
        "SUCCESS"
      ]
    },
    {
      "tag": "status",
      "values": [
        "500",
        "200"
      ]
    }
  ]
}

You will surely see the measurements section. It provides types and values of statistics recorded at a certain point in time. Types of statistics are ones described in Statistics enum.
Another one is the availableTags section, which contains a set of default tags distinguishing each metric by URI, status, or method. You can easily put your tags there like a host or container. If you want to check metric for a particular tag, Actuator lets you do this by using tag query http://localhost:8080/actuator/metrics/http.server.request?tag=status:200

Metric system model

However, each monitoring system has its own metrics model and therefore uses different names for the same things. In our case, we use Influx Registry.
Let’s look into InfluxMeterRegistry class implementation.

private Stream writeTimer(Timer timer) {
    final Stream fields = Stream.of(
        new Field("sum", timer.totalTime(getBaseTimeUnit())),
        new Field("count", timer.count()),
        new Field("mean", timer.mean(getBaseTimeUnit())),
        new Field("upper", timer.max(getBaseTimeUnit()))
    );

    return Stream.of(influxLineProtocol(timer.getId(), "histogram", fields));
}

We see which field in influx corresponds to actuators measurement. Moreover, our registry equips us with an additional mean field, which is basically TOTAL_TIME divided by COUNT. Therefore we don’t need to calculate it manually inside our monitoring system.

Summary

(1) Be aware that the Actuator metric model directly corresponds to Micrometer model
(2) When it comes to timing requests carefully choose the step in which metrics are exported
(3) Do not mix composing metric values with aggregations, selectors, and transformations, e.g. mean(mean)

— Previous article

The experience of developing “Quak” during a hackathon.

Next article —

Being agile in 2019

You May Also Like
DDevelopment & Design

JBoss Envers and Spring transaction managers

I've stumbled upon a bug with my configuration for JBoss Envers today, despite having integration tests all over the application. I have to admit, it casted a dark shadow of doubt about the value of all the tests for a moment. I've been practicing TDD since 2005, and frankly speaking, I should have been smarter than that.

My fault was simple. I've started using Envers the right way, with exploratory tests and a prototype. Then I've deleted the prototype and created some integration tests using in-memory H2 that looked more or less like this example:

@Test
public void savingAndUpdatingPersonShouldCreateTwoHistoricalVersions() {
    //given
    Person person = createAndSavePerson();
    String oldFirstName = person.getFirstName();
    String newFirstName = oldFirstName + "NEW";

    //when
    updatePersonWithNewName(person, newFirstName);

    //then
    verifyTwoHistoricalVersionsWereSaved(oldFirstName, newFirstName);
}

private Person createAndSavePerson() {
    Transaction transaction = session.beginTransaction();
    Person person = PersonFactory.createPerson();
    session.save(person);
    transaction.commit();
    return person;
}    

private void updatePersonWithNewName(Person person, String newName) {
    Transaction transaction = session.beginTransaction();
    person.setFirstName(newName);
    session.update(person);
    transaction.commit();
}

private void verifyTwoHistoricalVersionsWereSaved(String oldFirstName, String newFirstName) {
    List<Object[]> personRevisions = getPersonRevisions();
    assertEquals(2, personRevisions.size());
    assertEquals(oldFirstName, ((Person)personRevisions.get(0)[0]).getFirstName());
    assertEquals(newFirstName, ((Person)personRevisions.get(1)[0]).getFirstName());
}

private List<Object[]> getPersonRevisions() {
    Transaction transaction = session.beginTransaction();
    AuditReader auditReader = AuditReaderFactory.get(session);
    List<Object[]> personRevisions = auditReader.createQuery()
            .forRevisionsOfEntity(Person.class, false, true)
            .getResultList();
    transaction.commit();
    return personRevisions;
}

Because Envers inserts audit data when the transaction is commited (in a new temporary session), I thought I have to create and commit the transaction manually. And that is true to some point.

My fault was that I didn't have an end-to-end integration/acceptance test, that would call to entry point of the application (in this case a service which is called by GWT via RPC), because then I'd notice, that the Spring @Transactional annotation, and calling transaction.commit() are two, very different things.

Spring @Transactional annotation will use a transaction manager configured for the application. Envers on the other hand is used by subscribing a listener to hibernate's SessionFactory like this:

<bean id="sessionFactory" class="org.springframework.orm.hibernate3.annotation.AnnotationSessionFactoryBean" >        
...
 <property name="eventListeners">
     <map key-type="java.lang.String" value-type="org.hibernate.event.EventListeners">
         <entry key="post-insert" value-ref="auditEventListener"/>
         <entry key="post-update" value-ref="auditEventListener"/>
         <entry key="post-delete" value-ref="auditEventListener"/>
         <entry key="pre-collection-update" value-ref="auditEventListener"/>
         <entry key="pre-collection-remove" value-ref="auditEventListener"/>
         <entry key="post-collection-recreate" value-ref="auditEventListener"/>
     </map>
 </property>
</bean>

<bean id="auditEventListener" class="org.hibernate.envers.event.AuditEventListener" />

Envers creates and collects something called AuditWorkUnits whenever you update/delete/insert audited entities, but audit tables are not populated until something calls AuditProcess.beforeCompletion, which makes sense. If you are using org.hibernate.transaction.JDBCTransaction manually, this is called on commit() when notifying all subscribed javax.transaction.Synchronization objects (and enver's AuditProcess is one of them).

The problem was, that I used a wrong transaction manager.

<bean id="transactionManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager" >
    <property name="dataSource" ref="dataSource"/>
</bean>

This transaction manager doesn't know anything about hibernate and doesn't use org.hibernate.transaction.JDBCTransaction. While Synchronization is an interface from javax.transaction package, DataSourceTransactionManager doesn't use it (maybe because of simplicity, I didn't dig deep enough in org.springframework.jdbc.datasource), and thus Envers works fine except not pushing the data to the database.

Which is the whole point of using Envers.

Use right tools for the task, they say. The whole problem is solved by using a transaction manager that is well aware of hibernate underneath.

<bean id="transactionManager" class="org.springframework.orm.hibernate3.HibernateTransactionManager" >
    <property name="sessionFactory" ref="sessionFactory"/>
</bean>

Lesson learned: always make sure your acceptance tests are testing the right thing. If there is a doubt about the value of your tests, you just don't have enough of them,
DDevelopment & Design

Inconsistent Dependency Injection to domains with Grails

I've encountered strange behavior with a domain class in my project: services that should be injected were null. I've became suspicious as why is that? Services are injected properly in other domain classes so why this one is different?

Constructors experiment

I've created an experiment. I've created empty LibraryService that should be injected and Book domain class like this:

class Book {
    def libraryService

    String author
    String title
    int pageCount

    Book() {
        println("Finished constructor Book()")
    }

    Book(String author) {
        this()
        this.@author = author
        println("Finished constructor Book(String author)")
    }

    Book(String author, String title) {
        super()
        this.@author = author
        this.@title = title
        println("Finished constructor Book(String author, String title)")
    }

    Book(String author, String title, int pageCount) {
        this.@author = author
        this.@title = title
        this.@pageCount = pageCount
        println("Finished constructor Book(String author, String title, int pageCount)")
    }

    void logInjectedService() {
        println("    Service libraryService is injected? -> $libraryService")
    }
}
class LibraryService {
    def serviceMethod() {
    }
}

Book has 4 explicit constructors. I want to check which constructor is injecting dependecies. This is my method that constructs Book objects and I called it in controller: 

class BookController {
    def index() {
        constructAndExamineBooks()
    }

    static constructAndExamineBooks() {
        println("Started constructAndExamineBooks")
        Book book1 = new Book().logInjectedService()
        Book book2 = new Book("foo").logInjectedService()
        Book book3 = new Book("foo", 'bar').logInjectedService()
        Book book4 = new Book("foo", 'bar', 100).logInjectedService()
        Book book5 = new Book(author: "foo", title: 'bar')
        println("Finished constructor Book(Map params)")
        book5.logInjectedService()
    }
}

Analysis

Output looks like this:

Started constructAndExamineBooks
Finished constructor Book()
    Service libraryService is injected? -> eu.spoonman.refaktor.LibraryService@2affcce2
Finished constructor Book()
Finished constructor Book(String author)
    Service libraryService is injected? -> eu.spoonman.refaktor.LibraryService@2affcce2
Finished constructor Book(String author, String title)
    Service libraryService is injected? -> null
Finished constructor Book(String author, String title, int pageCount)
    Service libraryService is injected? -> null
Finished constructor Book()
Finished constructor Book(Map params)
    Service libraryService is injected? -> eu.spoonman.refaktor.LibraryService@2affcce2

What do we see?

  1. ✔

    Empty constructor injects dependencies.

  2. ✔

    Constructor that invokes empty constructor explicitly injects dependencies.

  3. ✘

    Constructor that invokes parent's constructor explicitly does not inject dependencies.

  4. ✘

    Constructor without any explicit call declared does not call empty constructor thus it does not inject dependencies.

  5. ✔

    Constructor provied by Grails with a map as a parameter invokes empty constructor and injects dependencies.

Conclusion

Always explicitily invoke empty constructor in your Grail domain classes to ensure Dependency Injection! I didn't know until today either!