And what would be the exact name of the write-behind delay parameter and where is it documented?  Tks

Yes, the <write-delay> parameter.  So we've set this to 5 s to enable the write-behind behavior.

So what you are saying is that the minimum amount of time between retries for requeued stores is 1 minute in our case, unless we put the write-delay setting above 30 seconds.

Understood.

Tks

Hi Randy,

It's JP from T***S.

We had this write-behind cache (FraudWirelessCacheStore) running on 4 storage nodes, defined in its own cache service (DistributedCache:DistributedCacheService-DataGrid-EVENTNOTIFY-FraudMgmt-Message).

We found out after a few days that the thread associated with the write-behind cache service on one of the nodes kept logging thread dumps after soft-timeout detection (<cachestore-timeout> was not set):

ERROR 2019-06-28 04:26:57,977 [com.tangosol.coherence.component.util.logOutput.Log4j] - 2019-06-28 04:26:57.977/3086020.634 Oracle Coherence GE 12.2.1.3.2 <Error> (thread=DistributedCache:DistributedCacheService-DataGrid-EVENTNOTIFY-FraudMgmt-Message, member=16): Detected soft timeout of {WrapperGuardable Daemon{Thread="Thread[WriteBehindThread:CacheStoreWrapper(xxxxxxxxxxxxxxxxxxxxxxxxxxxxx.cachestore.FraudWirelessCacheStore):DistributedCacheService-DataGrid-EVENTNOTIFY-FraudMgmt-Message:xxxxxxxxxxxxxxxxxxxxxxxxxxxxx.FraudWirelessEventMessage,5,WriteBehindThread:CacheStoreWrapper(xxxxxxxxxxxxxxxxxxxxxxxxxxxxx.cachestore.FraudWirelessCacheStore):DistributedCacheService-DataGrid-EVENTNOTIFY-FraudMgmt-Message]", State=Running} Service=PartitionedCache{Name=DistributedCacheService-DataGrid-EVENTNOTIFY-FraudMgmt-Message, State=(SERVICE_STARTED), Id=10, OldestMemberId=1, LocalStorage=enabled, PartitionCount=257, BackupCount=0, AssignedPartitions=21, CoordinatorId=1}}

From the thread dump, looking at the stack trace of that thread, this is what we could see:

"WriteBehindThread:CacheStoreWrapper(xxxxxxxxxxxxxxxxxxxxxxxxxxxxx.cachestore.FraudWirelessCacheStore):DistributedCacheService-DataGrid-EVENTNOTIFY-FraudMgmt-Message:xxxxxxxxxxxxxxxxxxxxxxxxxxxxx.FraudWirelessEventMessage" id=69 State:RUNNABLE (in native)

at java.net.SocketInputStream.socketRead0(Native Method)

at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)

at java.net.SocketInputStream.read(SocketInputStream.java:171)

at java.net.SocketInputStream.read(SocketInputStream.java:141)

at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)

at sun.security.ssl.InputRecord.readV3Record(InputRecord.java:593)

at sun.security.ssl.InputRecord.read(InputRecord.java:532)

at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:975)

-  locked java.lang.Object@7973ed67

at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1367)

-  locked java.lang.Object@bc1bb94

at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1395)

at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1379)

at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:396)

at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:355)

at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)

at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:359)

at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381)

at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237)

at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)

at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)

at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)

at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)

at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)

at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)

at xxxxxxxxxxxxxxxxxxxxxxxx.cachestore.client.RestWSClient.sendMessage(RestWSClient.java:111)

at xxxxxxxxxxxxxxxxxxxxxxxx.cachestore.client.RestWSClient.sendMessage(RestWSClient.java:28)

at xxxxxxxxxxxxxxxxxxxxxxxx.cachestore.AbstractMessageCacheStore.sendMessage(AbstractMessageCacheStore.java:214)

at xxxxxxxxxxxxxxxxxxxxxxxx.cachestore.AbstractMessageCacheStore.storeAndSendMessage(AbstractMessageCacheStore.java:190)

at xxxxxxxxxxxxxxxxxxxxxxxx.cachestore.AbstractMessageCacheStore.store(AbstractMessageCacheStore.java:117)

at com.tangosol.net.cache.ReadWriteBackingMap$CacheStoreWrapper.storeInternal(ReadWriteBackingMap.java:6014)

at com.tangosol.net.cache.ReadWriteBackingMap$StoreWrapper.store(ReadWriteBackingMap.java:5085)

at com.tangosol.net.cache.ReadWriteBackingMap$WriteThread.run(ReadWriteBackingMap.java:4491)

at com.tangosol.util.Daemon$DaemonWorker.run(Daemon.java:806)

at java.lang.Thread.run(Thread.java:748)

So this cache store uses apache CloseableHttpClient to send a request to a REST service based on the store data.  This HTTPclient had no configured timeouts, all defaults and uses a pool, although not useful since the write-behind is single threaded per JVM.

We think this HTTP client had some issue connecting to the REST target and somehow the connection was never properly resetted.  So it kept failing, and the wrote-behind retry queue kept growing - measured though the CacheMBean QueueSize JMX metric.

We since have changed the proper connection timeouts on the HTTP client, but then we wanted to know exactly what were the retry delays on the queue to fully understand the write-behind behaviour.

I implemented a custom "re-queue 3 time then forget" logic and I have to mention that it was fairly easy to implement within the cache store and using an extra transient retry attribute to the cache entry.  Tested it and worked fine.

So we might not need it after all, but we might in a future use-case.

Thanks for your contribution, always much appreciated.

Regards,

JP