Do I untherstand the concept of Ehcache 3 with terracotta?

[Ferdinand]

1. What version of Ehcache you are currently using;
2. Paste the configuration for the Cache/CacheManager you have an issue with;
3. Add any name and version of other library or framework you use Ehcache with (e.g. Hibernate);
4. Providing JDK and OS versions maybe useful as well.

 I'm currently implemented ehcache 3.6.1. But need to use it in a multi-node envorionment. So I decided to use the terracotta cluster kit(3.6.1) to set this up. Al seemed to work perfectly when using a single node, but when I use 2 nodes strange things happen.

For terracotta I used the very basic configuration see the attachment.

For the 2 nodes I use the excly the same ehcache.xml to connect to the terracotta:

<?xml version="1.0" encoding="UTF-8"?>
<config
    xmlns="http://www.ehcache.org/v3"
    xmlns:jsr107="http://www.ehcache.org/v3/jsr107"
    xmlns:mnm="http://www.ehcache.org/v3/management"
    xmlns:tc="http://www.ehcache.org/v3/clustered">
   
    <!-- Use below for cluster setup -->
    <service>
        <tc:cluster>
            <tc:connection url="terracotta://localhost/clustered"/>
            <tc:server-side-config auto-create="true">
                <tc:default-resource from="primary-server-resource"/>        
            </tc:server-side-config>
        </tc:cluster>
    </service>

    <cache-template name="single-entry-cache">
            <expiry>
                <ttl unit="seconds">10</ttl>
            </expiry>
            <resources>
                <heap unit="entries">1</heap>
                <tc:clustered-dedicated unit="MB">1</tc:clustered-dedicated>
            </resources>
            <tc:clustered-store consistency="strong"/>
    </cache-template>

    <cache-template name="default-cache">
        <expiry>
            <ttl unit="seconds">3600</ttl>
        </expiry>
        <resources>    
            <heap unit="entries">1000</heap>
            <tc:clustered-dedicated unit="MB">10</tc:clustered-dedicated>
        </resources>
        <tc:clustered-store consistency="strong"/>
    </cache-template>
    <cache-template name="big-cache">
        <expiry>
            <ttl unit="seconds">3600</ttl>
        </expiry>
        <resources>    
            <heap unit="entries">10000</heap>
            <tc:clustered-dedicated unit="MB">100</tc:clustered-dedicated>
        </resources>
        <tc:clustered-store consistency="strong"/>
    </cache-template>

    <cache-template name="default-query-results-region">
        <expiry>
            <ttl unit="seconds">600</ttl>
        </expiry>
        <resources>
            <heap unit="entries">5000</heap>
            <tc:clustered-dedicated unit="MB">50</tc:clustered-dedicated>
        </resources>
        <tc:clustered-store consistency="strong"/>
    </cache-template>

    <cache-template name="default-update-timestamps-region" >
        <expiry>
            <none />
        </expiry>
        <resources>
            <heap unit="entries">1000</heap>
            <tc:clustered-dedicated unit="MB">10</tc:clustered-dedicated>            
        </resources>
        <tc:clustered-store consistency="strong"/>
    </cache-template>

<!-- removed using the templates below, because it is not needed for this discussion -->

When connecting the nodes it works for a while, but after some klicking in my application it stall's. No error is given.

When connect jmx of tc server I see permanent0 and permanent1 with the same remoteName and different remoteAdress(port)

So yust to be sure, should it work with my configuration? Or do I miss something?

[Anthony Dahanne]

Hello Ferdinand, 

That looks like a correct setup; although be careful with the host parameter given to your tc server : if you're using localhost, only clients on localhost will be able to access it.

As a rule of thumb, make sure the clients and server are in the same network / NAT .

Other than that, it should  work fine, add a passive or 2 to prevent failures would be my advice.

if that still does not work, please provide more logs (clients and server)

HTH

Anthony

[Ferdinand]

Hi Anthony,

Thanks for confirmation that I'm on the right way. I have installed the kit on localhost and also spin up 2 tomcat applications in a cluster on localhost, so that should be fine.

So meanwhile I removed some of my @Cacheable @Cache(region = "definition", usage = CacheConcurrencyStrategy.READ_WRITE) on my hibernate entities and came up with the following erorrs on my client. Any idea?

