backup restore fails java.lang.OutOfMemoryError: Java heap space

**SageMajor** · 10-19-2016, 08:59 PM

I am doing a migration and moving from 8.0.6 Network edition to 8.7 FOSS.

I created a backup using the migration tool and keep getting out of memory errors when restoring even single accounts.
The new server has 64gb ram, the old one only had 16.

The log ends with this

Code:

2016-10-19 11:50:46,926 DEBUG Restoring item 2767
2016-10-19 11:50:49,294 INFO Adding item 2767 => 2861
2016-10-19 11:50:49,299 DEBUG Restoring item 2768
2016-10-19 11:50:51,065 INFO Adding item 2768 => 2862
2016-10-19 11:50:51,073 DEBUG Restoring item 2769
2016-10-19 11:50:52,253 INFO Adding item 2769 => 2863
2016-10-19 11:50:52,262 DEBUG Restoring item 2770
2016-10-19 11:50:54,035 INFO Adding item 2770 => 2864
2016-10-19 11:50:54,037 DEBUG Restoring item 2772
2016-10-19 11:50:57,461 ERR Exception: java.lang.OutOfMemoryError: Java heap space

and the email I get says this

Code:

This is an automated notification from ZxBackup about External Restore.

Operation External Restore failed.

Operation Id: fb8a7e01-94e3-4907-a4c1-a62f00796306
Operation Host: mail3.xxx.com

Operation requested by: admin@mail3.xxx.com

ZeXtras Suite Version: 2.4.0
commit: c78b623c8cd9ae664a8017ebddf20ce3c9c62abb

Zal Version: 1.11.0
Zal commit: c78b623c8cd9ae664a8017ebddf20ce3c9c62abb
Zimbra version: 8.7.0_GA_1659 20160628202701 20160628-2034 FOSS

- exception -
com.zextras.lib.Error.OperationBlockingError: Blocking operation error
        at com.zextras.op.backup.ZEExternalRestoreOperation.restoreItemsFromExternal (ZEExternalRestoreOperation.java:1110)
        at com.zextras.op.backup.ZEExternalRestoreOperation.doOperation (ZEExternalRestoreOperation.java:837)
        at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
        at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
        at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
        at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
        at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)
Caused by: java.lang.OutOfMemoryError: Java heap space

Last progress info:
 -- 
 Operation log path:                           /opt/zimbra/log/op_ExternalRestore_fb8a7e01-94e3-4907-a4c1-a62f00796306.log
 Warnings/Errors:                              1/0
 Restored Accounts(only attributes):           1/1
 Restored Accounts(common items):              0/1
 Restored Accounts(only shared & datasources): 0/1
 Current Account:                              sage@xxx.com
 Restored/Skipped Items:                       1000/984
 Unrestored Items:                             0

**SageMajor** · 10-19-2016, 11:19 PM

I keep getting errors even when doing single restores of a mailbox. In one mailbox the largest attachment is 23mb.
Here is the email I get when it fails

The server has 64gb ram.

This is an automated notification from ZxBackup about External Restore.

Operation External Restore failed.

Operation Id: fb8a7e01-94e3-4907-a4c1-a62f00796306
Operation Host: mail3.xxx.com

Operation requested by: admin@mail3.xxx.com

ZeXtras Suite Version: 2.4.0
commit: c78b623c8cd9ae664a8017ebddf20ce3c9c62abb

Zal Version: 1.11.0
Zal commit: c78b623c8cd9ae664a8017ebddf20ce3c9c62abb
Zimbra version: 8.7.0_GA_1659 20160628202701 20160628-2034 FOSS

- exception -
com.zextras.lib.Error.OperationBlockingError: Blocking operation error
at com.zextras.op.backup.ZEExternalRestoreOperation.r estoreItemsFromExternal (ZEExternalRestoreOperation.java:1110)
at com.zextras.op.backup.ZEExternalRestoreOperation.d oOperation (ZEExternalRestoreOperation.java:837)
at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)
Caused by: java.lang.OutOfMemoryError: Java heap space

