Logging in Infinispan Cluster

[stephanf]

We have an application using hibernate 5.2.5 with hibernate-infinispan / infinispan 8.2.5 as 2nd level cache implementation.This application runs in a cluster of 4 nodes.

Occasionally we get reports for errors which look as if the caches of those nodes went out of sync. Manually clearing the caches fixes those errors.

We have not been able to reproduce those errors in a controlled environment so far.

What we'd like to do is enable some kind of logging to pin down what's happening with the caches and cache cluster when such an error appears.

What we've done so far:

* Implemented a listener for the cache manager listening to ViewChangedEvent, logging when the members of the cluster change. This seems to work judging from the output generated when restarting a node.

* Implemented another listener for the entity caches, listening to CacheEntryInvalidatedEvent. The intent here is to see, after another of those errors occurred, whether some cache entry was not invalidated even though it should have been.

The latter does not (yet) work. The cache in question has the mode INVALIDATION_SYNC.

My understanding is, that if for example two nodes have a cache entry for the same entity, and on one of those nodes the entity is changed, the entry on the other node should be invalidated, and the event fired.

Is my understanding wrong? Have I overlooked something?

Another question: Are there any other ideas what kind of logging could be enabled, or other measures taken, to help analyze our issue?

Thank you

[galder.zamarreno]

Hi Stephan,

From a Hibernate Infinispan cache perspective, the biggest detail is achieved when TRACE is enabled on org.infinispan and org.hibernate.infinispan packages. You can try to run with DEBUG on this packages and see how the system behaves. That might gives us some clues on what's up, or at least a way to detect what goes wrong and be able to reproduce it outside a production environment.

If you want to go into more detail, I'd consider these the key packages to get an idea of what goes on:

* org.infinispan.container

* org.infinispan.interceptors.impl

* org.hibernate.cache.infinispan.access

In theory, CacheEntryInvalidatedEvent would be fired in the node where the data is removed as a result of an invalidation. However, since Hibernate 5.x we tweak internal Infinispan interceptors heavily to get best performance out of Hibernate Infinispan combo, so can't guarantee that listener will work as expected, but it should do.

Best here would be to get some logs when things go wrong and have a look.

In the mean, I'd suggest you:

1. Attach your Hibernate/JPA config and Infinispan config

2. Share the entity/collection classes that are having issues.

3. Does the issue affect entities only? Or collections only? Or both?

4. Are you using query caching? Is this affected by issue?

Cheers

[stephanf]

Hello Galder,

thank you for your reply. We've implemented some additional logging according to your advice and, for now, are waiting for something to happen.

Everything seems quiet so far, but should our issues resurface, I'll come back with additional information or a resolution.

Cheers