Bootstrap completes before replication

Type: Bug
Status: New
Priority: 2 Major
Resolution:
Component/s: ehcache-jgroupsreplication
Labels:

Assignee: drb
Reporter: onetimer
Created: October 06, 2015
Votes: 0
Watchers: 1
Updated:
October 06, 2015
Resolved:

Attachments

onetimer (967.0) text/xml ehcache.xml

Description

Using bootstrap to keep information loaded across 2 Server Nodes. When doing a rolling restart a Node always stays up. When I boot the 1st Node up from a deployment, sometimes, not always, the cache is not loaded back into the 1st Node from Node 2nd where the data is replicated

JGroupsCacheReceiver|DEBUG||received bootstrap complete:   cache=tokenCache
JGroupsBootstrapManager|INFO ||Bootstrap for cache tokenCache is complete, loaded 0 elements
JGroupsCacheReceiver|DEBUG||received bootstrap reply:      cache=tokenCache, key=92b00b82-10f7-41d5-81bf-77cda762d421
JGroupsBootstrapManager|WARN ||No BootstrapRequest registered for cache tokenCache, the event will have no effect: JGroupEventMessage [event=BOOTSTRAP_RESPONSE, cacheName=tokenCache, serializableKey=92b00b82-10f7-41d5-81bf-77cda762d421, element=[ key = 92b00b82-10f7-41d5-81bf-77cda762d421, value=user1234, version=1, hitCount=0, CreationTime = 1444165390000, LastAccessTime = 1444165390000 ]]
JGroupsBootstrapManager|DEBUG||Removed BootstrapRequest [cache=tokenCache, bootstrapStatus=COMPLETE, boostrapCompleteLatch=0, replicated=0, asynchronous=true, chunkSize=5000000]

Since Node 2 seems to be sending a “complete” message it doesn’t seem like a problem with timeout, it seems Node 2 just doesn’t check or the process is asleep sometimes when it receives the message.

See “Bug Found In Detail” for version numbers. (For 2.10.0 I had to do the fix described here to get it to work http://stackoverflow.com/questions/29298776/how-do-i-integrate-ehcache-2-9-jgroups-replication)

Comments

Flavel Heyman 2015-10-06

Forgot to retrieve the beginning of the messaging for the cache:

Cache|DEBUG||Initialised cache: tokenCache
JGroupsBootstrapManager|DEBUG||Scheduled BootstrapRequest Reference cleanup timer with 60000ms period
JGroupsBootstrapManager|DEBUG||Registered BootstrapRequest [cache=tokenCache, bootstrapStatus=UNSENT, boostrapCompleteLatch=1, replicated=0, asynchronous=true, chunkSize=5000000]
ConfigurationHelper|DEBUG||CacheDecoratorFactory not configured. Skipping for 'tokenCache'.
ConfigurationHelper|DEBUG||CacheDecoratorFactory not configured for defaultCache. Skipping for 'tokenCache'.
JGroupsBootstrapManager|DEBUG||Loading cache tokenCache with local address node1-56727 from peers: [node2-21383]
10-06-2015|16:04:14:025|net.sf.ehcache.distribution.jgroups.JGroupsBootstrapManager|DEBUG||Requesting bootstrap of tokenCache from node2-21383

Flavel Heyman 2015-10-06

The following a successful bootstrap. It says it loaded 0 elements, but it it lies.

Cache|DEBUG||Initialised cache: tokenCache
JGroupsBootstrapManager|DEBUG||Scheduled BootstrapRequest Reference cleanup timer with 60000ms period
JGroupsBootstrapManager|DEBUG||Registered BootstrapRequest [cache=tokenCache, bootstrapStatus=UNSENT, boostrapCompleteLatch=1, replicated=0, asynchronous=true, chunkSize=5000000]
ConfigurationHelper|DEBUG||CacheDecoratorFactory not configured. Skipping for 'tokenCache'.
ConfigurationHelper|DEBUG||CacheDecoratorFactory not configured for defaultCache. Skipping for 'tokenCache'.
JGroupsBootstrapManager|DEBUG||Loading cache tokenCache with local address node1-39221 from peers: [node2-21383]
JGroupsBootstrapManager|DEBUG||Requesting bootstrap of tokenCache from node2-21383
JGroupsCachePeer|DEBUG||Sending 1 JGroupEventMessages synchronously.
JGroupsCacheReceiver|DEBUG||received bootstrap complete:   cache=tokenCache
JGroupsCacheReceiver|DEBUG||received bootstrap reply:      cache=tokenCache, key=39e16bf8-c738-4d06-afd8-2765bff1ad71
JGroupsBootstrapManager|INFO ||Bootstrap for cache tokenCache is complete, loaded 0 elements
JGroupsBootstrapManager|DEBUG||Removed BootstrapRequest [cache=tokenCache, bootstrapStatus=COMPLETE, boostrapCompleteLatch=0, replicated=0, asynchronous=true, chunkSize=5000000]