Friday, July 28, 2017

Web Caching aka Stragegize for better economy. And how to do it with Java

The best metaphor I read for caching comes from Peter Chester which he used during a wordpress conference. He asked the audience, “what’s 3.485.250 divided by 23.235?” After the initial silence, some people took their calculators out and finally someone yelled the answer “150”. Then Mr. Chester asked again the same question - to which immediately everyone was able to respond. And this is caching!

In all fairness, this is a very simple case of caching, because the answer is always the same. But the metaphor is fantastic! In its essence, caching is about economy. We save time for clients that are waiting for responses. We save our resources from re-calculating answers we already know. We save on bandwidth.

How do we do that? By keeping some of the responses “closer” to the requesters and serving them again without having to go back to the origin server and calculate the answer again.

This is not a straightforward task and it requires serious strategy in its implementation. We need to evaluate the “end goals” of our application, the nature of our data, the users of our application, the existing design of the application and the actual purpose for our caching. The are various dangers if our strategy is not well thought. Examples?

We could expose sensitive data that could harm our users. We may serve stale/invalid data which depending on the application could be catastrophic. We could even hurt our performance, if we have a bad cache hit ratio, which is simply the number of requests  that can be served from the cache divided by the total requests served.

You might ask, why not just save everything in cache? Again, economy! Caching is usually done in-memory which is more expensive than database storage. Also replicating our whole database can be expensive and very complicated.

So, how we decide what to keep in the database and how much space to allocate for it? In what order we evict items from the cache when it gets full? Well, it is more like an art. We make a hypothesis, monitor if and how it works and adjust accordingly. Is this whole exercise worth our trouble?

We can be optimistic that some data will be more popular than the rest relying on principles like locality of reference  and the pareto principle.  So yes, caching can be worth it.

Let’s take a high level view of a Web application in order to introduce some terms related to caching and put some grounds under our different scenarios. Consider a typical multitier application. On the base level we have the origin server which provide access to data from some kind of repository and performs calculations. On the other end is a client, typically a web browser, from which users can see and access the great applications and offerings of the origin server. Between them, a number of other components can act as mediators passing the data from the origin server to the browser for our users' satisfaction.

Now, the main way in which these layers cooperate for caching is by signaling each other their rules or preferences. This is done through HTTP headers. I will not go into detail on all headers related to caching, but we can broadly categorize them in terms of how they work.

Time
Certain headers are used to signal the time period a cached resource is considered fresh. A resource is fresh when it can be used to serve a request, meaning it is in state with the resource in the origin server. Content that is not fresh is called stale. These headers are provided in the Cache-Control and the most common are:
  • max-age: which is the time period before cached resource has to be revalidated
  • s-maxage: same as max-age but is used for intermediate caches. Combined they can provide flexibility in our caching policy
  • max-stale: used by clients willing to accept responses that exceeded the expiration time
  • min-fresh: used by clients that require responses to be fresh in time period specified (by them)

As you can understand, this time based caching, does not really guarantee that the content we receive from cache is not stale. It can happen that immediately after a resource is cached, it is updated in the origin server. But this kind of caching has its uses. For example having such a policy for a couple of seconds can protect us from a user that keeps pressing f5.

State
Then what about caching based on the state of the object? There are headers that can help with that:
  • ETag: is a value the origin server provides along with a resource. In subsequent requests for this resource the client provides the ETag and the server checks if the resource changed (based on the calculated ETag) or not and responds accordingly
  • Last-modified: in a similar way the server provides the last modification time with a resource, the client uses it in the next requests and based on the last modification date of the resource either responds it is not modified or serves the updated resource with the new last modification time

These headers surely ensure that the cached content is in state with the origin server. But they do not really save us from calculations, the origin server still has to evaluate the etag of the resource or check its last-modified time. But it can save us on bandwidth when the resource is not modified, because it does not send it again (responds with HTTP 304).

So we still want something better, I will give a simple example later in the tutorial on ways to keep our cache fresh. But for now let's close with some other headers which give directives regarding the content to be cached. For example if the content can be cached or not, by whom, if it can be transformed and if the responses must be revalidated.

  • no-store: requests that no resource can be cached in any way and is important to be used with sensitive data
  • no-cache: requests that any cache request has to be revalidated each time. Does not mean that all the internal calculations have to be repeated, just make sure the cached resource is in state with the origin server
  • private: instructs that the resource cannot be cached by intermediate caches
  • public: allows resources to be cached by intermediate caches
  • content-length: specifies the size of the resource to be cached
  • no-transform: requests that the resource will not be transformed in any way (e.g., compress for performance reasons)
  • must-revalidate: instructs that max-age and s-managed must be followed (and not for example serve stale content in case of network interruption)
  • proxy-revalidate: same as must-revalidate but used in intermediate caches

Ok, so now that we have an understanding of how Web caching works, lets see how to implement these in code. I created a small project for the tutorial which you can find on my github. We start with our pom, which is fairly simple because we will use Spring Boot and it provides many of the dependencies for us. Also we will use EhCcache and other dependencies which you can see in the pom below.

