How to log request information for future data analysis [Spring MVC + AOP + MongoDB]

Today I would like to speak a little bit about very popular task - logging information about incoming requests in order to have data for future analysis.

Well, this is a common requirement for such areas as E-commerce, social portals, services and so on. From the first look the task is very simple: all you have to do is just log data about incoming requests, responses and other additional data. But when you start thinking deeply about what kind of storage you will be using, what is the requirements for the data analyzer, you will understand that's it's not so trivial and you have to keep in mind a lot of things to build a correct architecture. 

Let's assume that your system is under impressive loading like 1000 requests per second. In such situation the system will produce terabytes of data and probably storing such huge amount of data either in files or in SQL-database is not a good option. So, you might want to ask yourself - which direction should I choose?

I would propose to implement something similar to the following architecture and choose components depending on your specific requirements:

So, imagine that your web server sends log messages first to some broker using JMS or AMQP. You might want to use logstash - a tool for managing events and logs, which I have glossed over until now. I'd highly recommend to take a look at it. Eventually all messages will be stored in a storage - either in NoSQL-storage like MongoDB or in Index-storage like Lucene. Strictly speaking in this case your application is doing its main job without spending additional resources for processing logs. All it does is only sending messages to the "messages bus" to be stored somewhere for future analysis. Choosing storage completely depends on your needs.