Last progress info:
--
Operation log path: /opt/zimbra/log/op_ExternalRestore_fb8a7e01-94e3-4907-a4c1-a62f00796306.log
Warnings/Errors: 1/0
Restored Accounts(only attributes): 1/1
Restored Accounts(common items): 0/1
Restored Accounts(only shared & datasources): 0/1
Current Account: sage@xxx.com
Restored/Skipped Items: 1000/984
Unrestored Items: 0

and the end of the log file
2016-10-19 11:50:46,926 DEBUG Restoring item 2767
2016-10-19 11:50:49,294 INFO Adding item 2767 => 2861
2016-10-19 11:50:49,299 DEBUG Restoring item 2768
2016-10-19 11:50:51,065 INFO Adding item 2768 => 2862
2016-10-19 11:50:51,073 DEBUG Restoring item 2769
2016-10-19 11:50:52,253 INFO Adding item 2769 => 2863
2016-10-19 11:50:52,262 DEBUG Restoring item 2770
2016-10-19 11:50:54,035 INFO Adding item 2770 => 2864
2016-10-19 11:50:54,037 DEBUG Restoring item 2772
2016-10-19 11:50:57,461 ERR Exception: java.lang.OutOfMemoryError: Java heap space

and the email from another failure
- exception -
com.zextras.lib.Error.OperationBlockingError: Blocking operation error
at com.zextras.op.backup.ZEExternalRestoreOperation.r estoreItemsFromExternal (ZEExternalRestoreOperation.java:1110)
at com.zextras.op.backup.ZEExternalRestoreOperation.d oOperation (ZEExternalRestoreOperation.java:837)
at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)
Caused by: java.lang.OutOfMemoryError: Java heap space
at com.zimbra.cs.store.BlobBuilder.append (BlobBuilder.java:133)
at com.zimbra.cs.store.file.FileBlobStore.storeIncomi ng (FileBlobStore.java:103)
at org.openzal.zal.FileBlobStoreWrapImpl.storeIncomin g (FileBlobStoreWrapImpl.java:81)
at org.openzal.zal.FileBlobPrimaryStore.storeIncoming (FileBlobPrimaryStore.java:251)
at org.openzal.zal.extension.InternalOverrideStoreMan ager.storeIncoming (InternalOverrideStoreManager.java:103)
at com.zimbra.cs.store.StoreManager.storeIncoming (StoreManager.java:145)
at com.zimbra.cs.mailbox.Mailbox.addMessage (Mailbox.java:5802)
at com.zimbra.cs.mailbox.Mailbox.addMessage (Mailbox.java:5828)
at org.openzal.zal.Mailbox.addMessage (Mailbox.java:1696)
at com.zextras.backup.ZEBItem.createZimbraItem (ZEBItem.java:1676)
at com.zextras.backup.ZEBItem.restore (ZEBItem.java:728)
at com.zextras.op.backup.ZEExternalRestoreOperation.r estoreItemsFromExternal (ZEExternalRestoreOperation.java:1028)
at com.zextras.op.backup.ZEExternalRestoreOperation.d oOperation (ZEExternalRestoreOperation.java:837)
at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)

**d0s0n** · 10-22-2016, 09:59 AM

Hi SageMajor,

this problem could be related to a problem already solved on the next zextras release (2.4.1) that should be released within few days. Probably the item 2772 of last restored account could be a particular calendar event with a large attachment, could you check that itemId on the source server?

D0s0n

**SageMajor** · 10-24-2016, 05:32 PM

Originally Posted by d0s0n

Hi SageMajor,

this problem could be related to a problem already solved on the next zextras release (2.4.1) that should be released within few days. Probably the item 2772 of last restored account could be a particular calendar event with a large attachment, could you check that itemId on the source server?

D0s0n