<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.tasosmartidis.caching-demo</groupId>
  <artifactId>caching-demo</artifactId>
  <version>1.0-SNAPSHOT</version>
  <packaging>war</packaging>

  <properties>
      <webappDirectory>${project.build.directory}/${project.build.finalName}</webappDirectory>
      <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>

      <springframework.context-support.version>4.1.0.RELEASE</springframework.context-support.version>
      <ehcache-version>2.10.2.2.21</ehcache-version>
      <lombok-version>1.16.18</lombok-version>
      <assertj.version>1.7.0</assertj.version>
      <rest-assured.version>2.4.0</rest-assured.version>
      <groovy-version>2.4.5</groovy-version>
  </properties>

  <parent>
      <groupId>org.springframework.boot</groupId>
      <artifactId>spring-boot-starter-parent</artifactId>
      <version>1.4.3.RELEASE</version>
  </parent>

  <dependencies>
      <!-- core application -->
      <dependency>
          <groupId>org.springframework.boot</groupId>
          <artifactId>spring-boot-starter-web</artifactId>
      </dependency>
      <dependency>
          <groupId>org.springframework</groupId>
          <artifactId>spring-context-support</artifactId>
          <version>${springframework.context-support.version}</version>
      </dependency>
      <dependency>
          <groupId>net.sf.ehcache</groupId>
          <artifactId>ehcache</artifactId>
          <version>${ehcache-version}</version>
      </dependency>
      <dependency>
          <groupId>org.projectlombok</groupId>
          <artifactId>lombok</artifactId>
          <version>${lombok-version}</version>
      </dependency>

      <!-- test -->
      <dependency>
          <groupId>org.springframework.boot</groupId>
          <artifactId>spring-boot-starter-test</artifactId>
          <scope>test</scope>
      </dependency>
      <dependency>
          <groupId>org.assertj</groupId>
          <artifactId>assertj-core</artifactId>
          <version>${assertj.version}</version>
          <scope>test</scope>
      </dependency>
      <dependency>
          <groupId>com.jayway.restassured</groupId>
          <artifactId>rest-assured</artifactId>
          <version>${rest-assured.version}</version>
          <scope>test</scope>
      </dependency>
      <dependency>
          <groupId>org.codehaus.groovy</groupId>
          <artifactId>groovy-all</artifactId>
          <version>${groovy-version}</version>
          <scope>test</scope>
      </dependency>

  </dependencies>

  <build>
      <finalName>caching-demo</finalName>
      <outputDirectory>${webappDirectory}/WEB-INF/classes</outputDirectory>
      <pluginManagement>
          <plugins>
              <plugin>
                  <artifactId>maven-compiler-plugin</artifactId>
                  <version>3.0</version>
                  <configuration>
                      <source>1.8</source>
                      <target>1.8</target>
                  </configuration>
              </plugin>
              <plugin>
                  <groupId>org.apache.maven.plugins</groupId>
                  <artifactId>maven-war-plugin</artifactId>
                  <configuration>
                      <failOnMissingWebXml>false</failOnMissingWebXml>
                      <webappDirectory>${webappDirectory}</webappDirectory>
                  </configuration>
              </plugin>
              <plugin>
                  <groupId>org.springframework.boot</groupId>
                  <artifactId>spring-boot-maven-plugin</artifactId>
              </plugin>
          </plugins>
      </pluginManagement>
  </build>

</project>

Next, we will setup the configuration for our REST application. We extend the AbstractAnnotationConfigDispatcherServletInitializer’ class which registers a ContextLoaderlistener and a DispatcherServlet. This simplifies our work and we can define configuration classes (e.g. for the servlets) and servlet mappings.

package com.tasosmartidis.caching_demo.config;

import org.springframework.web.servlet.support.AbstractAnnotationConfigDispatcherServletInitializer;

public class WebAppInitializer extends AbstractAnnotationConfigDispatcherServletInitializer {

  @Override
  protected Class<?>[] getRootConfigClasses() {
      return new Class[] { RootConfig.class };
  }

  @Override
  protected Class<?>[] getServletConfigClasses() {
      return new Class[] { WebConfig.class } ;
  }

  @Override
  protected String[] getServletMappings() {
      return new String[] { "/" };
  }

}

The WebAppInitializer class has only 3 methods. The getServletMappings() indicates the paths in which the DispatcherServlet will be mapped to. We map it to the default servlet which will handle all requests coming into our application. The getRootConfigClasses() handles the configuration of the application context created by ContextLoaderListener. Finally the getServletConfigClasses() handles the configuration for the DispacherServlet.

In our RootConfig class we will create the generic purpose beans, in this case the beans for EhCache which will provide us the caching support.

package com.tasosmartidis.caching_demo.config;

import org.springframework.cache.CacheManager;
import org.springframework.cache.annotation.EnableCaching;
import org.springframework.cache.ehcache.EhCacheCacheManager;
import org.springframework.cache.ehcache.EhCacheManagerFactoryBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.ComponentScan;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.io.ClassPathResource;

@Configuration
@EnableCaching
@ComponentScan("com.tasosmartidis.caching_demo")
public class RootConfig {

  private static final String EHCACHE_CONFIGURATION = "ehcache.xml";

  @Bean
  public CacheManager cacheManager() {
      return new EhCacheCacheManager(ehCacheCacheManager().getObject());
  }

  @Bean
  public EhCacheManagerFactoryBean ehCacheCacheManager() {
      EhCacheManagerFactoryBean factory = new EhCacheManagerFactoryBean();
      factory.setConfigLocation(new ClassPathResource(EHCACHE_CONFIGURATION));
      factory.setShared(true);
      return factory;
  }

}

In the WebConfig class we will attach interceptors which we will use to log the start and end of incoming calls.

package com.tasosmartidis.caching_demo.config;

import com.tasosmartidis.caching_demo.utils.LoggingInterceptor;
import org.springframework.context.annotation.ComponentScan;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.DefaultServletHandlerConfigurer;
import org.springframework.web.servlet.config.annotation.EnableWebMvc;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurerAdapter;


