Bug 1151523

Summary: X-Site State transfer values not propagated correctly
Product: [JBoss] JBoss Data Grid 6 Reporter: Matej Čimbora <mcimbora>
Component: InfinispanAssignee: Tristan Tarrant <ttarrant>
Status: CLOSED CURRENTRELEASE QA Contact: Martin Gencur <mgencur>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.4.0CC: jdg-bugs, pruivo, slaskawi
Target Milestone: ER2   
Target Release: 6.4.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Matej Čimbora 2014-10-10 15:26:11 UTC
Tested on 6.4.0.ER1
Used configuration:
a) SITE1: 2 nodes, cache testCacheSite1
<backups>
    <backup site="SITE2"/>
</backups>
b) SITE2: 3 nodes, cache testCacheSite1_backup – backup cache for testCacheSite1
<backup-for remote-cache="testCacheSite1" remote-site="SITE1"/>

When using backup cache with name (testCacheSite1_backup) different from the name of the main cache in SITE1 (testCacheSite1), the data is not propagated to the backup cache completely. The issue seems to be fixed by using the same name for the backup cache (testCacheSite1). 

Scenario
1. Start site1 and write data into it (1000 entries)
2. Start site2 and invoke XsiteAdminOperations.pushState(“site2”)
3. Wait 2 minutes
4. Check whether the state was transferred to site2 (tested on dist & repl backup cache configs)
a) distributed mode (numOwners=2) - expected 2000 entries in total, was 648 on site2 master & 0 on other nodes
b) replicated mode – expected 3000 entries in total, was 1000 on site2 master & 0 on other nodes
 
Trace log:
04:14:39,116 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (OOB-10,edg-perf13-23152) Silently ignoring that testCacheSite1 cache is not defined
04:14:39,375 TRACE [org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher] (OOB-10,edg-perf13-23152) Attempting to execute command: SingleRpcCommand{cacheName='testCacheSite1_backup', command=PutKeyValueCommand{key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, flags=[SKIP_REMOTE_LOOKUP, PUT_FOR_X_SITE_STATE_TRANSFER, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}} [sender=edg-perf14-31850]
04:14:39,376 TRACE [org.infinispan.statetransfer.StateTransferLockImpl] (OOB-10,edg-perf13-23152) Checking if transaction data was received for topology 4, current topology is 4
04:14:39,376 TRACE [org.infinispan.util.concurrent.BlockingTaskAwareExecutorServiceImpl] (OOB-10,edg-perf13-23152) Added a new task: 0 task(s) are waiting
04:14:39,376 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (remote-thread--p3-t2) Calling perform() on SingleRpcCommand{cacheName='testCacheSite1_backup', command=PutKeyValueCommand{key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, flags=[SKIP_REMOTE_LOOKUP, PUT_FOR_X_SITE_STATE_TRANSFER, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}}
04:14:39,378 TRACE [org.infinispan.commands.remote.BaseRpcInvokingCommand] (remote-thread--p3-t2) Invoking command PutKeyValueCommand{key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, flags=[SKIP_REMOTE_LOOKUP, PUT_FOR_X_SITE_STATE_TRANSFER, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}, with originLocal flag set to false
04:14:39,378 TRACE [org.infinispan.interceptors.InvocationContextInterceptor] (remote-thread--p3-t2) Invoked with command PutKeyValueCommand{key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, flags=[SKIP_REMOTE_LOOKUP, PUT_FOR_X_SITE_STATE_TRANSFER, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true} and InvocationContext [org.infinispan.context.impl.NonTxInvocationContext@266883cb]
04:14:39,379 TRACE [org.infinispan.statetransfer.StateTransferInterceptor] (remote-thread--p3-t2) handleNonTxWriteCommand for command PutKeyValueCommand{key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, flags=[SKIP_REMOTE_LOOKUP, PUT_FOR_X_SITE_STATE_TRANSFER, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}
04:14:39,380 TRACE [org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor] (remote-thread--p3-t2) Are (edg-perf13-23152) we the lock owners for key 'key_0000000000000001'? false
04:14:39,380 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (remote-thread--p3-t2) Wrapping entry 'key_0000000000000001'? true
04:14:39,380 TRACE [org.infinispan.container.EntryFactoryImpl] (remote-thread--p3-t2) Exists in context? null 
04:14:39,382 TRACE [org.infinispan.container.EntryFactoryImpl] (remote-thread--p3-t2) Retrieved from container null (isL1Enabled=false, isLocal=true)
04:14:39,382 TRACE [org.infinispan.container.EntryFactoryImpl] (remote-thread--p3-t2) Creating new entry.
04:14:39,388 TRACE [org.infinispan.container.EntryFactoryImpl] (remote-thread--p3-t2) Wrap key_0000000000000001 for put. Entry=ReadCommittedEntry(197b92bc){key=key_0000000000000001, value=null, oldValue=null, isCreated=true, isChanged=false, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
04:14:39,390 TRACE [org.infinispan.interceptors.CallInterceptor] (remote-thread--p3-t2) Executing command: PutKeyValueCommand{key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, flags=[SKIP_REMOTE_LOOKUP, PUT_FOR_X_SITE_STATE_TRANSFER, IGNORE_RETURN_VALUES, SKIP_XSITE_BACKUP], putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}.
04:14:39,391 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (remote-thread--p3-t2) About to commit entry ReadCommittedEntry(197b92bc){key=key_0000000000000001, value=value_key_0000000000000001_SITE1_ORIGINAL@testCacheSite1, oldValue=null, isCreated=true, isChanged=true, isRemoved=false, isValid=true, skipRemoteGet=false, metadata=EmbeddedMetadata{version=null}}
04:14:39,392 TRACE [org.infinispan.statetransfer.CommitManager] (remote-thread--p3-t2) Trying to commit. Key=key_0000000000000001. Operation Flag=PUT_FOR_X_SITE_STATE_TRANSFER, L1 invalidation=false
04:14:39,392 TRACE [org.infinispan.statetransfer.CommitManager] (remote-thread--p3-t2) Not committing key=key_0000000000000001. It is a state transfer key but no track is enabled!
04:14:39,392 TRACE [org.infinispan.interceptors.EntryWrappingInterceptor] (remote-thread--p3-t2) The return value is null


Suspicious lines:
04:14:39,116 TRACE [org.infinispan.remoting.InboundInvocationHandlerImpl] (OOB-10,edg-perf13-23152) Silently ignoring that testCacheSite1 cache is not defined

04:14:39,392 TRACE [org.infinispan.statetransfer.CommitManager] (remote-thread--p3-t2) Not committing key=key_0000000000000001. It is a state transfer key but no track is enabled!

Comment 2 JBoss JIRA Server 2014-10-14 11:06:01 UTC
Pedro Ruivo <pruivo> updated the status of jira ISPN-4826 to Coding In Progress

Comment 3 Sebastian Łaskawiec 2014-10-23 09:08:25 UTC
PR: https://github.com/infinispan/jdg/pull/293

Comment 4 Matej Čimbora 2014-10-23 14:36:38 UTC
Verified, working now for library mode. Another bz [1] has been created, to be able to specify custom backup cache name for client-server mode (tested on JDG 6.4.0.ER2).

[1] https://bugzilla.redhat.com/show_bug.cgi?id=1156088