It looks like a normal email message from solarwinds marketing team. It is a total of 480 lines long when I do
Subject of "Find Bandwidth Hogs now and it looks like a size of 29kb

https://servername/service/home/sage/?id=2772

**d0s0n** · 10-25-2016, 09:37 AM

Hi SageMajor,

are you sure about the item and the specific user `sage`? (please check the operation log file under /opt/zimbra/log/op_ExternalRestore-*.log)

Could you send us the item? (as attachment in a mail to community@zextras.com)

D0s0n

**SageMajor** · 10-28-2016, 06:17 PM

I have tried another restore with 2.4.2 This time I tried a full restore and it did some users but again failed with out of memory

Code:

2016-10-28 08:30:36,598 INFO Restoring common items of account jorge.chavez@domain
2016-10-28 08:37:56,161 INFO Adding item 9227 => 9920
2016-10-28 08:37:56,683 DEBUG Restoring item 9230
2016-10-28 08:38:11,585 INFO Adding item 9230 => 9921
2016-10-28 08:38:15,646 DEBUG Restoring item 9231
2016-10-28 08:39:00,138 ERR Exception: java.lang.OutOfMemoryError: Java heap space

Code:

and the email I got 
ZeXtras Suite Version: 2.4.2
commit: ae9376b25732296284dee82550a71d948520ee08

Zal Version: 1.11.2
Zal commit: ae9376b25732296284dee82550a71d948520ee08
Zimbra version: 8.7.0_GA_1659 20160628202701 20160628-2034 FOSS

- exception -
com.zextras.lib.Error.OperationBlockingError: Blocking operation error
        at com.zextras.op.backup.ZEExternalRestoreOperation.restoreItemsFromExternal (ZEExternalRestoreOperation.java:1110)
        at com.zextras.op.backup.ZEExternalRestoreOperation.doOperation (ZEExternalRestoreOperation.java:837)
        at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
        at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
        at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
        at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
        at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)
Caused by: java.lang.OutOfMemoryError: Java heap space

Looking at the mail message 9231 via command line

Code:

/opt/zimbra/bin/zmprov
 selectMailbox jorge.chavez@domain
mbox jorge.chavez@domain> gm 9231
Id: 9231
Conversation-Id: -9231
Folder: /Cancelled accounts
Subject: CANCEL CKT       Foot Detox      99002039
From: Mario Flores (Service) <mario.flores@domain.com>
To: Jorge Chavez (Service) <jorge.chavez@domain.com>,
 Cindy Saravia <csaravia@domain.com>
Cc: Robert Rivas <robert@dmrcom.com>
Date: Wed, 01 Jun 2016 14:01:52 -0700 (PDT)
Size: 2.76 KB

Please cancel ckts



DXI50/26-NL/0059/ANHMCA01/ANHMCA01W0J
73.LXFP.528010.245.PT








DXI50/26-NL/0060/ANHMCA01/ANHMCA01W0J
73.LXFP.528010.246.PT

So again it failed on a small message.

**SageMajor** · 10-28-2016, 06:41 PM

doing a restore of only jorge.chavez I get an error

Code:

2016-10-28 09:20:20,527 WARN Unable to restore zimbraACE settings for ZimbraID: 6cd8abe8-f2f2-4f94-9408-63067f868d7b id not found.
2016-10-28 09:20:20,527 WARN Unable to restore zimbraACE settings for ZimbraID: 46b400a1-da5a-4942-a571-b53095001645 id not found.
2016-10-28 09:20:20,527 INFO Every account has been created
2016-10-28 09:20:20,527 INFO From now on you can receive emails and use accounts, expect slowdowns(items will be added while the user is using his account)
2016-10-28 09:20:20,534 INFO Starting items restoring
2016-10-28 09:20:20,534 INFO Restoring common items of account jorge.chavez@dmrcom.com
2016-10-28 09:20:21,553 ERR Exception: com.zextras.lib.Error.UnableToReadMapError: Unable to read Map: /opt/zimbra/backup/zextras/accounts/3af86dc1-b302-44ee-b1cf-703e2df44357/id_mapper
        at com.zextras.backup.ZEBackupMap.<init> (ZEBackupMap.java:55)
        at com.zextras.backup.ZEBAccount.getMap (ZEBAccount.java:96)
        at com.zextras.op.backup.ZEExternalRestoreOperation.restoreItemsFromExternal (ZEExternalRestoreOperation.java:989)
        at com.zextras.op.backup.ZEExternalRestoreOperation.doOperation (ZEExternalRestoreOperation.java:837)
        at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
        at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
        at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
        at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
        at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)