@Configuration
@EnableWebMvc
@ComponentScan("com.tasosmartidis.caching_demo")
public class WebConfig extends WebMvcConfigurerAdapter {

  @Override
  public void configureDefaultServletHandling(DefaultServletHandlerConfigurer configurer) {
      configurer.enable();
  }

  @Override
  public void addInterceptors(final InterceptorRegistry registry) {
      registry.addInterceptor(new LoggingInterceptor()).addPathPatterns("/**");
  }

}

The LoggingInterceptor class implements the HandleInterceptor interface and its implementation looks like the following:

package com.tasosmartidis.caching_demo.utils;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

public class LoggingInterceptor implements HandlerInterceptor {

  private static final Logger LOGGER = LoggerFactory.getLogger(LoggingInterceptor.class);

  @Override
  public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
          throws Exception {

      LOGGER.info("-------------------------");
      LOGGER.info("--- Request made --------");
      return true;
  }

  @Override
  public void postHandle(    HttpServletRequest request, HttpServletResponse response,
                             Object handler, ModelAndView modelAndView) throws Exception { }

  @Override
  public void afterCompletion(HttpServletRequest request, HttpServletResponse response,
                              Object handler, Exception ex) throws Exception {

      LOGGER.info("--- Request Completed ---");
      LOGGER.info("-------------------------");
  }
}

And now that we are in utils classes and logging, here is another one that we use to log when methods were entered, started and finished.

package com.tasosmartidis.caching_demo.utils;

import org.slf4j.Logger;

public class LoggingUtils {

  public static void logMethodEntered(Logger logger) {
      logger.info("Got into the method!");
  }

  public static void logResponse(String message, Logger logger) {
      logger.info(message);
      logger.info("");
  }

  public static void logExplanationMessage(String message, Logger logger) {
      logger.info(message);
  }

  public static void logMethodUnderTestStart(String methodName, Logger logger) {
      logger.info("Test for method '{}' started...", methodName);
  }

  public static void logMehodUnderTestEnd(String methodName, Logger logger) {
      logger.info("Test for method '{}' finished...", methodName);
  }
}

We are almost ready to get into the jist of our demo project. The types of caching we are going to see are time-based caching, state-based caching and invalidation of caching. As mentioned before, we use EhCache for our caching and following is the file that contains our caching configuration.


<ehcache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:noNamespaceSchemaLocation="ehcache.xsd"
       updateCheck="true"
       monitoring="autodetect"
       dynamicConfig="true">

  <diskStore path="java.io.tmpdir" />

  <cache name="time-based-short-lived"
         maxEntriesLocalHeap="100"
         maxEntriesLocalDisk="1000"
         eternal="false"
         timeToIdleSeconds="10"
         timeToLiveSeconds="10"
         memoryStoreEvictionPolicy="LFU"
         overflowToDisk="false"
         transactionalMode="off">
  </cache>

  <cache name="time-based-long-lived"
         maxEntriesLocalHeap="100"
         maxEntriesLocalDisk="1000"
         eternal="false"
         timeToIdleSeconds="300"
         timeToLiveSeconds="600"
         memoryStoreEvictionPolicy="LFU"
         overflowToDisk="false"
         transactionalMode="off">
  </cache>

  <cache name="resource-level-cache"
         maxEntriesLocalHeap="100"
         maxEntriesLocalDisk="1000"
         eternal="false"
         timeToIdleSeconds="300"
         timeToLiveSeconds="86400"
         memoryStoreEvictionPolicy="LFU"
         overflowToDisk="false"
         transactionalMode="off">
  </cache>

</ehcache>

Now we will create an endpoint to showcase how time based caching works. The service will simply return “greetings” but the responses of the endpoints will be cached for a specified time period. We will use logging in order to know when the service performed calculations instead of serving from the cache.


package com.tasosmartidis.caching_demo.web;

import org.slf4j.*;
import org.springframework.cache.annotation.Cacheable;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.*;

import static com.tasosmartidis.caching_demo.utils.LoggingUtils.logMethodEntered;

@RestController
public class TimeBasedCachedService {

  private static final Logger LOGGER = LoggerFactory.getLogger(TimeBasedCachedService.class);

  private static final String HELLO_INPUT_NAME_ENDPOINT  = "/hello/{name}";
  private static final String HELLO_WORLD_ENDPOINT             = "/helloworld";
  private static final String HELLO_SHORT_CACHE                     = "time-based-short-lived";
  private static final String HELLO_LONG_CACHE                       = "time-based-long-lived";
  private static final String NAME_CACHE_KEY                            = "#name";

  @RequestMapping(value= HELLO_WORLD_ENDPOINT, method = RequestMethod.GET)
  @Cacheable(HELLO_SHORT_CACHE)
  public ResponseEntity<String> sayHelloWorld() {
      logMethodEntered(LOGGER);

      return ResponseEntity.ok().body("Hello World!");
  }

  @RequestMapping(value= HELLO_INPUT_NAME_ENDPOINT, method = RequestMethod.GET)
  @Cacheable(value = HELLO_LONG_CACHE, key = NAME_CACHE_KEY)
  public ResponseEntity<String> sayHelloByName(@PathVariable String name) {
      logMethodEntered(LOGGER);

     return  ResponseEntity.ok().body("Hello " + name + "!");
  }

}

Now we will see how it performs. We will use rest-assured to call the endpoints and make sure our responses are as expected, but the logging of the calls will give us the main input. The class below will make things clearer.


