Search code examples
javaspring-bootspring-mvccachingthymeleaf

Spring caching bypassing cached method?

Something weird is happening with Spring Cache; maybe someone can help me know what to look for.

I have two Spring Boot applications 1) the "web app", using Spring MVC with Thymeleaf, and 2) a "backend service" that talks to the database. The backend service exposes a RESTful interface to the web app, which is called during Thymeleaf processing (not asynchronously from the page using Ajax).

Thymeleaf -> web app -> (REST over HTTP) -> backend service -> database

I'm using Spring Cache with Caffeine, with Coffee Boots to allow me to configure eviction on a per-cache basis. Here is part of the Maven POM:

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-starter-cache</artifactId>
</dependency>

<dependency>
  <groupId>com.github.ben-manes.caffeine</groupId>
  <artifactId>caffeine</artifactId>
</dependency>

<dependency>
  <groupId>io.github.stepio.coffee-boots</groupId>
  <artifactId>coffee-boots</artifactId>
</dependency>

I use @EnableCaching to turn on caching in my web app configuration:

@Configuration
@EnableCaching
public class WebAppConfiguration {
  …

My web app has a WebAppFooBarRepositoryImpl.getFooBars(), with caching turned on:

@Repository("fooBarRepository")
public class WebAppFooBarRepositoryImpl implements WebAppFooBarRepository {

  …

  @Override
  @Cacheable("foobar")
  public Flux<FooBar> getFooBars() {

    System.out.println("CACHE MISS");

    return webClient.get().uri("backend-service").…
  }

  …

Note that this repository method logs CACHE MISS every time it is called, and then it makes a request to the backend.

Note also that I named the repository fooBarRepository, so that in Thymeleaf I can iterate over the Flux<FooBar> items like this in the web page:

<li th:each="foobar: ${@fooBarRepository.getFooBars.toIterable()}">[[${foobar}]]</li>

The backend service then has a RestController that accepts the request, like this (the web site repository converts the Iterable to a Flux):

@GetMapping(path = "backend-service")
public Iterable<FooBar> getFooBars() throws IOException {

  System.out.println("backend getting foobars");

  return getBackendFooBarRepository().getFooBars();
}

Everything is completely standard and boring so far, with the caching being the only thing even slightly out of the ordinary. I add this configuration in the web app application.yaml to cache the foobar results at the web layer for 15 minutes at a time:

coffee-boots:
  cache:
    spec:
      foobar: expireAfterWrite=15m

With everything in place, I load the web page and hit F5 over and over to continuously reload it.

  • I see CACHE MISS in the web site logs every 15 minutes. This is as expected: the web layer should be caching calls to WebAppFooBarRepositoryImpl.getFooBars(), and only actually making the call when the cache expires—after 15 minutes.
  • However I see "backend getting foobars" every time I reload the page, multiple times a second—each time I hit F5!!

This must mean that something is calling the backend service every time the page is reloaded. But how? The only way to the backend service is via WebAppFooBarRepositoryImpl.getFooBars(), which makes the REST call. If WebAppFooBarRepositoryImpl.getFooBars() were being called more often, the web app would be printing CACHE MISS to the logs more often. But the web site is logging CACHE MISS every 15 minutes, exactly as I expect, regardless of how often I reload the page.

Remembering that Spring is probably creating a proxy for my WebAppFooBarRepositoryImpl instance, I thought perhaps that the caching logic intercepting the call might be skipping the log output but still calling the backend. But I've never heard of a Spring proxy parsing out the code inside the method, and skipping only part of it; that makes no sense.

Currently I'm at a loss to explain this weird behavior. If someone has an idea let me know. I'm hoping soon it will pop into my head and I'll be like, "duh, I accidentally did such and such", but for the moment, I honestly can't explain this.

Solution

  • I'm hoping soon it will pop into my head and I'll be like, "duh, I accidentally did such and such" …

    hahahaha In fact it did just pop into my mind; I think I know exactly what is happening.

    I think that Spring Cache is not caching my FooBars, but instead is caching my Flux<FooBar>—which in fact is exactly what I asked it to do. This means that it only generates a new Flux<FooBar> every 15 minutes. But for calls in the interim, Thymeleaf iterates the cached Flux<FooBar> instance, which makes another REST call to the backend service, in effect bypassing the WebAppFooBarRepositoryImpl.getFooBars() method.

    I guess I didn't look closely at what the method was returning, and assumed Spring knew what I wanted to cache.

    Duh!

    The only surprise here is that I didn't know that if you held on to a Flux<FooBar> coming from a WebClient, that it would make a new request every time you called Flux.toIterable(). But it makes sense, as iterables are normally meant to be iterated multiple times.

    Update: I have now performed tests to verify that this indeed seems to be the cause. The fix was to change the repository to return something that could be cached that already contained the objects (i.e. a materialized container), such as a List<FooBar>, rather than something that represented supplying the objects in the future:

    @Repository("fooBarRepository")
public class WebAppFooBarRepositoryImpl implements WebAppFooBarRepository {

  …

  @Override
  @Cacheable("foobar")
  public List<FooBar> getFooBars() {
    return webClient.get().uri("backend-service")
        ….collectList().block()
  }

  …

    With the existing WebClient code, the quick workaround was to add ….collectList().block() to the existing Flux<FooBar> being returned, as shown in the snippet above. I'll then take some time to reexamine the entire approach to how this repository returns information, now that caching needs to be taken into consideration.