Help with understanding caching possibly.

Andrew Willerding <[email protected]>
Newsgroups gmane.comp.java.cayenne.user
Message-ID <[email protected]>
Hi,

I am getting some strange results in writing/reading with Threads using 
Cayenne and I'm sure it's something I'm not understanding about 
Cayenne's data caching.  I'm hoping to get a solution to force a direct 
read somehow but so far I haven't found anything with Mr. Google.

I'm using 4.1.B2.

The issue is that I believe that I am writing a value to the database 
and the database contents reflect the update but subsequent reads in 
other Threads are not picking up the new value.  Here's an example in my 
log file where I log the first Thread update to the object and a 
subsequent read from another Thread

2019-10-03,12:38:01:727,INFO 
,[CAsteriskAMIMgrProxyRemoteIF-Thread-1570],ClientBase,::NotifyQueue - 
PostUpdate NotifyQueue=[Complete](125)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](15)Test call
2019-10-03,12:38:01:728,INFO 
,[NotifyTypeHandlerDialer-pool-449-thread-1],ClientBase,::NotifyQueue - 
PostLoad NotifyQueue=[Running](125)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](15)Test call

   The first line PostUpdate shows that the NotifyQueue item (125) is 
Complete and when I check the database the value is definitely showing 
Complete.  However the next line from a different thread is reading the 
same NotifyQueue record (125) and it's displaying Running.   I don't 
understand how this is possible.  All indications show the PostUpdate is 
working but PostLoad is not picking up the changed value.

Here's a second example with another pair of NotifyQueue items 
(127,129).  The Web page picks up the correct status values (Complete) 
as indicated in the log below

2019-10-03,13:31:07:535,INFO 
,[http-nio-8080-exec-126],ClientBase,::NotifyQueue - PostLoad 
NotifyQueue=[Complete](127)Test 
call->Phone=416-712-2323::NotifyEvent=[New](17)Test call
2019-10-03,13:31:07:535,INFO 
,[http-nio-8080-exec-126],ClientBase,::NotifyQueue - PostLoad 
NotifyQueue=[Complete](129)Test 
call->Phone=416-712-2323::NotifyEvent=[New](19)Test call

And the background ThreadNotifyEventsForClient again does not pickup the 
updated Complete status (shows Running) more than a few seconds later 
(as opposed to the microseconds in the first logging example).  When I 
do a manual query on the DB, the status is definitely Complete.

2019-10-03,13:31:32:265,INFO 
,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](17)Test 
call::checkForCompletedQueueItems NotifyQueueCount=1
2019-10-03,13:31:32:265,DEBUG,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](17)Test 
call::checkForCompletedQueueItems 
NotifyQueueItem=NotifyQueue=[Running](127)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](17)Test call
2019-10-03,13:31:32:265,DEBUG,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](17)Test 
call::checkForCompletedQueueItems 
INCOMPLETE->NotifyQueue=[Running](127)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](17)Test call DEBUG 
UNCOMMITTED=0

2019-10-03,13:31:32:265,INFO 
,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](19)Test 
call::checkForCompletedQueueItems NotifyQueueCount=1
2019-10-03,13:31:32:265,DEBUG,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](19)Test 
call::checkForCompletedQueueItems 
NotifyQueueItem=NotifyQueue=[Running](129)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](19)Test call
2019-10-03,13:31:32:265,DEBUG,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](19)Test 
call::checkForCompletedQueueItems 
INCOMPLETE->NotifyQueue=[Running](129)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](19)Test call DEBUG 
UNCOMMITTED=0
2019-10-03,13:31:32:265,INFO 
,[ThreadNotifyEventsForClient-pool-545-thread-1],NotifyEvent,ThreadNotifyEventsForClient::Callista 
Computer Telephony Inc.::checkForCompletedQueueItems Done


I have now made a change in my code for the background 
ThreadNotifyEventsForClient from

List<NotifyQueue> listQueue = notifyEvent.getListNotifyQueue();

to what should be the actual underlying transaction generated by Cayenne

             List<NotifyQueue> listQueue = 
ObjectSelect.query(NotifyQueue.class)
                 .where(NotifyQueue.NOTIFY_EVENT.eq(notifyEvent))
                 .select(ClientBaseAdmin.getObjectContext());

Here's the extract from the map.xml file for the relationship

     <db-relationship name="listNotifyQueue" source="NotifyEvent" 
target="NotifyQueue" toMany="true">
         <db-attribute-pair source="id" target="notifyEventID"/>

     <obj-relationship name="listNotifyQueue" source="NotifyEvent" 
target="NotifyQueue" deleteRule="Cascade" 
db-relationship-path="listNotifyQueue"/>


And guess what.  It works consistently with the explicit code change 
with a difference that I now get a PostLoad event now in the 
ThreadNotifyEventsForClient


2019-10-03,14:12:00:103,INFO 
,[CAsteriskAMIMgrProxyRemoteIF-Thread-5291],ClientBase,::NotifyQueue - 
PostUpdateNotifyQueue=[Complete](133)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](23)Test call

2019-10-03,14:12:00:107,INFO 
,[ThreadNotifyEventsForClient-pool-758-thread-1],ClientBase,::NotifyQueue 
- PostLoad NotifyQueue=[Complete](133)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](23)Test call
2019-10-03,14:12:00:107,INFO 
,[ThreadNotifyEventsForClient-pool-758-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](23)Test 
call::checkForCompletedQueueItems NotifyQueueCount=1
2019-10-03,14:12:00:107,DEBUG,[ThreadNotifyEventsForClient-pool-758-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](23)Test 
call::checkForCompletedQueueItems 
NotifyQueueItem=NotifyQueue=[Complete](133)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](23)Test call
2019-10-03,14:12:00:107,INFO 
,[ThreadNotifyEventsForClient-pool-758-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](23)Test 
call::checkForCompletedQueueItems NotifyEvent has been completed
2019-10-03,14:12:00:107,DEBUG,[ThreadNotifyEventsForClient-pool-758-thread-1],NotifyEvent,ThreadNotifyEventsForClient::NotifyEvent=[Running](23)Test 
call::checkForCompletedQueueItems Generating NotifyLog for 
NotifyQueue->NotifyQueue=[Complete](133)Test 
call->Phone=416-712-2323::NotifyEvent=[Running](23)Test call


Can someone explain why this is the case and how I can "fix it" without 
the code change.


Thanks,

Andrew
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.