package com.tasosmartidis.caching_demo.web;

import org.junit.Test;
import org.junit.runner.RunWith;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import static com.tasosmartidis.caching_demo.testutils.HttpMethodsUtils.doGetEnsure200AndReturnResponseAsString;
import static com.tasosmartidis.caching_demo.utils.LoggingUtils.*;

@RunWith(SpringJUnit4ClassRunner.class)
@SpringBootTest(webEnvironment=SpringBootTest.WebEnvironment.DEFINED_PORT)
public class TimeBasedCachedServiceTest {

  private static final Logger LOGGER = LoggerFactory.getLogger(TimeBasedCachedServiceTest.class);
  private static final String HELLO_WORLD_RESOURCE = "helloworld";
  private static final String HELLO_INPUT_RESOURCE = "hello/";

  @Test
  public void sayHello() throws Exception {
      logMethodUnderTestStart("Hello World", LOGGER);

      logExplanationMessage("Should get into the method!", LOGGER);
      doGetHelloService(HELLO_WORLD_RESOURCE);
      Thread.sleep(5000);

      logExplanationMessage("Should use cache response now!", LOGGER);
      doGetHelloService(HELLO_WORLD_RESOURCE);
      Thread.sleep(6000);

      logExplanationMessage("Should get into the method again!", LOGGER);
      doGetHelloService(HELLO_WORLD_RESOURCE);

      logMehodUnderTestEnd("Hello World", LOGGER);
  }


  @Test
  public void sayHelloByName() throws Exception {
      logMethodUnderTestStart("Hello {input}", LOGGER);

      logExplanationMessage("Should get into method now!", LOGGER);
      doGetHelloService(HELLO_INPUT_RESOURCE + "Kent");

      logExplanationMessage("Should use cache response now!", LOGGER);
      doGetHelloService(HELLO_INPUT_RESOURCE + "Kent");

      logExplanationMessage("Should get into the method again!", LOGGER);
      doGetHelloService( HELLO_INPUT_RESOURCE + "Martin");

      logMehodUnderTestEnd("Hello {input}", LOGGER);
  }

  private void doGetHelloService(String resource) {
      String result = doGetEnsure200AndReturnResponseAsString(resource);
      logResponse(result, LOGGER);
  }

}

The “doGetEnsure200AndReturnResponseAsString” method is in a utility class which is shown below:

package com.tasosmartidis.caching_demo.testutils;

import com.jayway.restassured.response.Response;
import com.jayway.restassured.specification.RequestSpecification;
import org.apache.http.HttpStatus;

import static com.jayway.restassured.RestAssured.given;
import static com.jayway.restassured.RestAssured.when;

public class HttpMethodsUtils {

  public static String doGetEnsure200AndReturnResponseAsString(String resource) {
      return doGetEnsure200AndReturnResponse(resource).asString();
  }

  public static Response doGetEnsure200AndReturnResponse(String resource) {
      Response response = when()
                              .get(resource)
                          .then()
                              .statusCode(HttpStatus.SC_OK)
                          .extract().response();

      return response;
  }

  public static String doGetEnsure304AndReturnResponseAsString(String resource, HttpHeader... headers) {
       RequestSpecification requestSpecification = given();

       for(HttpHeader header : headers) {
           requestSpecification.header(header.getHeaderName(), header.getHeaderValue());
       }

       Response response =    requestSpecification.when()
                                  .get(resource)
                              .then()
                                  .statusCode(HttpStatus.SC_NOT_MODIFIED)
                              .extract().response();

      return response.asString();
  }

  public static String doPutEnsure200AndReturnResponseAsString(String resource) {
      Response response = when()
                              .put(resource)
                          .then()
                              .statusCode(HttpStatus.SC_OK)
                          .extract().response();

      return response.asString();
  }
}

Running our TimeBasedCachedServiceTest class will give something like that:

web.TimeBasedCachedServiceTest     : Test for method 'Hello World' started...
web.TimeBasedCachedServiceTest     : Should get into the method!
utils.LoggingInterceptor                      : -------------------------
utils.LoggingInterceptor                      : --- Request made --------
web.TimeBasedCachedService           : Got into the method!
utils.LoggingInterceptor                      : --- Request Completed ---
utils.LoggingInterceptor                      : -------------------------
web.TimeBasedCachedServiceTest     : Hello World!
web.TimeBasedCachedServiceTest     :
web.TimeBasedCachedServiceTest     : Should use cache response now!
utils.LoggingInterceptor                      : -------------------------
utils.LoggingInterceptor                      : --- Request made --------
utils.LoggingInterceptor                      : --- Request Completed ---
utils.LoggingInterceptor                      : -------------------------
web.TimeBasedCachedServiceTest     : Hello World!
web.TimeBasedCachedServiceTest     :
web.TimeBasedCachedServiceTest     : Should get into the method again!
utils.LoggingInterceptor                      : -------------------------
utils.LoggingInterceptor                      : --- Request made --------
web.TimeBasedCachedService           : Got into the method!
utils.LoggingInterceptor                      : --- Request Completed ---
utils.LoggingInterceptor                      : -------------------------
web.TimeBasedCachedServiceTest     : Hello World!
web.TimeBasedCachedServiceTest     :
web.TimeBasedCachedServiceTest     : Test for method 'Hello World' finished...

