Hi Andrew,
So I assume those two NotifyQueue are in different ObjectContexts?
Since 4.1 we stopped doing cross-context state synchronization by default. So
when you commit in one context, the same object in other contexts does not get
refreshed until e.g. you run a query. This improves both performance and
consistency in a typical multi-user application. But of course each app has
different requirements. So you may turn synchronization back on when
bootstrapping Cayenne:
SererRuntime runtime = ServerRuntime
.builder()
...
.addModule(b ->
ServerModule.contributeProperties(b).put(Constants.SERVER_CONTEXTS_SYNC_PROPERTY,
"true"))
.build();
Andrus
> 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
>
>
