0

I have spring caching enabled in my boot app. Simple testing shows it to be working. However, when I run jmeter against it I see output very clearly indicating cache misses with milliseconds of each other.

Eventually, it quiets down but not before it errors because it's overloading my db connection pool.

When I run the same test again, it works perfectly; the cache already having been primed. Can someone explain this?

Sample output

Looking for 'Philadelphia', 'Shoe' at timestamp: 1454203396865
Looking for 'Philadelphia', 'Shoe' at timestamp: 1454203396863
Looking for 'Atlanta', 'Wii' at timestamp: 1454203396992
Looking for 'Atlanta', 'Wii' at timestamp: 1454203397001
Looking for 'Atlanta', 'Wii' at timestamp: 1454203396998
Looking for 'Atlanta', 'Wii' at timestamp: 1454203396998
Looking for 'Atlanta', 'Wii' at timestamp: 1454203396993
Looking for 'San Francisco', 'Jeep' at timestamp: 1454203397174
Looking for 'San Francisco', 'Jeep' at timestamp: 1454203397187
Looking for 'San Francisco', 'Jeep' at timestamp: 1454203397190

Starting the test @ Sat Jan 30 18:41:55 PST 2016 (1454208115431)
Waiting for possible shutdown message on port 4445
summary +      1 in   7.1s =    0.1/s Avg:  2022 Min:  2022 Max:  2022 Err:     1 (100.00%) Active: 100 Started: 100 Finished: 0
summary +   7999 in  17.3s =  463.4/s Avg:   244 Min:    82 Max:  9965 Err:    43 (0.54%) Active: 0 Started: 100 Finished: 100
summary =   8000 in  24.3s =  328.9/s Avg:   244 Min:    82 Max:  9965 Err:    44 (0.55%)
Tidying up ...    @ Sat Jan 30 18:42:19 PST 2016 (1454208139824)
... end of run
Violas-MacBook-Pro:ou cbongiorno$ jmeter -n -t src/test/test-plan.jmx -l mc_results.jtl
Creating summariser <summary>
Created the tree successfully 
Starting the test @ Sat Jan 30 18:42:24 PST 2016 (1454208144475)
Waiting for possible shutdown message on port 4445
summary +   3034 in   5.5s =  554.8/s Avg:    93 Min:    81 Max:   272 Err:     0 (0.00%) Active: 100 Started: 100 Finished: 0
summary +   4966 in   7.1s =  702.1/s Avg:    91 Min:    81 Max:   325 Err:     0 (0.00%) Active: 0 Started: 100 Finished: 100
summary =   8000 in    13s =  637.9/s Avg:    92 Min:    81 Max:   325 Err:     0 (0.00%)
Tidying up ...    @ Sat Jan 30 18:42:37 PST 2016 (1454208157073)

Code snippet

@SpringBootApplication
@EnableAutoConfiguration
@EnableAsync
@EnableScheduling
@EnableCaching
public class SampleApp {

    public static void main(String[] args) throws Exception {
        System.setProperty("hibernate.temp.use_jdbc_metadata_defaults","false");

        SpringApplication.run(SampleApp.class, args);
    }
}

not in the same class

   @Cacheable("suggestions")
    public Suggestion getSuggestionFor(String city, String item) {
        System.out.format("Looking for '%s', '%s' at timestamp: %s\r\n", city,item,System.currentTimeMillis());
        Suggestion result = null;
        List<Offer> offers = null;
        if(city != null)
            offers = repository.find(city, item);
        else
            offers = repository.find(item);

        if (offers != null && offers.size() > 0) {
            Map<Integer, Long> byPrice = offers.stream().collect(groupingBy(Offer::getListPrice, TreeMap::new, counting()));

            Map.Entry<Integer, Long> entry = byPrice.entrySet().stream().reduce((e1, e2) -> MODE.compare(e1, e2) > 0 ? e1 : e2).orElse(null);
            if (entry != null)
                result = new Suggestion(city, item, entry.getKey(), entry.getValue(), offers.size());
        }
        return result;
    }
Christian Bongiorno
  • 5,150
  • 3
  • 38
  • 76

1 Answers1

0

I'm not sure it's a matter of heavy load, it may just be because you haven't specified the key to be a combination of both city, and item. Try a declaration like this.

@Cacheable("suggestions", key="#city.toString() + #item.toString()")
public Suggestion getSuggestionFor(String city, String item) {
    ....
}

You can read more information from this great answer on a question related to Cached keys.

Community
  • 1
  • 1
DominicEU
  • 3,585
  • 2
  • 21
  • 32
  • I had assumed it would just use the hashcode/equals of all objects in the argument list. I did as you suggested and now it complains about calling toString() when those params are null. I will hunt that down – Christian Bongiorno Jan 31 '16 at 02:03
  • You don't actually have to make use of toString(), you can even include null values (if it's possible for them to be null). ```#city?.toString()``` may work off of the top of my head to fix the npe issue. – DominicEU Jan 31 '16 at 02:06
  • No dice: identical results. but the '?' did the trick for nulls – Christian Bongiorno Jan 31 '16 at 02:40
  • What is calling ```getSuggestionFor```? Nothing from inside of the same bean right? Remember that only external method calls coming in through the proxy class generated by spring are intercepted and hit the cache. – DominicEU Jan 31 '16 at 02:51
  • Nope, controller -> service.getSuggestionFor(...) It works perfectly once I run the tests again or if I run it locally and just poke at it. That's why ti seems to be a high-speed thing? – Christian Bongiorno Jan 31 '16 at 02:53