Caused by: java.io.EOFException
        at java.io.ObjectInputStream$BlockDataInputStream.readFully (ObjectInputStream.java:2772)
        at java.io.ObjectInputStream.defaultReadFields (ObjectInputStream.java:2007)
        at java.io.ObjectInputStream.readSerialData (ObjectInputStream.java:1942)
        at java.io.ObjectInputStream.readOrdinaryObject (ObjectInputStream.java:1808)
        at java.io.ObjectInputStream.readObject0 (ObjectInputStream.java:1353)
        at java.io.ObjectInputStream.readObject (ObjectInputStream.java:373)
        at java.util.HashMap.readObject (HashMap.java:1404)
        at sun.reflect.NativeMethodAccessorImpl.invoke0 (NativeMethodAccessorImpl.java:-2) [native]
        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.invokeReadObject (ObjectStreamClass.java:1058)
        at java.io.ObjectInputStream.readSerialData (ObjectInputStream.java:1909)
        at java.io.ObjectInputStream.readOrdinaryObject (ObjectInputStream.java:1808)
        at java.io.ObjectInputStream.readObject0 (ObjectInputStream.java:1353)
        at java.io.ObjectInputStream.readObject (ObjectInputStream.java:373)
        at com.zextras.backup.ZEBackupMap.<init> (ZEBackupMap.java:51)
        at com.zextras.backup.ZEBAccount.getMap (ZEBAccount.java:96)
        at com.zextras.op.backup.ZEExternalRestoreOperation.restoreItemsFromExternal (ZEExternalRestoreOperation.java:989)
        at com.zextras.op.backup.ZEExternalRestoreOperation.doOperation (ZEExternalRestoreOperation.java:837)
        at com.zextras.op.ZEOperation.exec (ZEOperation.java:757)
        at com.zextras.op.LegacyOperationProxy.exec (LegacyOperationProxy.java:83)
        at com.zextras.op.StatefulOperationImpl.exec (StatefulOperationImpl.java:115)
        at com.zextras.op.OperationStarterActivity.run (OperationStarterActivity.java:45)
        at com.zextras.lib.activities.ActivityThread.run (ActivityThread.java:122)

I then deleted the id_mapper file listed in the log

and got the out of memory error again

Code:

2016-10-28 09:35:22,302 DEBUG Restoring item 17560
2016-10-28 09:35:26,234 INFO Adding item 17560 => 11484
2016-10-28 09:35:26,828 DEBUG Restoring item 1177
2016-10-28 09:35:44,161 ERR Exception: java.lang.OutOfMemoryError: Java heap space

however the message again is small

Code:

zimbra@mail:/home/sage$  /opt/zimbra/bin/zmprov
prov> selectMailbox jorge.chavez@domain.com
mailbox: jorge.chavez@domain.com, size: 4.25 GB, messages: 11981, unread: 8
authenticated as jorge.chavez@domain.com
mbox jorge.chavez@domain.com> gm 1177
Id: 1177
Conversation-Id: -1177
Folder: /Sent
Subject: TEST
From: Jorge Chavez (Service) <jorge.chavez@domain.com>
To: <7142829745@faxgw.domain.com>
Date: Tue, 02 Feb 2016 16:18:37 -0800 (PST)
Flags: sentByMe
Size: 543 B