web.TimeBasedCachedServiceTest     : Test for method 'Hello {input}' started...
web.TimeBasedCachedServiceTest     : Should get into method now!
utils.LoggingInterceptor                      : -------------------------
utils.LoggingInterceptor                      : --- Request made --------
web.TimeBasedCachedService           : Got into the method!
utils.LoggingInterceptor                      : --- Request Completed ---
utils.LoggingInterceptor                      : -------------------------
web.TimeBasedCachedServiceTest     : Hello Kent!
web.TimeBasedCachedServiceTest     :
web.TimeBasedCachedServiceTest     : Should use cache response now!
utils.LoggingInterceptor                      : -------------------------
utils.LoggingInterceptor                      : --- Request made --------
utils.LoggingInterceptor                      : --- Request Completed ---
utils.LoggingInterceptor                      : -------------------------
web.TimeBasedCachedServiceTest     : Hello Kent!
web.TimeBasedCachedServiceTest     :
web.TimeBasedCachedServiceTest     : Should get into the method again!
utils.LoggingInterceptor                      : -------------------------
utils.LoggingInterceptor                      : --- Request made --------
web.TimeBasedCachedService           : Got into the method!
utils.LoggingInterceptor                      : --- Request Completed ---
utils.LoggingInterceptor                      : -------------------------
web.TimeBasedCachedServiceTest     : Hello Martin!



That’s for time based, but as we discussed, such caching does not guarantee that our cached responses are in state with the origin server. So let’s get to the state based service. We will get a bit more sophisticated now and have data for saving and a fake repository to save them to. Then a service will allow us to update and retrieve the data. We have a StubData POJO as below:

package com.tasosmartidis.caching_demo.data;

import lombok.*;

import java.util.Date;

@Getter
@Setter
@EqualsAndHashCode
@Builder
@ToString
public class StubData {
  private String id;
  private String name;
  private Date lastModified;

  public void updateData() {
      name = "name changed at: " + new Date();
      lastModified = new Date();
  }

}

And a fake repository:

package com.tasosmartidis.caching_demo.data;

import org.springframework.stereotype.Component;

import java.util.Date;
import java.util.HashMap;
import java.util.Map;

@Component
public class StubDataDao {
  private Map<String, StubData> fakeDatabase;

  public StubDataDao() {
      fakeDatabase = new HashMap<>();
      initializeFakeDatabaseState();
  }

  public StubData getDataEntry(String id) {
      assertIdExistsInDatabaseOrThrowRuntimeException(id);

      return fakeDatabase.get(id);
  }

  public void updateDataEntry(String id) {
      assertIdExistsInDatabaseOrThrowRuntimeException(id);

      fakeDatabase.get(id).updateData();
  }

  private void assertIdExistsInDatabaseOrThrowRuntimeException(String id) {
      if(!fakeDatabase.containsKey(id)) {
          throw new RuntimeException("Id not found!");
      }
  }

  private void initializeFakeDatabaseState() {
      String idOne   = "1";
      String idTwo   = "2";
      String idThree = "3";
      Date date = new Date();

      StubData entryOne = StubData.builder().id(idOne).name("Kent").lastModified(date).build();
      StubData entryTwo = StubData.builder().id(idTwo).name( "Martin").lastModified(date).build();
      StubData entryThree = StubData.builder().id(idThree).name("Bob").lastModified(date).build();

      fakeDatabase.put(idOne, entryOne);
      fakeDatabase.put(idTwo, entryTwo);
      fakeDatabase.put(idThree, entryThree);
  }
}

Nothing fancy, just a map in-memory with some entries we can retrieve and update via our endpoints. The endpoints are in the StateBasedCacheService class:

package com.tasosmartidis.caching_demo.web;

import com.tasosmartidis.caching_demo.data.StubData;
import com.tasosmartidis.caching_demo.data.StubDataDao;
import com.tasosmartidis.caching_demo.utils.LoggingUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.http.CacheControl;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.bind.annotation.RestController;

import javax.servlet.http.HttpServletRequest;
import java.text.ParseException;
import java.util.Date;

import static com.tasosmartidis.caching_demo.utils.HttpUtils.*;

@RestController
public class StateBasedCachedService {

  private static final Logger LOGGER = LoggerFactory.getLogger(StateBasedCachedService.class);

  private static final String STATE_BASED_BASE_ENDPOINT            = "/stubdata";
  private static final String STATE_BASED_UPDATE_RESOURCE_ENDPOINT = STATE_BASED_BASE_ENDPOINT+"/{id}";
  private static final String LAST_MODIFIED_ENDPOINT               = STATE_BASED_BASE_ENDPOINT + "/lastmodified/{id}";
  private static final String ETAG_ENDPOINT                        = STATE_BASED_BASE_ENDPOINT + "/etag/{id}";

  @Autowired
  private StubDataDao dataDao;

  @RequestMapping(value=LAST_MODIFIED_ENDPOINT, method = RequestMethod.GET)
  public ResponseEntity<StubData> getResourceWithLastModified(@PathVariable String id, HttpServletRequest request) throws ParseException {
      StubData data = dataDao.getDataEntry(id);

      if(modifiedSinceHeaderPresent(request)) {
          Date modifiedSinceHeaderDate = parseIfModifiedSinceHeaderToDate(request);

          if(modifiedSinceHeaderDate.equals(data.getLastModified())) {
              LoggingUtils.logExplanationMessage("Resource not changed, sending back 304!", LOGGER);
              return make304NotModifiedResponse();
          }
      }

      return ResponseEntity.ok()
              .cacheControl(CacheControl.empty()).lastModified(data.getLastModified().getTime())
              .body(data);
  }

