Multiple queries with entity cache after not cached query

Support
#1

Hi there!

Got a performance problem with entity and query cache. You can reproduce it in attached sample-sales-cuba7 project (cache-issue.zip 1.2 MB)

Basically this is project with enabled entity cache (Order, OrderLine) and query cache.

Test case.
0. Enable eclipselink.sql logger

  1. Open orders screen
  2. Click “Cached query” button
  3. After 2 (?) clicks no more SALES_ORDER_LINE queries appear in the log. That’s okay, we’ve loaded orders and lines so far.
  4. Click “Non cached query” button. It loads from DB - okay.
  5. Click “Cached query” again.
    Actual result. It loads order lines from the DB. And this is something I don’t understand? Why it loads orders and lines? They were cached before.

Example of the order lines loaded at step 5:

2022-08-26 15:56:15.504 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 1459080584> [0 ms] spent
2022-08-26 15:56:15.507 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 919723986> SELECT ID, CREATE_TS, CREATED_BY, DELETE_TS, DELETED_BY, QUANTITY, UPDATE_TS, UPDATED_BY, VERSION, ORDER_ID, PRODUCT_ID FROM SALES_ORDER_LINE WHERE ((ORDER_ID = ?) AND (DELETE_TS IS NULL))
        bind => [a64649a9-a646-49a9-8f15-cf798f15cf79]
2022-08-26 15:56:15.508 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 919723986> [1 ms] spent
2022-08-26 15:56:15.510 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 907774191> SELECT ID, CREATE_TS, CREATED_BY, DELETE_TS, DELETED_BY, QUANTITY, UPDATE_TS, UPDATED_BY, VERSION, ORDER_ID, PRODUCT_ID FROM SALES_ORDER_LINE WHERE ((ORDER_ID = ?) AND (DELETE_TS IS NULL))
        bind => [ec864774-ec86-4774-d935-2ce5d9352ce5]
2022-08-26 15:56:15.511 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 907774191> [1 ms] spent
2022-08-26 15:56:15.513 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 1246617453> SELECT ID, CREATE_TS, CREATED_BY, DELETE_TS, DELETED_BY, QUANTITY, UPDATE_TS, UPDATED_BY, VERSION, ORDER_ID, PRODUCT_ID FROM SALES_ORDER_LINE WHERE ((ORDER_ID = ?) AND (DELETE_TS IS NULL))
        bind => [f12a4193-f12a-4193-c83d-2a46c83d2a46]
2022-08-26 15:56:15.514 DEBUG [http-nio-8080-exec-19/app-core/admin] eclipselink.sql - <t 1661478782, conn 1246617453> [1 ms] spent

It reproduced both in hsql and postgres.

#3

Hello, Ivan!
Sorry for the late reply. I’ve checked this case and here’s what I discovered.

Let’s examine one Order with its Order Lines.

  1. During first querying: Query is performed. Order loaded without lines and stored in Entity Cache before returning by eclipselink. Then framework fetched OrderLines according to passed view. (Order object in Entity Cache has no lines loaded because has been cloned at some step between storing in Entity Cache and fetching).
  2. During second querying: Orders query isn’t performed because ids of result entities stored in Query Cache. Order requested by id and eclipselink returns Order from Entity Cache. Without cloning at this time. So, order lines appears in Entity Cache as part of Order when it fetched and will not be loaded during next requests.
  3. During loading by not cached query: Order object without fetched lines replaces previously fully loaded Order in Entity Cache.
    Thus, next time order lines are loaded again.

So, briefly:

Query Cache stores ids only. Entity Cache stores entities by their id’s. If we want to cache not single entities but entity graphs, caches compliments each other well for “toOne” relations (e.g. Order.customer) - when nested entities referenced by id, but not for “toMany” relations - when nested entities loaded by query. Howewer, for “toMany” case, after two the same subsequent queries entity graph will be fully got from cache.

Why it loads orders and lines? They were cached before

Actually It loads lines only, but not orders (see logs).
Lines were cached by ids. lines is a “toMany” lazy-loaded collection inside Order and it takes separate query to load it, so they cannot be got neither from Entity Cache by ids nor from Query Cache because lazy-loading works on eclipselink level and does not use Query Cache.

UPD: I’ve created an issue to see if we can improve caching behaviour for nested entity collections.

Regards,
Dmitry