In this article I wanna show you simple example how you can achieve it. In order to make it understandable I simplified the architecture a little bit and remove part with Logstash/RabbitMQ (but it's still required for such kind of tasks). So, technologies/frameworks for this small maven project are: Spring/Spring MVC, AOP, MongoDB. Let's start...

I assume that you already have MongoDB installed, up and running. If not - take a look at this tutorial first.

So, as a first step you need to create a simple web-app project. For this purpose you can use maven archetype:

mvn archetype:generate -DgroupId={groupId} -DartifactId={artifactId} -DarchetypeArtifactId=maven-archetype-webapp

Then you have to modify pom.xml file:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/maven-v4_0_0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <groupId>com.vadymlotar.demo</groupId>
    <artifactId>springMongoDB</artifactId>
    <packaging>war</packaging>
    <version>1.0.0</version>
    <name>springMongoDB</name>
   
    <properties>
        <org.springframework-version>3.2.2.RELEASE</org.springframework-version>
        <org.springframework.data-version>1.2.1.RELEASE</org.springframework.data-version>
        <org.aspectj-version>1.6.10</org.aspectj-version>
    </properties>
   
    <dependencies>
        <!-- Spring -->
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-orm</artifactId>
            <version>${org.springframework-version}</version>
        </dependency>

        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-webmvc</artifactId>
            <version>${org.springframework-version}</version>
        </dependency>
       
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-aop</artifactId>
            <version>${org.springframework-version}</version>
        </dependency>

        <dependency>
            <groupId>org.springframework.data</groupId>
            <artifactId>spring-data-mongodb</artifactId>
            <version>${org.springframework.data-version}</version>
        </dependency>
       
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-test</artifactId>
            <version>${org.springframework-version}</version>
        </dependency>
       
        <!-- Servlet -->
        <dependency>
            <groupId>javax.servlet</groupId>
            <artifactId>servlet-api</artifactId>
            <version>2.5</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>javax.servlet.jsp</groupId>
            <artifactId>jsp-api</artifactId>
            <version>2.2</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>javax.servlet</groupId>
            <artifactId>jstl</artifactId>
            <version>1.2</version>
        </dependency>           
       
        <!-- AspectJ -->
        <dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjtools</artifactId>
            <version>1.7.2</version>
        </dependency>
        <dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjrt</artifactId>
            <version>${org.aspectj-version}</version>
        </dependency>   
       
        <!-- Test -->
        <dependency>
            <groupId>junit</groupId>
            <artifactId>junit</artifactId>
            <version>4.10</version>
            <scope>test</scope>
        </dependency>
    </dependencies>
    <build>
        <finalName>springMongoDB</finalName>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>2.5.1</version>
                <configuration>
                    <source>1.7</source>
                    <target>1.7</target>
                    <compilerArgument>-Xlint:all</compilerArgument>
                    <showWarnings>true</showWarnings>
                    <showDeprecation>true</showDeprecation>
                </configuration>
            </plugin>
        </plugins>
    </build>
</project>

Do not forget about Spring configuration file:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:context="http://www.springframework.org/schema/context"
       xmlns:p="http://www.springframework.org/schema/p"
       xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.2.xsd http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.2.xsd http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.0.xsd">

    <context:component-scan base-package="com.vadymlotar.demo" />

    <!-- Factory bean that creates the MongoDB instance -->
    <bean id="mongo" class="org.springframework.data.mongodb.core.MongoFactoryBean">
        <property name="host" value="localhost" />
    </bean>
    
    <!-- MongoTemplate for connecting and querying the documents in the database -->
    <bean id="mongoTemplate" class="org.springframework.data.mongodb.core.MongoTemplate">
        <constructor-arg name="mongo" ref="mongo" />
        <constructor-arg name="databaseName" value="test" />
    </bean>

    <!-- Use this post processor to translate any MongoExceptions thrown in @Repository annotated classes -->
    <bean class="org.springframework.dao.annotation.PersistenceExceptionTranslationPostProcessor" />
    
        
    <bean id="jspViewResolver"
          class="org.springframework.web.servlet.view.InternalResourceViewResolver"
          p:prefix="/WEB-INF/jsp/"
          p:suffix=".jsp" />
         
    <!-- Enable Aspects -->     
    <aop:aspectj-autoproxy/>

</beans> 

Create controller which will handle all requests mapped on /home:

@Controller
public class MainController {

    @RequestMapping(value = "/home", method = RequestMethod.GET)
    public ModelAndView show() throws InterruptedException {
        ModelAndView mv = new ModelAndView("/home");
        mv.addObject("message", "Recieved and logged one more request");

        // do some 'real' work
        Random random = new Random();
        int randomDelay = random.nextInt(200);
        Thread.sleep(randomDelay);

        return mv;
    }

}

In order to log requests we need to create POJO class:

public class LogItem {
    @Id
    private String id;
    private String response;
    private long requestDuration;
    private Date date;

    public String getId() {
        return id;
    }
    public void setId(String id) {
        this.id = id;
    }
    public long getRequestDuration() {
        return requestDuration;
    }
    public void setRequestDuration(long requestDuration) {
        this.requestDuration = requestDuration;
    }
    public String getResponse() {
        return response;
    }
    public void setResponse(String response) {
        this.response = response;
    }
    public Date getDate() {
        return date;
    }
    public void setDate(Date date) {
        this.date = date;
    }   
}

This POJO can be extended according to your specific needs.

Then we have to create service class which will be responsible for saving the log data to the MongoDB:

public interface LogItemService {   
    static final String COLLECTION_NAME = "requests";   
    public void addLogItem(LogItem logItem);
}

@Repository
public class LogItemServiceImpl implements LogItemService {

    @Autowired
    private MongoTemplate mongo;

    public void addLogItem(LogItem logItem) {
        initCollectionInMongo();
        // fill out required fields
        logItem.setId(UUID.randomUUID().toString());
        logItem.setDate(new Date());
        // save object in MongoDB
        mongo.insert(logItem, COLLECTION_NAME);
    }

    /**
     * If collection does not exist then creates new collection and registers
     * required indexes
     */
    private void initCollectionInMongo() {
        if (!mongo.collectionExists(COLLECTION_NAME)) {
            // create collection
            DBCollection collection = mongo.createCollection(COLLECTION_NAME);
            // create Time-To-Live Index
            BasicDBObject index = new BasicDBObject("date", 1);
            BasicDBObject options = new BasicDBObject("expireAfterSeconds",
                    TimeUnit.MINUTES.toSeconds(60));
            collection.ensureIndex(index, options);
            // create index for requestDuration column
            index = new BasicDBObject("requestDuration", 1);
            collection.ensureIndex(index);
        }
    }  
}

One of the main steps is to create an advice which will allow us to collect information about incoming request:

@Component
@Aspect
public class RequestLoggerAspect {
   
    @Autowired
    private LogItemService responseItemService;

    /**
     * Advice which allows to do some operations with logging before and after
     * method execution
     *
     * @param joinPoint
     *            joinPoint object describing the calling method
     * @return result of method execution
     * @throws Throwable
     *             an exception could be thrown
     */
    @Around("execution(* com.vadymlotar.demo.controller..MainController*.*(..))")
    public Object logTimeMethod(ProceedingJoinPoint joinPoint) throws Throwable {
        // execution of method started
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        Object retVal = joinPoint.proceed();
        // execution of method finished
        stopWatch.stop();
        // prepare string which will appear in the log
        StringBuffer logMessage = new StringBuffer();
        logMessage.append(joinPoint.getTarget().getClass().getName());
        logMessage.append(".");
        logMessage.append(joinPoint.getSignature().getName());
        logMessage.append("(");
        // append args
        Object[] args = joinPoint.getArgs();
        for (int i = 0; i < args.length; i++) {
            logMessage.append(args[i]).append(",");
        }
        if (args.length > 0) {
            logMessage.deleteCharAt(logMessage.length() - 1);
        }

        logMessage.append(")");
        logMessage.append(" execution time: ");
        logMessage.append(stopWatch.getTotalTimeMillis());
        logMessage.append(" ms");
        System.out.println(logMessage.toString());
       
        //save information about request in MongoDB
        LogItem responseItem = new LogItem();
        responseItem.setRequestDuration(stopWatch.getTotalTimeMillis());
        responseItem.setResponse(retVal.toString());
        responseItemService.addLogItem(responseItem);
       
        return retVal;
    }
}
AOP concepts are well explained in Spring documentation. It takes a bit of getting used to, but it's a very powerful thing.

So, now you can deploy the application to some servlet container (e.g. Tomcat or Jetty) and go to http://localhost:8080/%appContext%. Each time you will open this page, a new request information will be put to the MongoDB.

With MongoDB you can analyze the data using MapReduce. For example, in order to know average duration time of request processing you may want to create following map and reduce functions:

// get avg request duration
        String mapFunction = "function(){emit( 'avg',this.requestDuration);}";
        String reduceFunction = "function(key,values){ var total = 0; for(var i = 0; i < values.length; i++) total += values[i]; var mean = total/values.length;return mean;}";

        @SuppressWarnings("rawtypes")
        MapReduceResults<Map> result = mongo.mapReduce(COLLECTION_NAME,
                mapFunction, reduceFunction, Map.class);
        for (Map<String, Double> map : result) {
            requestStatistics.setAvgDuration(map.get("value"));
        }

The completed project contains a lot of examples of how to analyze collected data and you can download project sources here.

In conclusion I would like to say that I do not impose you to choose the technologies for such kind of tasks. You can use whatever you want and whatever is suitable for this task. If you have any comments, remarks or questions don't hesitate to leave your comments below and I'll try to answer.

Thank you for reading and may the force be with you...