[2019-04-19 13:39:54.499] ector Thread_R [ ] ERROR com.tc.net.protocol.tcm.TCMessageParser Invalid header length ! length = 0
[2019-04-19 13:39:54.499] ector Thread_R [ ] ERROR com.tc.net.protocol.tcm.TCMessageParser error header = msgType: ZERO_MESSAGE, msgVer=2
 
[2019-04-19 13:39:54.499] ector Thread_R [ ] ERROR com.tc.net.protocol.tcm.TCMessageParser  buffer data is TCByteBufferJDK14@899308735(java.nio.HeapByteBuffer[pos=0 lim=41 cap=41]) { 0 0 0 0 0 2 1 0 2 0 0 0 0 0 0 5 -128 0 0 0 9 8 10 1 82 20 3 10 1 0 2 0 0 0 1 40 0 64 1 -86 -86  }  
[2019-04-19 13:39:54.500] ector Thread_R [ ] ERROR com.tc.net.core.TCConnection com.tc.net.core.TCConnectionImpl@334509349: connected: true, closed: false local=127.0.0.1:35536 remote=127.0.0.1:9410 connect=[Fri Apr 19 13:38:57 CEST 2019] idle=1ms [749873 read, 569004 write]buffer=com.tc.net.core.ClearTextBufferManager@55832208 Invalid header length: 0
[2019-04-19 13:39:54.505] ector Thread_R [ ] ERROR com.tc.net.core.TCConnectionManager Exception:  java.lang.RuntimeException: Invalid header length: 0
    at com.tc.net.protocol.tcm.TCMessageParser.parseMessage(TCMessageParser.java:46)
    at com.tc.net.protocol.tcm.AbstractMessageChannel.receive(AbstractMessageChannel.java:215)
    at com.tc.net.protocol.transport.MessageTransportBase.receiveToReceiveLayer(MessageTransportBase.java:134)
    at com.tc.net.protocol.transport.ClientMessageTransport.receiveTransportMessageImpl(ClientMessageTransport.java:253)
    at com.tc.net.protocol.transport.MessageTransportBase.receiveTransportMessage(MessageTransportBase.java:112)
    at com.tc.net.protocol.transport.ClientMessageTransport$1.putMessage(ClientMessageTransport.java:445)
    at com.tc.net.protocol.transport.WireProtocolAdaptorImpl.addReadData(WireProtocolAdaptorImpl.java:75)
    at com.tc.net.core.TCConnectionImpl.addNetworkData(TCConnectionImpl.java:826)
    at com.tc.net.core.TCConnectionImpl.doReadFromBufferInternal(TCConnectionImpl.java:488)
    at com.tc.net.core.TCConnectionImpl.doReadFromBuffer(TCConnectionImpl.java:342)
    at com.tc.net.core.TCConnectionImpl.doReadInternal(TCConnectionImpl.java:325)
    at com.tc.net.core.TCConnectionImpl.doRead(TCConnectionImpl.java:309)
    at com.tc.net.core.CoreNIOServices$CommThread.selectLoop(CoreNIOServices.java:662)
    at com.tc.net.core.CoreNIOServices$CommThread.run(CoreNIOServices.java:366)

