Terracotta Discussion Forums

Is it possible to start up a writebehind cache writer again once it has stopped due to to many retries?

For ex. My DB goes down, the cahce writer will then try to write to the db but fails and does so for all the retries that I have configured. Then my DB goes back on again and I will want to resume normal operation again, but my write behind writers have shut down. Is it possible to start them again?

I might be confused about your question, but the writer shouldn't be stopped because of too many failures !? The writer will only be stopped if you do so, or shut the cache down. Am I missing something ? Basically lifecycle will be managed by the cache, which is managed by the CacheManager.

I dont know if I am doing something wrong or just explaining wrong. Lets try again. I have a Write behind cache, it has a property of retryAttempts and retryAttemptDelaySeconds. When all retries are "used up" I get an error saying:

net.sf.ehcache.CacheException: The element '[ key = 2012-02-02:457726799:1:false, value=net.nnn.action.vo.ActionCountVO@7df8290d, version=1, hitCount=0, CreationTime = 1328192329536, LastAccessTime = 1328192329536 ]' couldn't be added through the write-behind queue for cache 'ActionCountWriteBehind' since it's not started.

I thought this was the result of the retries. Any suggestions?

I didn't realize that would be a potential behaviour. Could be I'm just missing something. Could you post your ehcache version and config ? At least the bits for the ActionCountWriteBehind cache. I might have a theory, but would first rather double check this behaviour really isn't the one you should see...

Version ehcache-core-2.5.0.jar

<cache name="ActionCountWriteBehind" maxElementsInMemory="100000" maxElementsOnDisk="200000" eternal="false" timeToIdleSeconds="87300" timeToLiveSeconds="87300">
<cacheWriter writeMode="write-behind" maxWriteDelay="60" writeCoalescing="true" writeBatching="true" writeBatchSize="100" retryAttempts="20" retryAttemptDelaySeconds="10" notifyListenersOnException="false">
<cacheWriterFactory class="net.nnn.common.cache.ActionCountCacheWriterFactory" />
</cacheWriter>

</cache>

I just found this:
https://jira.terracotta.org/jira/browse/EHC-750

Could the solution be that simple to add :

catch (CacheException ce) {
logger.error("Cache Exception Error saving actionCountVO", ce);
}

or will this cause other functionallity to break the for ex, writeAll method in the writer wants to throw that exception, so if I catch it it may break other error handling.

As far as I can tell by reading the 2.5 code, only InterruptedException should bubble up and shut the writer down. But I could be missing something. Can you provide some stack trace of the failure ?
I'll be writing a small test case in the meantime.

I will start a test and shut down db to reproduce. Im in sweden so its sleeping time now (01:45) , I will reply when I have the stacktrace.

I did a couple of tests based on unit tests that we have and couldn't reproduce this. Now earlier versions in unclustered did behave inconsistently, but 2.5.x should be good. Now one way to have this fail still it interrupting the thread that does the writing. Could it be this is happening ?

Can you isolate the failure and provide a reproducible test case ?

I will try to get the stacktrace to you first, I havent had time to fix this yet. I have had a release to fix inbetween. I get back to you.

The write-behind queue is getting stopped when there is even a null pointer exception. I am using 2.5.1 version.
Please see the below stack trace. First when a null pointer is encountered, I guess the queue is stopped, so the subsequent writes are not able to be written to the persistant storage.

