1
votes

I am working with Hazelcast using hibernate 2nd level cache (configured with spring), while the first server send an eviction message to the 2nd server. the eviction time stamp on the 2nd server include the actual eviction time + 1 hour .

This cause the 2nd server to lost his cache and run queries to the DB as for the next hour or until the local cache (from the 2nd server) was evicted.

While looking at version 3.6.2 implementation the 1 hour interval is cause due to getTimeout function under the com.hazelcast.hibernate.HazelcastTimestamper

public static int getTimeout(HazelcastInstance instance, String regionName) {
        try {
            final MapConfig cfg = instance.getConfig().findMapConfig(regionName);
            if (cfg.getTimeToLiveSeconds() > 0) {
                // TTL in ms
                return cfg.getTimeToLiveSeconds() * SEC_TO_MS;
            }
        } catch (UnsupportedOperationException e) {
            // HazelcastInstance is instance of HazelcastClient.
            Logger.getLogger(HazelcastTimestamper.class).finest(e);
        }
        return CacheEnvironment.getDefaultCacheTimeoutInMillis();
    }

The getDefaultCacheTimeoutInMillis return 360

While the mapConfig.getTimeToLiveSeconds() == 0

The AbstractHazelcastRegion get the timeout

this.timeout = HazelcastTimestamper.getTimeout(instance, regionName);

at the org.hibernate.cache.spi.UpdateTimestampsCache

public void preInvalidate(Serializable[] spaces, SessionImplementor session) throws CacheException {
    final boolean stats = factory != null && factory.getStatistics().isStatisticsEnabled();

    **final Long ts = region.nextTimestamp() + region.getTimeout();**

    for ( Serializable space : spaces ) {
        if ( DEBUG_ENABLED ) {
            LOG.debugf( "Pre-invalidating space [%s], timestamp: %s", space, ts );
        }

        try {
            session.getEventListenerManager().cachePutStart();

            //put() has nowait semantics, is this really appropriate?
            //note that it needs to be async replication, never local or sync
            region.put( space, ts );
        }
        finally {
            session.getEventListenerManager().cachePutEnd();
        }

        if ( stats ) {
            factory.getStatisticsImplementor().updateTimestampsCachePut();
        }
    }
}

During eviction message the eviction timeout = 360*1000 is actually added to the eviction message timestamp resulting with a problematic cache timestamp

Am i missing something or the actual logic is very problematic ? did anyone actually have a working configuration for distributed servers using hibernate 2nd level that is actually working as expected ?

1

1 Answers

1
votes

Hibernate will call preInvalidate at the beginning of a transaction for updates/inserts, then once the transaction is done it will call UpdateTimestampsCache.invalidate(...). This will set the lastUpdate time back to the current time.

So while the transaction is running, any queries on affected spaces will not be up-to-date, but once the transaction is over the lastUpdate time will be set and future select queries can be cached.

You can observe this in the logs if you set logging for org.hibernate to DEBUG. The logs will look like this:

DEBUG [UpdateTimestampsCache] Pre-invalidating space [<affected query spaces>], timestamp: <approximate current time + timeout>
... your transaction here ...
DEBUG [AbstractTransactionImpl] committing
DEBUG [JdbcTransaction] committed JDBC Connection
DEBUG [JdbcTransaction] re-enabling autocommit
DEBUG [UpdateTimestampsCache] Invalidating space [<affected query spaces>], timestamp: <approximate current time>

I have observed that sometimes this second "Invalidating space" fails to happen if the transaction is not committed (possible coding error), leaving the cache in a bad state where the lastUpdate is set to (future time + cache timeout setting), causing all queries on affected spaces to be not up-to-date until that time is reached.