[2019-04-19 13:39:54.506] ector Thread_R [ ] ERROR com.tc.net.core.TCConnection com.tc.net.core.TCConnectionImpl@334509349: connected: true, closed: true local=127.0.0.1:35536 remote=127.0.0.1:9410 connect=[Fri Apr 19 13:38:57 CEST 2019] idle=1ms [749873 read, 569004 write]buffer=com.tc.net.core.ClearTextBufferManager@55832208 Invalid magic number: 3961796 != -1431655766
[2019-04-19 13:39:54.506] ector Thread_R [ ] ERROR com.tc.net.core.TCConnection com.tc.net.core.TCConnectionImpl@334509349: connected: true, closed: true local=127.0.0.1:35536 remote=127.0.0.1:9410 connect=[Fri Apr 19 13:38:57 CEST 2019] idle=0ms [749873 read, 569004 write]buffer=com.tc.net.core.ClearTextBufferManager@55832208 Invalid Header Length: 4, min: 32, max: 60, bufLen: 32
[2019-04-19 13:39:54.533]  [_default_]-0 [ ] ERROR com.terracotta.connection.entity.TerracottaEntityRef Exception:  com.tc.object.LocalConnectionClosedException: org.ehcache.clustered.client.internal.store.InternalClusterTierClientEntity:clustered$educator-catalog-definition - Connection closed before sending message
    at com.tc.object.ExceptionUtils.throwRuntimeExceptionWithLocalStack(ExceptionUtils.java:65)
    at com.tc.object.ExceptionUtils.addLocalStackTraceToEntityException(ExceptionUtils.java:34)
    at com.tc.object.InFlightMessage.getWithTimeout(InFlightMessage.java:189)
    at com.tc.object.InFlightMessage.get(InFlightMessage.java:153)
    at com.tc.object.ClientEntityManagerImpl.sendMessageWhileBusy(ClientEntityManagerImpl.java:466)
    at com.tc.object.ClientEntityManagerImpl.internalRelease(ClientEntityManagerImpl.java:446)
    at com.tc.object.ClientEntityManagerImpl.internalLookup(ClientEntityManagerImpl.java:431)
    at com.tc.object.ClientEntityManagerImpl.fetchEntity(ClientEntityManagerImpl.java:148)
    at com.terracotta.connection.entity.TerracottaEntityRef.fetchEntity(TerracottaEntityRef.java:85)
    at org.ehcache.clustered.client.internal.ClusterTierManagerClientEntityFactory.fetchClusterTierClientEntity(ClusterTierManagerClientEntityFactory.java:322)
    at org.ehcache.clustered.client.internal.ClusterTierManagerClientEntityFactory.getClusterTierClientEntity(ClusterTierManagerClientEntityFactory.java:315)
    at org.ehcache.clustered.client.internal.service.ConnectionState.createClusterTierClientEntity(ConnectionState.java:101)
    at org.ehcache.clustered.client.internal.service.DefaultClusteringService.getServerStoreProxy(DefaultClusteringService.java:256)
    at org.ehcache.clustered.client.internal.store.ClusteredStore$Provider.initStore(ClusteredStore.java:662)
    at org.ehcache.clustered.client.internal.store.ClusteredStore$Provider.lambda$null$0(ClusteredStore.java:708)
    at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1626)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
Caused by: org.terracotta.exception.ConnectionClosedException: Connection closed before sending message
    at com.tc.object.ClientEntityManagerImpl.throwClosedExceptionOnMessage(ClientEntityManagerImpl.java:383)
    at com.tc.object.ClientEntityManagerImpl.queueInFlightMessage(ClientEntityManagerImpl.java:512)
    at com.tc.object.ClientEntityManagerImpl.sendMessageWhileBusy(ClientEntityManagerImpl.java:464)
    ... 14 common frames omitted

[2019-04-19 13:39:54.538] o-8091-exec-44 [fitnesse fg] ERROR org.ehcache.core.internal.resilience.RobustResilienceStrategy Ehcache key ...#10043 in possible inconsistent state - Similar messages will be suppressed for 30 seconds org.ehcache.spi.resilience.StoreAccessException: org.ehcache.clustered.client.internal.store.ReconnectInProgressException: Connection lost to server. Client is trying to reconnect to server
    at org.ehcache.core.exceptions.StorePassThroughException.handleException(StorePassThroughException.java:78)
    at org.ehcache.clustered.client.internal.store.ClusteredStore.getInternal(ClusteredStore.java:199)
    at org.ehcache.clustered.client.internal.store.ClusteredStore.getAndFault(ClusteredStore.java:508)
    at org.ehcache.impl.internal.store.tiering.TieredStore.lambda$get$0(TieredStore.java:89)
    at org.ehcache.impl.internal.store.heap.OnHeapStore.lambda$getOrComputeIfAbsent$12(OnHeapStore.java:684)
    at org.ehcache.impl.internal.store.heap.OnHeapStore$Fault.getValueHolder(OnHeapStore.java:971)
    at org.ehcache.impl.internal.store.heap.OnHeapStore$Fault.access$300(OnHeapStore.java:944)
    at org.ehcache.impl.internal.store.heap.OnHeapStore.resolveFault(OnHeapStore.java:722)
    at org.ehcache.impl.internal.store.heap.OnHeapStore.getOrComputeIfAbsent(OnHeapStore.java:688)
    at org.ehcache.impl.internal.store.tiering.TieredStore.get(TieredStore.java:87)
    at org.ehcache.core.Ehcache.doGet(Ehcache.java:82)
    at org.ehcache.core.EhcacheBase.get(EhcacheBase.java:127)
    at org.ehcache.jsr107.Eh107Cache.get(Eh107Cache.java:90)
    at org.hibernate.cache.jcache.internal.JCacheAccessImpl.getFromCache(JCacheAccessImpl.java:38)
    at org.hibernate.cache.spi.support.AbstractReadWriteAccess.putFromLoad(AbstractReadWriteAccess.java:101)
    at org.hibernate.cache.spi.support.AbstractReadWriteAccess.putFromLoad(AbstractReadWriteAccess.java:137)
    at org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:226)
    at org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:129)
    at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:1151)
    at org.hibernate.loader.Loader.processResultSet(Loader.java:1010)
    at org.hibernate.loader.Loader.doQuery(Loader.java:948)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:340)
    at org.hibernate.loader.Loader.doList(Loader.java:2695)
    at org.hibernate.loader.Loader.doList(Loader.java:2678)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2512)
    at org.hibernate.loader.Loader.list(Loader.java:2507)
    at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:109)
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1999)
    at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:370)
    at ...Repository.getObjects(AbstractHibernateReadRepository.java:357)