DEBUG : 09 Mar 2012 16:16:43,311 - com.system.commerce.interfaces.jms.InventoryJMSListener : The incoming inventory message
INFO : 09 Mar 2012 16:16:43,317 - com.system.commerce.interfaces.cache.diffinventory.InventoryDifferentialCache : No resultant value for this
INFO : 09 Mar 2012 16:16:43,318 - com.system.commerce.interfaces.inventory.InventoryOperationsManager : The differential inventory for partnumber 468117536988 is -1
INFO : 09 Mar 2012 16:16:43,514 - com.system.commerce.interfaces.cache.inventory.InventoryCacheWriter : Time : Fri Mar 09 16:16:43 PST 2012the element collection is being written - has count :1
INFO : 09 Mar 2012 16:16:43,514 - com.system.commerce.interfaces.db.dao.InventoryDBAccessV2 : Update buyable flag to '1' for 468117536988
INFO : 09 Mar 2012 16:16:43,535 - com.system.commerce.interfaces.db.dao.InventoryDBAccessV2 : Update availability code to '1' for 468117536988
INFO : 09 Mar 2012 16:16:43,554 - com.system.commerce.interfaces.db.dao.InventoryDBAccessV2 : Update Gross Margin, GM-Units{57}, GM-Dollars {2134650.0}, GM-Cost {1068750.0}, GM-Average Unit Cost {0.0 } for 468117536988
DEBUG : 09 Mar 2012 16:16:43,554 - com.system.commerce.interfaces.common.modal.InventoryMessageBean : Gross Margin Calculation for Part number : 468117536988, using formula ...
ERROR : 09 Mar 2012 16:16:43,554 - com.system.commerce.interfaces.db.dao.InventoryDBAccessV2 : Generic Exception happened while updating the Gross Margin null
java.lang.NullPointerException
at com.system.commerce.interfaces.common.modal.InventoryMessageBean.calculateGrossDemandNew(InventoryMessageBean.java:675)
at com.system.commerce.interfaces.db.dao.InventoryDBAccessV2.updateGrossMargin(InventoryDBAccessV2.java:148)
at com.system.commerce.interfaces.db.dao.InventoryDBAccessV2.syncWithCommerceDB(InventoryDBAccessV2.java:717)
at com.system.commerce.interfaces.inventory.InventoryOperationsManager.syncWithCommerceDB(InventoryOperationsManager.java:109)
at com.system.commerce.interfaces.cache.inventory.InventoryCacheWriter.inventoryWrite(InventoryCacheWriter.java:94)
at com.system.commerce.interfaces.cache.inventory.InventoryCacheWriter.writeAll(InventoryCacheWriter.java:136)
at net.sf.ehcache.writer.writebehind.operations.WriteAllOperation.performBatchOperation(WriteAllOperation.java:45)
at net.sf.ehcache.writer.writebehind.WriteBehindQueue.processBatchedOperations(WriteBehindQueue.java:374)
at net.sf.ehcache.writer.writebehind.WriteBehindQueue.processQuarantinedItems(WriteBehindQueue.java:340)
at net.sf.ehcache.writer.writebehind.WriteBehindQueue.processItems(WriteBehindQueue.java:285)
at net.sf.ehcache.writer.writebehind.WriteBehindQueue.access$200(WriteBehindQueue.java:47)
at net.sf.ehcache.writer.writebehind.WriteBehindQueue$ProcessingThread.run(WriteBehindQueue.java:151)
at java.lang.Thread.run(Thread.java:736)
ERROR : 09 Mar 2012 16:16:43,555 - com.system.commerce.interfaces.db.dao.InventoryDBAccessV2 : Generic Exception happened while Synching with the Commerce DB for partnumber number 468117536988
DEBUG : 09 Mar 2012 16:16:45,543 - com.system.commerce.interfaces.jms.InventoryJMSListener : The incoming inventory message
INFO : 09 Mar 2012 16:16:45,546 - com.system.commerce.interfaces.inventory.InventoryOperationsManager : The differential inventory for partnumber 472037683738 is -1
ERROR : 09 Mar 2012 16:16:45,546 - com.system.commerce.interfaces.jms.InventoryJMSListener : Exception happened while processing inbound message The element '[ key = 472037683738, value=com.system.commerce.interfaces.common.modal.InventoryMessageBean@3520352, version=1, hitCount=0, CreationTime = 1331338605546, LastAccessTime = 0 ]' couldn't be added through the write-behind queue for cache 'inventoryCache' since it's not started.
net.sf.ehcache.CacheException: The element '[ key = 472037683738, value=com.system.commerce.interfaces.common.modal.InventoryMessageBean@3520352, version=1, hitCount=0, CreationTime = 1331338605546, LastAccessTime = 0 ]' couldn't be added through the write-behind queue for cache 'inventoryCache' since it's not started.
at net.sf.ehcache.writer.writebehind.WriteBehindQueue.write(WriteBehindQueue.java:451)
at net.sf.ehcache.writer.writebehind.WriteBehindQueueManager.write(WriteBehindQueueManager.java:75)
at net.sf.ehcache.writer.writebehind.WriteBehindManager.put(WriteBehindManager.java:60)
at net.sf.ehcache.store.MemoryStore.putWithWriter(MemoryStore.java:282)
at net.sf.ehcache.store.FrontEndCacheTier.putWithWriter(FrontEndCacheTier.java:284)
at net.sf.ehcache.Cache.putInternal(Cache.java:1474)
at net.sf.ehcache.Cache.putWithWriter(Cache.java:1432)
at com.system.commerce.interfaces.cache.inventory.InventoryCache.writeData(InventoryCache.java:102)
at com.system.commerce.interfaces.inventory.InventoryOperationsManager.processInventory(InventoryOperationsManager.java:267)
at com.system.commerce.interfaces.jms.InventoryJMSListener.processInventoryMessage(InventoryJMSListener.java:165)
at com.system.commerce.interfaces.jms.InventoryJMSListener.process(InventoryJMSListener.java:141)
at com.system.commerce.interfaces.jms.InventoryJMSListener.onMessage(InventoryJMSListener.java:90)
at com.ibm.mq.jms.MQMessageConsumer$FacadeMessageListener.onMessage(MQMessageConsumer.java:399)
at com.ibm.msg.client.jms.internal.JmsMessageConsumerImpl$JmsProviderMessageListener.onMessage(JmsMessageConsumerImpl.java:879)

adithyar: Did you manage to workaround it? I havent had time to look into this myself yet.

I had to do the obvious work around of capturing exception and suppressing them as of now as I too had very little time to go through the ehcache source to figure out problem as the deployment was a just a few days after i posted the stacktrace.

This was not the case with version 2.4.x, which i was using before. It started happening only after i upgraded to 2.5.1 version. I have had many exceptions happen while using the older version and never had any issues with the write-behind queue.

But i planning to debug with the ehcache source code next week and so I will able to post whatever i find.