TEST

TEST

TEST

TEST

**d0s0n** · 10-31-2016, 10:54 AM

Hi SageMajor,

with these behaviors, my initial suspetcs were wrong, you have definitely a memory configuration problem that commonly happens when you change the ram amount after the zimbra installation without changing the heap space settings.

Raising the Heap Size to a proper value as described on the official Zimbra documentation should promptly solve the issue (you'll need to restart the mailboxd service in order for the new settings to kick in)...

Have a nice day,
D0s0n

**imanudin11** · 12-02-2016, 04:23 AM

Originally Posted by d0s0n

Hi SageMajor,

with these behaviors, my initial suspetcs were wrong, you have definitely a memory configuration problem that commonly happens when you change the ram amount after the zimbra installation without changing the heap space settings.

Raising the Heap Size to a proper value as described on the official Zimbra documentation should promptly solve the issue (you'll need to restart the mailboxd service in order for the new settings to kick in)...

Have a nice day,
D0s0n

Hi D0s0n and Members,

I have same problem when restore backup from ZCS 7.2.x to ZCS 8.7.1 running CentOS 7. Every 4 minutes, i am getting error like below

Code:

ZeXtras Suite has detected an abnormal interruption of a ZxBackup operation, usually caused by a mailboxd service restart.
Please make sure to find and fix the cause of said service restart before restarting the operation. 

For additional information see http://wiki.zextras.com/wiki/Running_Operation_Awareness .


-- Operation Details --
Name: External Restore
Start Time: 02/12/2016 10:05:38
Operation Id: fe660ef5-262c-4cb1-82ac-c542f6484b0a
Requested By: zimbra

-- Parameters --
skipSystemAccount = true
onlyProvisioning = false
notificationeMails = com.zextras.lib.ContainerListString@e28e7f0e
skipDistList = false
skipAliases = false
skipCos = false
origin = ZxLink
filterDeleteAccount = true
humanDate = last available
obeyHSM = false
dataPath = /srv/ai/zextras/

I've configure mailboxd_java_heap as mention on Zimbra link

Code:

[zimbra@mail ~]$ zmlocalconfig mailboxd_java_options mailboxd_java_heap_size mailboxd_java_heap_memory_percent
mailboxd_java_options = -server -Dhttps.protocols=TLSv1,TLSv1.1,TLSv1.2 -Djdk.tls.client.protocols=TLSv1,TLSv1.1,TLSv1.2 -Djava.awt.headless=true -Dsun.net.inetaddr.ttl=${networkaddress_cache_ttl} -Dorg.apache.jasper.compiler.disablejsr199=true -XX:+UseConcMarkSweepGC -XX:SoftRefLRUPolicyMSPerMB=1 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -XX:-OmitStackTraceInFastThrow -Xloggc:/opt/zimbra/log/gc.log -XX:-UseGCLogFileRotation -XX:NumberOfGCLogFiles=20 -XX:GCLogFileSize=4096K -Djava.net.preferIPv4Stack=true
mailboxd_java_heap_size = 2992
mailboxd_java_heap_memory_percent = 25

My system

Code:

[root@mail srv]# cat /etc/os-release 
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="7"

RAM : 12 GB
HDD : 1 TB

What's wrong with my system? or any tweak or other to import zextras backup to the new server (ZCS 8.7.1)

Thanks
AI

**Cine** · 12-15-2016, 09:47 AM

Hello Imanudin!

It appears that your mailboxd service is crashing multiple times, do you see any error in the mailbox.log or in the zmmailboxd.out before the service crashes?

Have a nice day,
Cine
the Zextras Team

Thread: backup restore fails java.lang.OutOfMemoryError: Java heap space

LinkBack

Thread Tools

Search Thread

Display

backup restore fails java.lang.OutOfMemoryError: Java heap space

backup restore fails java.lang.OutOfMemoryError: Java heap space

Bookmarks

Bookmarks

Posting Permissions