/../
Caused by: org.ehcache.clustered.client.internal.store.ReconnectInProgressException: Connection lost to server. Client is trying to reconnect to server
    at org.ehcache.clustered.client.internal.store.ReconnectingServerStoreProxy$ReconnectInProgressProxy.get(ReconnectingServerStoreProxy.java:137)
    at org.ehcache.clustered.client.internal.store.ReconnectingServerStoreProxy.lambda$get$0(ReconnectingServerStoreProxy.java:56)
    at org.ehcache.clustered.client.internal.store.ReconnectingServerStoreProxy.onStoreProxy(ReconnectingServerStoreProxy.java:99)
    at org.ehcache.clustered.client.internal.store.ReconnectingServerStoreProxy.onStoreProxy(ReconnectingServerStoreProxy.java:105)
    at org.ehcache.clustered.client.internal.store.ReconnectingServerStoreProxy.get(ReconnectingServerStoreProxy.java:56)
    at org.ehcache.clustered.client.internal.store.ClusteredStore.getInternal(ClusteredStore.java:178)
    ... 153 common frames omitted

Op woensdag 17 april 2019 16:15:53 UTC+2 schreef Anthony Dahanne:

[Anthony Dahanne]

Hello Ferdinand,

If you change your caching topology, I'd suggest you to also "reset" your clustered layer by simply restarting your terracotta servers ?

Let us know if that helps,

Anthony

[Ferdinand]

Sorry for the late reaction, but I was on Holiday.

I did stopped and started the terracotta-kit server and my application nodes, with no result, same errors and stalls.

I have only 1 terracotta server and 2 application nodes for this test. Should look into this on a later moment and investigate more time. But for the sake of time I will skipp using terracotta and use second level cache per server with very low duration, with the down-fall of having not all(non fatal, definition like) entities in sync.

Or maybe I have to look at infinispan.

Anyway thanks for the help. If somebody have the same problems and have found a sollution, please let me know.

Op dinsdag 23 april 2019 15:22:01 UTC+2 schreef Anthony Dahanne:

[Ferdinand]

Just had some time left to do some investigation again and started by disabling all @Caches for my entities. And started with a simple Entity. All goes right. After adding almost all, everything is still good.

Oke, I was little confused because this is not what I expected. So I did take a diff with what I changed at my struggle earlier and found out that the following property was changed to false.

hibernate.generate_statistics=false

When I set this to true again I directly get problems on multi node:

[2019-05-06 08:56:41.866] _ack_stage, 0) [ ] ERROR com.tc.async.api.Stage: multi_request_ack_stage ClientID[1]: Uncaught exception in stage org.hibernate.HibernateException: Could not find a SessionFactory [uuid=29bbaed7-a412-469f-91d6-36f23c89e460,name=null]
    at org.hibernate.type.spi.TypeConfiguration$Scope.readResolve(TypeConfiguration.java:366)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)

    at java.io.ObjectStreamClass.invokeReadResolve(ObjectStreamClass.java:1260)
... many more, after that it get connection lost problems.


Seems that I found my enemy here :D. Tested with the setting to false (without some big entities) and found no problems anymore. No idea why, maybe somebody can explain. But for now I'm glad is is working.





Greetings, Ferdinand


Op vrijdag 19 april 2019 14:23:23 UTC+2 schreef Ferdinand: