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:
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[/bug]). The on disk sizes are way from reaching this limit though:
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.
I don't really know if these messages are really an error, I haven't seen any issues yet which I relate to them. I still see them regularly (see below from one of our mailbox servers) and customers see them as well.
Feb 12 17:04:44 zimbra.domain.com mailbox.log: 2018-02-12 17:04:44,628 WARN [ImapSSLServer-13] [name=email@domain.com;mid=60;ip=1.1.1.1;oip=1.1.1.1;via=1.1.1.1(nginx/1.7.1);ua=Zimbra/8.8.6_GA_1906;] CompoundCachingTier - Error overflowing 'ee1336f8-d3b1-4cc3-ad3c-a7912d856511:20813:78625:19506' into lower caching tier org.ehcache.impl.internal.store.offheap.OffHeapStore@35e8316e
Feb 12 17:04:44 zimbra.domain.com mailbox.log: Caused by: org.terracotta.offheapstore.exceptions.OversizeMappingException: Storage Engine and Eviction Failed - Empty Map
Feb 12 17:04:44 zimbra.domain.com mailbox.log: Allocator: org.terracotta.offheapstore.storage.allocator.IntegerBestFitAllocator@4fbe56aa
Feb 12 17:04:44 zimbra.domain.com mailbox.log: at org.terracotta.offheapstore.AbstractOffHeapClockCache.storageEngineFailure(AbstractOffHeapClockCache.java:84)
Feb 12 17:04:44 zimbra.domain.com mailbox.log: at org.terracotta.offheapstore.OffHeapHashMap.writeEntry(OffHeapHashMap.java:689)
Feb 12 17:04:44 zimbra.domain.com mailbox.log: at org.terracotta.offheapstore.OffHeapHashMap.computeWithMetadata(OffHeapHashMap.java:1947)
Feb 12 17:04:44 zimbra.domain.com mailbox.log: at org.terracotta.offheapstore.AbstractLockedOffHeapHashMap.computeWithMetadata(AbstractLockedOffHeapHashMap.java:582)
Feb 12 17:04:44 zimbra.domain.com mailbox.log: at org.terracotta.offheapstore.concurrent.AbstractConcurrentOffHeapMap.computeWithMetadata(AbstractConcurrentOffHeapMap.java:743)
I have the same problem/error in my 8.8.5 version and as well the java cpu 100% or even more,... any ideas? I have centos 7 64bit and OSE Zimbra, 24GB ram 4 core and 2 thread.
after I upgrade to 8.8.8 all is fine since a long time but in a couple of days now is again a java CPU 100% is that normal if I have an 8 core CPU server?
2018-08-02 14:20:09,888 WARN [ImapSSLServer-1] [name=removed_user@removed_domain.com;mid=121;ip=10.7.57.17;oip=removed;via=removed(nginx/1.7.1);ua=Zimbra/8.8.8_GA_3008;cid=1624;] CompoundCachingTier - Error overflowing '8ec5c54f-eb59-4b22-adb6-2f2707617874:5:70072:1' into lower caching tier org.ehcache.impl.internal.store.offheap.OffHeapStore@4d0b8b8b
org.ehcache.core.spi.store.StoreAccessException: The element with key '8ec5c54f-eb59-4b22-adb6-2f2707617874:5:70072: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:138)
at com.zimbra.cs.imap.EhcacheImapCache.get(EhcacheImapCache.java:40)
at com.zimbra.cs.imap.ImapSessionManager.deserialize(ImapSessionManager.java:799)
at com.zimbra.cs.imap.ImapListener.reload(ImapListener.java:713)
at com.zimbra.cs.imap.ImapListener.getImapFolder(ImapListener.java:399)
at com.zimbra.cs.imap.ImapSessionManager.duplicateExistingSession(ImapSessionManager.java:482)
at com.zimbra.cs.imap.ImapSessionManager.duplicateExistingSession(ImapSessionManager.java:471)
at com.zimbra.cs.imap.ImapSessionManager.openFolder(ImapSessionManager.java:315)
at com.zimbra.cs.imap.ImapHandler.setSelectedFolder(ImapHandler.java:1196)
at com.zimbra.cs.imap.ImapHandler.selectFolder(ImapHandler.java:1784)
at com.zimbra.cs.imap.ImapHandler.doSELECT(ImapHandler.java:1750)
at com.zimbra.cs.imap.ImapHandler.executeRequest(ImapHandler.java:837)
at com.zimbra.cs.imap.NioImapHandler.processRequest(NioImapHandler.java:123)
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@709a4140
Page Source: UpfrontAllocatingPageSource
Chunk 1
Size : 1MB
Free Allocator : PowerOfTwoAllocator: Occupied 1022.3KB [Largest Available Area 1KB]
Victim Allocator : PowerOfTwoAllocator: Occupied 368B [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)
... 51 more
___________________________________ L. Mark Stone Mission Critical Email - Zimbra VAR/BSP/Training Partner https://www.missioncriticalemail.com/ AWS Certified Solutions Architect-Associate
zmprov ms `zmhostname` zimbraImapInactiveSessionEhcacheSize 104857600
on all my mailbox servers, and then restart the mailbox service.
The variable is originally set (at least on my system) to 1MB; the above command increases it to 100MB. Zimbra Support also advised that the warnings are essentially benign in that something the system tried to cache wasn't able to be cached.
I'll restart mailboxd during the next maintenance window and report back to confirm that the errors like the ones below have reduced in frequency.