  @RequestMapping(value=ETAG_ENDPOINT, method = RequestMethod.GET)
  public ResponseEntity<StubData> getResourceWithEtag(@PathVariable String id, HttpServletRequest request) throws ParseException {
      StubData data = dataDao.getDataEntry(id);

      if(checkIfEtagHeaderPresent(request)) {
          String etagSent = parseEtagHeader(request);

          if(etagSent.equals(String.valueOf(data.hashCode()))) {
              LoggingUtils.logExplanationMessage("Resource not changed, sending back 304!", LOGGER);
              return make304NotModifiedResponse();
          }
      }

      return ResponseEntity.ok()
              .cacheControl(CacheControl.empty()).eTag(String.valueOf(data.hashCode()))
              .body(data);
  }

  @RequestMapping(value=STATE_BASED_UPDATE_RESOURCE_ENDPOINT, produces = "application/json", method = RequestMethod.PUT)
  public ResponseEntity updateResource(@PathVariable String id) {
      dataDao.updateDataEntry(id);

      return ResponseEntity.ok().build();
  }

}

Our endpoints work with the Etag and Last-Modified headers, so we create a utility method to help us with necessary checks and operations. The HttpUtils class shown below:

package com.tasosmartidis.caching_demo.utils;

import org.springframework.http.HttpStatus;
import org.springframework.http.ResponseEntity;

import javax.servlet.http.HttpServletRequest;
import java.text.ParseException;
import java.text.SimpleDateFormat;
import java.util.Date;

public class HttpUtils {

  private static final String IF_MODIFIED_SINCE_HEADER = "if-modified-since";
  private static final String HEADER_DATE_PATTERN      = "EEE, dd MMM yyyy HH:mm:ss zzz";
  private static final String ETAG_HEADER              = "etag";

  public static ResponseEntity make304NotModifiedResponse() {
      return ResponseEntity.status(HttpStatus.NOT_MODIFIED).build();
  }

  public static Date parseIfModifiedSinceHeaderToDate(HttpServletRequest request) throws ParseException {

      SimpleDateFormat format = new SimpleDateFormat(HEADER_DATE_PATTERN);
      return format.parse(request.getHeader(IF_MODIFIED_SINCE_HEADER));
  }

  public static boolean modifiedSinceHeaderPresent(HttpServletRequest request) {
      return request.getHeader(IF_MODIFIED_SINCE_HEADER)!=null;
  }

  public static boolean checkIfEtagHeaderPresent(HttpServletRequest request) {
      return request.getHeader(ETAG_HEADER)!=null;
  }

  public static String parseEtagHeader(HttpServletRequest request) throws ParseException {
      return request.getHeader(ETAG_HEADER).replace("\"","");
  }
}


Let’s now create our tests for these endpoints and checkout the logs.


package com.tasosmartidis.caching_demo.web;


import com.jayway.restassured.response.Response;
import com.tasosmartidis.caching_demo.testutils.HttpHeader;
import org.junit.Ignore;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import static com.tasosmartidis.caching_demo.testutils.HttpMethodsUtils.*;
import static com.tasosmartidis.caching_demo.utils.LoggingUtils.*;

@RunWith(SpringJUnit4ClassRunner.class)
@SpringBootTest(webEnvironment= SpringBootTest.WebEnvironment.DEFINED_PORT)
public class StateBasedCachedServiceTest {

  private static final Logger LOGGER = LoggerFactory.getLogger(StateBasedCachedServiceTest.class);
  private static String STUB_DATA_RESOURCE_LAST_MODIFIED = "stubdata/lastmodified/1";
  private static String STUB_DATA_RESOURCE_ETAG          = "stubdata/etag/1";
  private static String STUB_DATA_UPDATE_RESOURCE        = "stubdata/1";

  @Test
  @Ignore
  public void testLastModifiedImplementation() {
      logMethodUnderTestStart("last-modified", LOGGER);

      logExplanationMessage("Get resource for the first time", LOGGER);
      Response response = doGetResource(STUB_DATA_RESOURCE_LAST_MODIFIED);


      logExplanationMessage("Get resource and send last-modified header should get 304", LOGGER);
      HttpHeader lastModified = extractLastModifiedHeader(response);
      doGetResourceWithLastModifiedHeaderExpect304(response);

      logExplanationMessage("Update the data", LOGGER);
      doPutResource(STUB_DATA_UPDATE_RESOURCE);

      logExplanationMessage("Get resource again and send last-modified. Should return resource", LOGGER);
      doGetResource(STUB_DATA_RESOURCE_LAST_MODIFIED, lastModified);

      logMehodUnderTestEnd("last-modified", LOGGER);
  }

  private Response doGetResourceWithLastModifiedHeaderExpect304(Response response) {
      HttpHeader httpHeader = extractLastModifiedHeader(response);
      response  = doGetEnsure304AndReturnResponse(STUB_DATA_RESOURCE_LAST_MODIFIED,httpHeader);
      logResponse(response.getStatusCode() + response.getHeaders().asList().toString(), LOGGER);

      return response;
  }

  private HttpHeader extractLastModifiedHeader(Response response) {
      String lastModifiedHeader = response.getHeader("Last-Modified");
      return HttpHeader.builder().headerName("if-modified-since").headerValue(lastModifiedHeader).build();
  }

