[infinispan-issues] [JBoss JIRA] (ISPN-2891) Calls to replace don't update cache until after tx commits

[Galder Zamarreño (JIRA)]

    [ https://issues.jboss.org/browse/ISPN-2891?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12758854#comment-12758854 ] 

Galder Zamarreño commented on ISPN-2891:
----------------------------------------

The ugly test might be acting weirdly due to a mix of things:

1. "nREPL-worker-0" seems to be logging stuff before "Thread-2 (HornetQ-client-global-threads-1854008926)" has finished doing its job, that's how I see that "nREPL-worker-0" can print 2, and then get from the cache and show 3. Don't really know how that is supposed to be coded, but you should wait until the message has been fully consumed? IOW, queue/done having all messages doesn't mean that the overall transaction that onMessage() runs on has completed. There could be a window between sending the message to queue/done and the onMessage() finishing, when the transaction is committed.

2. The cache ends up having value 3, how is that possible? It appears that the test is not sending 3 replace calls, but instead 6, each with a different transaction: https://gist.github.com/anonymous/438ee1e99e449f581869. Why 6 replace calls? Could it be retries by the HornetQ/Messaging as a result of write skew exceptions when committing?

Overall, I don't really see anything wrong with Infinispan here.
                
> Calls to replace don't update cache until after tx commits
> ----------------------------------------------------------
>
>                 Key: ISPN-2891
>                 URL: https://issues.jboss.org/browse/ISPN-2891
>             Project: Infinispan
>          Issue Type: Bug
>          Components: Transactions
>    Affects Versions: 5.2.1.Final
>            Reporter: Jim Crossley
>            Assignee: Galder Zamarreño
>              Labels: 5.2.x
>             Fix For: 5.3.0.Alpha1, 5.3.0.Final
>
>         Attachments: bad.log, good.log, ugly.log
>
>
> Since upgrading our AS7.2 dependency in Immutant (transitively pulling in 5.2.1.Final), one of our integration tests has begun failing intermittently on our CI server. We've yet to see the failure in local runs, only on CI, so I suspect there's something racist going on.
> The two tests (one for optimistic locking, the other for pessimistic) integrate an Infinispan cache (on which the Immutant cache is built) with HornetQ and XA transactions. A number of queue listeners respond to messages by attempting to increment a value in the cache. The failure occurs with both locking schemes, but much more often with optimistic.
> We've confirmed the failure on 5.2.2 as well.
> Attached you'll find three traces of the optimistic test: the good, the bad, and the ugly. All three correspond to this test: https://github.com/immutant/immutant/blob/31a2ef6222088ccb828898e9e3e4531e0333d517/integration-tests/apps/caching/counter/test/counter/test/locking.clj
> So you can correlate the log messages prefixed with "JC:" in the traces to the code. Note in particular the last two lines in locking.clj: a logged message containing the count, and then an assertion of the count. Note that the "bad" trace was an actual failing test, but the "ugly" trace was a successful test, even though the trace clearly shows the count logged as 2, not 3. The Infinispan TRACE output clearly shows the value as 3, hence the ugliness of this test.
> It's important to understand that the "work" function occurs within an XA transaction. This means, as I understand it, that if three messages are published to "/queue/done", the cached count should equal 3. Line #44 in locking.clj will block until it receives 3 messages, after which the cached count should be 3.
> These tests always pass locally. They only ever fail on CI, which runs *very* slowly.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira