New warnings after upgrade: CompoundCachingTier - Error overflowing into lower caching tier - The element is too large

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
User avatar
msquadrat
Advanced member
Advanced member
Posts: 102
Joined: Mon Oct 14, 2013 10:09 am

New warnings after upgrade: CompoundCachingTier - Error overflowing into lower caching tier - The element is too large

Postby msquadrat » Mon Oct 16, 2017 12:20 pm

This weekend I upgraded our installation from 8.6 to 8.711 and as always kept an eye on the mailbox.log to see if anything bad happens. Looks good so far, except for one warning which crops up regularly on one of our mailbox servers:

Code: Select all

2017-10-16 03:16:55,831 WARN  [ImapServer-2] [name=user1@example.org;ip=...;oip=...;via...;ua=Zimbra/8.7.11_GA_1854;] CompoundCachingTier - Error overflowing '0decc7d9-7df0-4ddb-90b4-7403b1d20c6d:2:997668:1' into lower caching tier org.ehcache.impl.internal.store.offheap.OffHeapStore@75a6bd06
org.ehcache.core.spi.store.StoreAccessException: The element with key '0decc7d9-7df0-4ddb-90b4-7403b1d20c6d:2:997668:1' is too large to be stored in this offheap store.
   at org.ehcache.impl.internal.store.offheap.AbstractOffHeapStore.computeWithRetry(AbstractOffHeapStore.java:1090)
   at org.ehcache.impl.internal.store.offheap.AbstractOffHeapStore.installMapping(AbstractOffHeapStore.java:1067)
   at org.ehcache.impl.internal.store.tiering.CompoundCachingTier$1.onInvalidation(CompoundCachingTier.java:69)
   at org.ehcache.impl.internal.store.heap.OnHeapStore$20.onInvalidation(OnHeapStore.java:921)
   at org.ehcache.impl.internal.store.heap.OnHeapStore$26.apply(OnHeapStore.java:1575)
   at org.ehcache.impl.internal.store.heap.OnHeapStore$26.apply(OnHeapStore.java:1568)
   at org.ehcache.impl.internal.concurrent.ConcurrentHashMap.computeIfPresent(ConcurrentHashMap.java:1793)
   at org.ehcache.impl.internal.store.heap.SimpleBackend.computeIfPresent(SimpleBackend.java:124)
   at org.ehcache.impl.internal.store.heap.OnHeapStore.evict(OnHeapStore.java:1568)
   at org.ehcache.impl.internal.store.heap.OnHeapStore.enforceCapacity(OnHeapStore.java:1535)
   at org.ehcache.impl.internal.store.heap.OnHeapStore.getOrComputeIfAbsent(OnHeapStore.java:723)
   at org.ehcache.impl.internal.store.tiering.CompoundCachingTier.getOrComputeIfAbsent(CompoundCachingTier.java:112)
   at org.ehcache.impl.internal.store.tiering.TieredStore.get(TieredStore.java:110)
   at org.ehcache.core.Ehcache.get(Ehcache.java:167)
   at com.zimbra.cs.imap.EhcacheImapCache.get(EhcacheImapCache.java:134)
   at com.zimbra.cs.imap.ImapSessionManager.deserialize(ImapSessionManager.java:647)
   at com.zimbra.cs.imap.ImapSession.reload(ImapSession.java:367)
   at com.zimbra.cs.imap.ImapSession.getImapFolder(ImapSession.java:97)
   at com.zimbra.cs.imap.ImapSessionManager.duplicateExistingSession(ImapSessionManager.java:394)
   at com.zimbra.cs.imap.ImapSessionManager.openFolder(ImapSessionManager.java:289)
   at com.zimbra.cs.imap.ImapHandler.setSelectedFolder(ImapHandler.java:1028)
   at com.zimbra.cs.imap.ImapHandler.selectFolder(ImapHandler.java:1489)
   at com.zimbra.cs.imap.ImapHandler.doSELECT(ImapHandler.java:1453)
   at com.zimbra.cs.imap.ImapHandler.executeRequest(ImapHandler.java:722)
   at com.zimbra.cs.imap.NioImapHandler.processRequest(NioImapHandler.java:126)
   at com.zimbra.cs.imap.NioImapHandler.messageReceived(NioImapHandler.java:63)
   at com.zimbra.cs.server.NioHandlerDispatcher.messageReceived(NioHandlerDispatcher.java:95)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageReceived(DefaultIoFilterChain.java:716)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
   at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
   at org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.flush(ProtocolCodecFilter.java:427)
   at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:245)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
   at com.zimbra.cs.server.NioLoggingFilter.messageReceived(NioLoggingFilter.java:68)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
   at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
   at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75)
   at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63)
   at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(OrderedThreadPoolExecutor.java:780)
   at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(OrderedThreadPoolExecutor.java:772)
   at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(OrderedThreadPoolExecutor.java:714)
   at java.lang.Thread.run(Thread.java:748)
Caused by: org.terracotta.offheapstore.exceptions.OversizeMappingException: Storage Engine and Eviction Failed - Empty Map
Storage Engine : OffHeapBufferStorageEngine allocated=1022.0KB occupied=0B
Storage Area: OffHeapStorageArea
   511 2KB pages
Allocator: org.terracotta.offheapstore.storage.allocator.IntegerBestFitAllocator@1e83a621
Page Source: UpfrontAllocatingPageSource
Chunk 1
Size             : 1MB
Free Allocator   : PowerOfTwoAllocator: Occupied 1022.2KB [Largest Available Area 1KB]
Victim Allocator : PowerOfTwoAllocator: Occupied 272B [Largest Available Area 512KB]
   at org.terracotta.offheapstore.AbstractOffHeapClockCache.storageEngineFailure(AbstractOffHeapClockCache.java:84)
   at org.terracotta.offheapstore.OffHeapHashMap.writeEntry(OffHeapHashMap.java:689)
   at org.terracotta.offheapstore.OffHeapHashMap.computeWithMetadata(OffHeapHashMap.java:1947)
   at org.terracotta.offheapstore.AbstractLockedOffHeapHashMap.computeWithMetadata(AbstractLockedOffHeapHashMap.java:582)
   at org.terracotta.offheapstore.concurrent.AbstractConcurrentOffHeapMap.computeWithMetadata(AbstractConcurrentOffHeapMap.java:743)
   at org.ehcache.impl.internal.store.offheap.EhcacheConcurrentOffHeapClockCache.compute(EhcacheConcurrentOffHeapClockCache.java:152)
   at org.ehcache.impl.internal.store.offheap.AbstractOffHeapStore.computeWithRetry(AbstractOffHeapStore.java:1088)
   ... 49 more
2017-10-16 03:16:55,832 INFO  [ImapServer-2] [name=user1@example.org;ip=...;oip=...;via...;ua=Zimbra/8.7.11_GA_1854;] imap - copying message data from existing session: INBOX


All tweaking I did to the EhCache was to reduce the maximum on disk size from the default 100G to 10G to avoid running out of disk (cf. Bug 104846). The on disk sizes are way from reaching this limit though:

Code: Select all

zimbra@zm1:~$ zmprov gs $(zmhostname) zimbraImapInactiveSessionCacheMaxDiskSize zimbraImapInactiveSessionEhcacheMaxDiskSize zimbraImapActiveSessionEhcacheMaxDiskSize zimbraImapInactiveSessionEhcacheSize zimbraActiveSyncEhcacheMaxDiskSize zimbraActiveSyncEhcacheHeapSize zimbraActiveSyncEhcacheExpiration
zimbraActiveSyncEhcacheExpiration: 5m
zimbraActiveSyncEhcacheHeapSize: 10485760
zimbraActiveSyncEhcacheMaxDiskSize: 10737418240
zimbraImapActiveSessionEhcacheMaxDiskSize: 10737418240
zimbraImapInactiveSessionCacheMaxDiskSize: 10737418240
zimbraImapInactiveSessionEhcacheMaxDiskSize: 10737418240
zimbraImapInactiveSessionEhcacheSize: 1048576
zimbra@zm1:~$ ls /opt/zimbra/data/mailboxd/*cache*/offheap-disk-store/* -lh
-rw-r----- 1 zimbra zimbra 152M Oct 16 14:15 /opt/zimbra/data/mailboxd/imap-active-session-cache_85be333d34866255dbb2082ee3fb1a79544d0878/offheap-disk-store/ehcache-disk-store.data
-rw-r----- 1 zimbra zimbra  117 Oct 15 15:03 /opt/zimbra/data/mailboxd/imap-active-session-cache_85be333d34866255dbb2082ee3fb1a79544d0878/offheap-disk-store/ehcache-disk-store.meta
-rw-r----- 1 zimbra zimbra 200M Oct 16 14:17 /opt/zimbra/data/mailboxd/imap-inactive-session-cache_fc164b40eddbe2ccbc469be50b2e7494ea03619a/offheap-disk-store/ehcache-disk-store.data
-rw-r----- 1 zimbra zimbra 4.3K Oct 15 15:03 /opt/zimbra/data/mailboxd/imap-inactive-session-cache_fc164b40eddbe2ccbc469be50b2e7494ea03619a/offheap-disk-store/ehcache-disk-store.index
-rw-r----- 1 zimbra zimbra  117 Oct 14 13:44 /opt/zimbra/data/mailboxd/imap-inactive-session-cache_fc164b40eddbe2ccbc469be50b2e7494ea03619a/offheap-disk-store/ehcache-disk-store.meta
-rw-r----- 1 zimbra zimbra 124K Oct 16 14:18 /opt/zimbra/data/mailboxd/sync-state-item-cache_eca9d558d785a39bf537e61b19815681b15d280f/offheap-disk-store/ehcache-disk-store.data
-rw-r----- 1 zimbra zimbra 3.3K Oct 15 15:03 /opt/zimbra/data/mailboxd/sync-state-item-cache_eca9d558d785a39bf537e61b19815681b15d280f/offheap-disk-store/ehcache-disk-store.index
-rw-r----- 1 zimbra zimbra  104 Oct 14 13:44 /opt/zimbra/data/mailboxd/sync-state-item-cache_eca9d558d785a39bf537e61b19815681b15d280f/offheap-disk-store/ehcache-disk-store.meta


Has anybody else seen this as well?

Googling for the exception brought me to a EhCache change which apparently was fixed in 3.2.1 (ZCS 8.7.11 ships 3.1.2).


markd
Posts: 20
Joined: Sat Sep 13, 2014 12:35 am

Re: New warnings after upgrade: CompoundCachingTier - Error overflowing into lower caching tier - The element is too lar

Postby markd » Mon Oct 30, 2017 8:18 pm

I haven't seen these errors buy my disk just went full because of the size of the ehcache files.
Thanks for including the bug reference. I hope we can limit the file size growth.

Return to “Administrators”

Who is online

Users browsing this forum: liverpoolfcfan and 47 guests