Issue with Loading cache Guava

Foto de Hasan Almasi en Unsplash

In this post we are going to talk about a bug that I found after making a release to production. Like all releases, it is recommended and necessary to have a way to verify that what we have released to production does not break the old functionality.

The thing is that in this delivery to production the release consisted of an optimization to reduce the response time of an endpoint of a rest api. It turns out that this endpoint had a response time of 10 seconds.

The problem was that in each request the application made a query to the database to fetch the same data. The request always returned the same values ​​from a database table, because the app was doing a select * from ...

The records of that table where the query was done were rarely modified compared to the number of reads, so in the code that is executed in the application to return the data it made sense to put a cache to avoid going each time to the database and thus reduce the response time.

To do this I used a Guava LoadingCache and a CacheLoader that refreshes the cache data every 30 minutes by doing a database query. When starting the application, the data of that cache is filled to prevent the first request from taking longer than necessary.

    CacheLoader<String, String> loader;
    loader = new CacheLoader<String, String>() {
        @Override
        public String load(String key) {
            return key.toUpperCase();
        }
    };

    LoadingCache<String, String> cache;
    cache = CacheBuilder.newBuilder().build(loader);

When releasing the changes to Canary and making a request to the stable Pod balancer I saw that the request returned 3982 elements and that the request to Canary returned 3982-24. In other words, 24 elements less than what should be returned to me.

After spending 1 day of work investigating what was happening, it turned out that the problem was the maximum size with which the cache was configured.

It was configured with a maximum of 4000 elements. This caused that when trying to return all the elements of the cache, it returned all the elements added except the last 24.

   CacheLoader<String, String> loader;
    loader = new CacheLoader<String, String>() {
        @Override
        public String load(String key) {
            return key.toUpperCase();
        }
    };
    LoadingCache<String, String> cache;
    cache = CacheBuilder.newBuilder().maximumSize(3).build(loader);

    cache.getUnchecked("first");
    cache.getUnchecked("second");
    cache.getUnchecked("third");
    cache.getUnchecked("forth");

In the previous code the first key will be evicted.

The solution was to increase the number of cache elements to 5000.

After finding the bug I did a unit test to ensure that if someone changed the cache settings a test would fail.

Conclusion

In this post we have seen how a configuration problem in a cache can cause a bug and how we solved the issue increasing the size of the cache.