On Oct 3, 2019, at 2:43 PM, Andrew Willerding <awillerd...@itsurcom.com> wrote:
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