@Cacheable and @Loggable - performance issues

[pacinpm]

Hi, I am using Aspects library and I have some doubts with @Cacheable. Here are some lines from logs:

Info:   16:55:01.687 [http-listener-1(3)] INFO pl.cbs.primio.api.PrimioAPI - #loginToShopId('666'): 172722 in 21,42ms
Info:   16:55:01.691 [http-listener-1(3)] INFO pl.cbs.primio.api.PrimioAPI - #loginToShopId('666'): 172722 cached in 27ms, valid for 1days

Info:   16:55:01.994 [http-listener-1(3)] INFO pl.cbs.primio.api.PrimioAPI - #loginToClientId('666'): NULL in 3,09ms
Info:   16:55:01.994 [http-listener-1(3)] INFO pl.cbs.primio.api.PrimioAPI - #loginToClientId('666'): NULL cached in 4ms, valid for 1days

Info:   16:54:59.934 [http-listener-1(4)] INFO pl.cbs.primio.api.PrimioAPI - #loginToShopId('666'): 172722 in 250,82ms
Info:   16:54:59.934 [http-listener-1(4)] INFO pl.cbs.primio.api.PrimioAPI - #loginToShopId('666'): 172722 cached in 251ms, valid for 1days

As you can see timing for cached call is very similar to non-cached call (and always longer). I expected cached calls to be much faster.

Is this a real result or just some side-effect of logging?

I use:

@loggable
@Cacheable(lifetime = 1, unit = TimeUnit.DAYS)

[0crat]

@yegor256 please, pay attention to this issue

[yegor256]

@pacinpm but I don't see any cache hits in the log. All calculations are made only one time. That's why there is no performance gain. You should call them a few times and you will see the speed improvement.