  @Test
  public void testEtagImplementation() {
      logMethodUnderTestStart("Etag", LOGGER);

      logExplanationMessage("Get resource for the first time", LOGGER);
      Response response = doGetResource(STUB_DATA_RESOURCE_ETAG);

      logExplanationMessage("Get resource and send ETag, should get 304", LOGGER);
      doGetWithEtagExpect304(response);

      logExplanationMessage("Update the data", LOGGER);
      doPutResource(STUB_DATA_UPDATE_RESOURCE);

      logExplanationMessage("Get resource and send ETag, should get the resource", LOGGER);
      doGetResource(STUB_DATA_RESOURCE_ETAG);


      logMehodUnderTestEnd("Etag", LOGGER);
  }

  private void doGetWithEtagExpect304(Response response) {
      HttpHeader httpHeader = extractEtagHeader(response);
      response= doGetEnsure304AndReturnResponse(STUB_DATA_RESOURCE_ETAG, httpHeader);
      logResponse(response.getStatusCode() + response.getHeaders().asList().toString(), LOGGER);
  }

  private HttpHeader extractEtagHeader(Response response) {
      String  eTag = response.getHeader("ETag");
      return HttpHeader.builder().headerName("etag").headerValue(eTag).build();
  }

  private Response doGetResource(String endpoint, HttpHeader... headers) {
      Response response = doGetEnsure200AndReturnResponse(endpoint, headers);
      logResponse(response.asString(), LOGGER);
      return response;
  }

  private void doPutResource(String endpoint) {
      String responseAsString;
      responseAsString = doPutEnsure200AndReturnResponseAsString(endpoint);
      logResponse(responseAsString, LOGGER);
  }

}

The logs of our test are showing what we expected, as is pictured below:

web.StateBasedCachedServiceTest    : Test for method 'last-modified' started...
web.StateBasedCachedServiceTest    : Get resource for the first time
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    : {"id":"1","name":"Kent","lastModified":1499719565426}
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Get resource and send last-modified header should get 304
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    : 304 [Last-Modified=Mon, 10 Jul 2017 20:52:32 GMT, Date=Mon, 10 Jul 2017 20:52:44 GMT]
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Update the data
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Get resource again and send last-modified. Should return resource
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    : {"id":"1","name":"name is changed at: Mon Jul 10 22:46:17 CEST 2017","lastModified":1499719577954}
eb.StateBasedCachedServiceTest       :
web.StateBasedCachedServiceTest    : Test for method 'last-modified' finished…

web.StateBasedCachedServiceTest    : Test for method 'Etag' started...
web.StateBasedCachedServiceTest    : Get resource for the first time
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    : {"id":"1","name":"Kent","lastModified":1499720546955}
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Get resource and send ETag, should get 304
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
web.StateBasedCachedService          : Resource not changed, sending back 304!
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    : 304[Date=Mon, 10 Jul 2017 21:02:39 GMT]
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Update the data
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Get resource and send ETag, should get the resource
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
web.StateBasedCachedServiceTest    : {"id":"1","name":"name is changed at: Mon Jul 10 23:02:39 CEST 2017","lastModified":1499720559361}
web.StateBasedCachedServiceTest    :
web.StateBasedCachedServiceTest    : Test for method 'Etag' finished...

So we save some bandwidth by not sending back resources when they are not altered. However, it doesn’t do much for our processing and retrieving the resource from the repository. And the time based caching didn’t ensure our resource is in state with the origin server. Then what?

Well we could come up with a solution to make sure caching is used and is guaranteed. We could come up with an invalidation solution for our cache. This is by no means an easy task, there is a long standing quote (origins unknown): “There are only two hard things in Computer Science: cache invalidation and naming things”.

Let’s take a simple example of invalidation where when a resource is updated, we either remove the cached version for this resource, or we update the version in the cache. This guarantees us, that never a stale version will be served to requests.

The following class, showcases how a service with this approach could look like.

package com.tasosmartidis.caching_demo.web;

import com.tasosmartidis.caching_demo.data.StubData;
import com.tasosmartidis.caching_demo.data.StubDataDao;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.cache.annotation.CacheEvict;
import org.springframework.cache.annotation.CachePut;
import org.springframework.cache.annotation.Cacheable;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.bind.annotation.RestController;

import static com.tasosmartidis.caching_demo.utils.LoggingUtils.logMethodEntered;

@RestController
public class CacheWithInvalidationService {
  private static final Logger LOGGER = LoggerFactory.getLogger(CacheWithInvalidationService.class);
    
  private static final String STUB_DATA_UPDATE_CACHE_ENDPOINT = "/update-cache/stubdata/{id}";
  private static final String STUB_DATA_EVICT_CACHE_ENDPOINT    = "/evict-cache/stubdata/{id}";
  private static final String INVALIDATION_CACHE_NAME                    = "resource-level-cache";
  private static final String STUB_DATA_ENDPOINT                                 = "/stubdata/{id}";
  private static final String ID_CACHE_KEY                                                = "#id";

  @Autowired
  private StubDataDao dataDao;

  @RequestMapping(value=STUB_DATA_ENDPOINT, method = RequestMethod.GET)
  @Cacheable(value = INVALIDATION_CACHE_NAME, key = ID_CACHE_KEY)
  public ResponseEntity<StubData> getResource(@PathVariable String id) {
      logMethodEntered(LOGGER);
      StubData data = dataDao.getDataEntry(id);

      return ResponseEntity.ok().body(data);
  }

  @RequestMapping(value=STUB_DATA_EVICT_CACHE_ENDPOINT, method = RequestMethod.PUT)
  @CacheEvict(value = INVALIDATION_CACHE_NAME, key = ID_CACHE_KEY)
  public ResponseEntity updateResourceAndEvictFromCache(@PathVariable String id) {
      logMethodEntered(LOGGER);
      dataDao.updateDataEntry(id);

      return ResponseEntity.ok().build();
  }

  @RequestMapping(value=STUB_DATA_UPDATE_CACHE_ENDPOINT, method = RequestMethod.PUT)
  @CachePut(value = INVALIDATION_CACHE_NAME, key = ID_CACHE_KEY)
  public ResponseEntity<StubData> updateResourceAndUpdateCache(@PathVariable String id) {
      logMethodEntered(LOGGER);
      dataDao.updateDataEntry(id);

      return ResponseEntity.ok().body(dataDao.getDataEntry(id));
  }

}

Let’s now create a test class and make sure that all work as we want them to:

package com.tasosmartidis.caching_demo.web;


import org.junit.Ignore;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.junit4.SpringJUnit4ClassRunner;

import static com.tasosmartidis.caching_demo.testutils.HttpMethodsUtils.doGetEnsure200AndReturnResponseAsString;
import static com.tasosmartidis.caching_demo.testutils.HttpMethodsUtils.doPutEnsure200AndReturnResponseAsString;
import static com.tasosmartidis.caching_demo.utils.LoggingUtils.*;

@RunWith(SpringJUnit4ClassRunner.class)
@SpringBootTest(webEnvironment=SpringBootTest.WebEnvironment.DEFINED_PORT)
public class CacheWithInvalidationServiceTest {

  private static final Logger LOGGER = LoggerFactory.getLogger(CacheWithInvalidationServiceTest.class);

  private static final String STUB_DATA_UPDATE_CACHE_ENDPOINT = "/update-cache/stubdata/1";
  private static final String STUB_DATA_EVICT_CACHE_ENDPOINT  = "/evict-cache/stubdata/1";
  private static final String STUB_DATA_ENDPOINT              = "/stubdata/1";

  @Test
  public void testCacheEviction() throws Exception {
      logMethodUnderTestStart("cache-eviction", LOGGER);

      logExplanationMessage("Should get in method for the resource!", LOGGER);
      doGetStubDataService(STUB_DATA_ENDPOINT);

      logExplanationMessage("Should use cache response now!", LOGGER);
      doGetStubDataService(STUB_DATA_ENDPOINT);

      logExplanationMessage("Updating resource! Clear resource from cache!", LOGGER);
      doPutStubDataService(STUB_DATA_EVICT_CACHE_ENDPOINT);

      logExplanationMessage("Should use updated cache response now!", LOGGER);
      doGetStubDataService(STUB_DATA_ENDPOINT);

      logMehodUnderTestEnd("cache-eviction", LOGGER);
  }

  @Test
  public void testCacheUpdate() throws Exception {
      logMethodUnderTestStart("cache-update", LOGGER);

      logExplanationMessage("Should get in the method for response now!", LOGGER);
      doGetStubDataService(STUB_DATA_ENDPOINT);

      logExplanationMessage("Should use cache response now!", LOGGER);
      doGetStubDataService(STUB_DATA_ENDPOINT);

      logExplanationMessage("Updating resource! Update resource from cache!", LOGGER);
      doPutStubDataService(STUB_DATA_UPDATE_CACHE_ENDPOINT);

      logExplanationMessage("Cache should serve updated response now!", LOGGER);
      doGetStubDataService(STUB_DATA_ENDPOINT);

      logMehodUnderTestEnd("cache-update", LOGGER);
  }

  private void doGetStubDataService(String endpoint) {
      String result = doGetEnsure200AndReturnResponseAsString(endpoint);
      logResponse(result, LOGGER);
  }

  private void doPutStubDataService(String endpoint) {
      String result = doPutEnsure200AndReturnResponseAsString(endpoint);
      logResponse(result, LOGGER);
  }
}

Running the test class gives us green and the logs tell the story as follows:

w.CacheWithInvalidationServiceTest : Test for method 'cache-eviction' started...
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
web.CacheWithInvalidationService   : Got into the method!
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"Kent","lastModified":1500017558822}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest :Should use cache response now!
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"Kent","lastModified":1500017558822}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Updating resource! Clear resource from cache!
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
web.CacheWithInvalidationService   : Got into the method!
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Should use updated cache response now!
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
web.CacheWithInvalidationService   : Got into the method!
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"name changed at: Fri Jul 14 09:32:52 CEST 2017","lastModified":1500017572211}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Test for method 'cache-eviction' finished…

w.CacheWithInvalidationServiceTest : Test for method 'cache-update' started...
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
web.CacheWithInvalidationService   : Got into the method!
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"Kent","lastModified":1500018351446}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Should use cache response now!
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"Kent","lastModified":1500018351446}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Updating resource! Update resource from cache!
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
web.CacheWithInvalidationService   : Got into the method!
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"name changed at: Fri Jul 14 09:46:05 CEST 2017","lastModified":1500018365404}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Cache should serve updated response now!
utils.LoggingInterceptor                     : -------------------------
utils.LoggingInterceptor                     : --- Request made --------
utils.LoggingInterceptor                     : --- Request Completed ---
utils.LoggingInterceptor                     : -------------------------
w.CacheWithInvalidationServiceTest : {"id":"1","name":"name changed at: Fri Jul 14 09:46:05 CEST 2017","lastModified":1500018365404}
w.CacheWithInvalidationServiceTest :
w.CacheWithInvalidationServiceTest : Test for method 'cache-update' finished...


And that was it! Again, you can find the project in my github. Happy coding!