Zimbra

smcgrath1111 · #1 (**permalink**) 03-26-2008, 09:36 AM

Running Release 5.0.1_GA_1902.UBUNTU6 (Network Edition)

At some point backups started reporting FAIL. I'm seeing a bunch of entries like this in the mailbox.log file:

Code:

2008-03-26 01:01:10,369 INFO  [btpool0-3248] [name=zimbra;ip=127.0.0.1;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: unable to read metadata for account e08bc6bd-d835-4262-8a56-7365c3313789 backup full-20080308.060007.994
Code:service.FAILURE
        at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:183)
        at com.zimbra.cs.service.backup.Backup.handleNetworkRequest(Backup.java:150)
        at com.zimbra.cs.service.NetworkDocumentHandler.handle(Unknown Source)
        at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:342)
        at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:208)
        at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:113)
        at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:272)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:174)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
        at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
        at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
        at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:148)
        at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
        at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
        at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:716)
        at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:406)
        at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
        at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.handler.RewriteHandler.handle(RewriteHandler.java:176)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.Server.handle(Server.java:313)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:844)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:644)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:396)
        at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)
Caused by: java.io.IOException: unable to read metadata for account e08bc6bd-d835-4262-8a56-7365c3313789 backup full-20080308.060007.994
        at com.zimbra.cs.backup.util.Utils.IOException(Utils.java:203)
        at com.zimbra.cs.backup.FileBackupTarget$RestoreAcctSession.<init>(FileBackupTarget.java:1571)
        at com.zimbra.cs.backup.FileBackupTarget.getAccountSession(FileBackupTarget.java:321)
        at com.zimbra.cs.backup.FileBackupTarget.getAccountSession(FileBackupTarget.java:303)
        at com.zimbra.cs.backup.BackupManager.backupIncremental(BackupManager.java:292)
        at com.zimbra.cs.service.backup.Backup.handleNetworkRequest(Backup.java:143)
        ... 31 more
Caused by: com.zimbra.common.service.ServiceException: system failure: Unable to parse XML file /opt/zimbra/backup/sessions/full-20080308.060007.994/a
ccounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/meta.xml
Code:service.FAILURE
        at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:183)
        at com.zimbra.cs.backup.XmlMeta.readAccountBackup(XmlMeta.java:381)
        at com.zimbra.cs.backup.FileBackupTarget$RestoreAcctSession.<init>(FileBackupTarget.java:1568)
        ... 35 more
Caused by: java.io.IOException: Input/output error
2008-03-26 01:01:10,369 INFO  [btpool0-3248] [name=zimbra;ip=127.0.0.1;] SoapEngine - handler exception
com.zimbra.common.service.ServiceException: system failure: unable to read metadata for account e08bc6bd-d835-4262-8a56-7365c3313789 backup full-20080
308.060007.994
Code:service.FAILURE
        at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:183)
        at com.zimbra.cs.service.backup.Backup.handleNetworkRequest(Backup.java:150)
        at com.zimbra.cs.service.NetworkDocumentHandler.handle(Unknown Source)
        at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:342)
        at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:208)
        at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:113)
        at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:272)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:174)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
        at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
        at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
        at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:148)
        at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
        at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
        at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:716)
        at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:406)
        at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
        at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.handler.RewriteHandler.handle(RewriteHandler.java:176)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.Server.handle(Server.java:313)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:844)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:644)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:396)
        at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)
Caused by: java.io.IOException: unable to read metadata for account e08bc6bd-d835-4262-8a56-7365c3313789 backup full-20080308.060007.994
        at com.zimbra.cs.backup.util.Utils.IOException(Utils.java:203)
        at com.zimbra.cs.backup.FileBackupTarget$RestoreAcctSession.<init>(FileBackupTarget.java:1571)
        at com.zimbra.cs.backup.FileBackupTarget.getAccountSession(FileBackupTarget.java:321)
        at com.zimbra.cs.backup.FileBackupTarget.getAccountSession(FileBackupTarget.java:303)
        at com.zimbra.cs.backup.BackupManager.backupIncremental(BackupManager.java:292)
        at com.zimbra.cs.service.backup.Backup.handleNetworkRequest(Backup.java:143)
        ... 31 more
Caused by: com.zimbra.common.service.ServiceException: system failure: Unable to parse XML file /opt/zimbra/backup/sessions/full-20080308.060007.994/a
ccounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/meta.xml
Code:service.FAILURE
        at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:183)
        at com.zimbra.cs.backup.XmlMeta.readAccountBackup(XmlMeta.java:381)
        at com.zimbra.cs.backup.FileBackupTarget$RestoreAcctSession.<init>(FileBackupTarget.java:1568)
        ... 35 more
Caused by: java.io.IOException: Input/output error
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.handler.RewriteHandler.handle(RewriteHandler.java:176)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.Server.handle(Server.java:313)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:844)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:644)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:396)
        at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)
2008-03-26 01:02:14,245 INFO  [IndexWritersSweeperThread] [] index - open index writers sweep: before=2, closed=0, after=2 (0ms)
2008-03-26 01:02:40,152 INFO  [btpool0-3197] [name=zimbra;ip=127.0.0.1;] backup - Backup request finished

I have checked the disk file system, there are no errors. Any ideas?

jhahm · #2 (**permalink**) 03-28-2008, 10:43 AM

Hi, can you check the contents of the file in question?

/opt/zimbra/backup/sessions/full-20080308.060007.994/a
ccounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/meta.xml

Does it exist and if so, does it contain valid-looking XML data? Does it have correct permission? (readable by zimbra user)

Here's what a sample file looks like:

<?xml version="1.0" encoding="utf-8"?>

<backupMetadata xmlns="urn:zimbraBackupMeta" version="7.0">
<accountBackup zimbraId="041760fd-24d9-40ef-b411-f46b3eef376a" email="user@domain.com" mailboxId="12" startTime="1206725960244" endTime="1206725960351" redoSeq="1" server="server.domain.com">
<volumes>
<volume id="2" path="/opt/zimbra/index/0/12/index">
</volume>
<volume id="1" path="/opt/zimbra/store/0/12/msg">
</volume>
</volumes>
</accountBackup>
</backupMetadata>

smcgrath1111 · #3 (**permalink**) 03-29-2008, 10:59 AM

Thanks for the response - the file is there:

total 15
drwxr-xr-x 1 zimbra zimbra 4096 Mar 7 12:04 blobs
drwxr-xr-x 1 zimbra zimbra 4096 Mar 7 12:04 db
drwxr-xr-x 1 zimbra zimbra 4096 Mar 7 12:04 index
-rwxr-xr-x 1 zimbra zimbra 1618 Mar 8 01:00 ldap.xml
-rwxr-xr-x 1 zimbra zimbra 530 Mar 8 01:00 meta.xml

And it does seem to contain valid data:

<backupMetadata xmlns="urn:zimbraBackupMeta" version="7.0">
<accountBackup zimbraId="e08bc6bd-d835-4262-8a56-7365c3313789" email="zimbra@phosphor" mailboxId="36" startTime="1204956019727" endTime="12049
56020594" redoSeq="35" server="phosphor">
<volumes>
<volume id="2" path="/opt/zimbra/index/0/36/index">
</volume>
<volume id="1" path="/opt/zimbra/store/0/36/msg">
</volume>
</volumes>
</accountBackup>
</backupMetadata>

I wonder why it's not permitted to read it...

jhahm · #4 (**permalink**) 03-29-2008, 11:39 AM

I wasn't implying there was a permission problem. I was only mentioning that as a possibility. It is definitely some type of trouble reading in the xml file, but unfortunately the stack trace doesn't mention exactly what is wrong. In fact the trace looks strange. The part at the bottom:

Caused by: com.zimbra.common.service.ServiceException: system failure: Unable to parse XML file /opt/zimbra/backup/sessions/full-20080308.060007.994/a
ccounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/meta.xml
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE (ServiceException.java:183)
at com.zimbra.cs.backup.XmlMeta.readAccountBackup(Xml Meta.java:381)
at com.zimbra.cs.backup.FileBackupTarget$RestoreAcctS ession.<init>(FileBackupTarget.java:1568)
... 35 more
Caused by: java.io.IOException: Input/output error
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:139)
at org.mortbay.jetty.handler.RewriteHandler.handle(Re writeHandler.java:176)
at org.mortbay.jetty.handler.HandlerWrapper.handle(Ha ndlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:313)
at org.mortbay.jetty.HttpConnection.handleRequest(Htt pConnection.java:506)

This looks very strange. Somehow the code that reads the meta.xml file got an exception out of HTTP handler? That doesn't make any sense. Are you sure you cut/pasted the stack trace correctly?

Unfortunately, Java IOExceptions don't report the OS errno and there's much guess work involved. One other possibility is that you are running out of file descriptors on your box. Did you see anything unusual in /var/log/messages around this time? (I'm not sure fd problems are reported there though.) Check the fd limits in /etc/security/limits.conf and also ulimit -n output of zimbra user.

Do another backup to see if the stack trace still comes out with the strange final "Caused By" section out of HTTP code. That is the most puzzling part of this problem.

smcgrath1111 · #5 (**permalink**) 03-31-2008, 09:06 AM

Yes, I'm still getting an error. This time it is for a different XML file: ldap_latest.xml and ldap.xml. It seems to throw this error for every account on the system. I am only excerpting one here, since they are all the same.

Code:

2008-03-31 01:00:14,201 INFO  [btpool0-3576] [name=zimbra;ip=127.0.0.1;] backup - Incremental backup is started for account zimbra@phosphor
2008-03-31 01:00:14,201 INFO  [btpool0-3576] [name=zimbra;ip=127.0.0.1;] backup - Saving account information from LDAP
2008-03-31 01:00:14,216 INFO  [btpool0-3576] [name=zimbra;ip=127.0.0.1;] backup - Incremental backup has ended
2008-03-31 01:00:14,219 INFO  [btpool0-3576] [name=zimbra;ip=127.0.0.1;] backup - Account zimbra@phosphor in backup set incr-20080331.050010.798: All pending file IO completed (0 out of 0)
2008-03-31 01:00:14,219 ERROR [btpool0-3576] [name=zimbra;ip=127.0.0.1;] backup - Error while backing up account zimbra@phosphor: link(/opt/zimbra/backup/tmp/incr-20080331.050010.798/accounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/ldap.xml, /opt/zimbra/backup/sessions/full-20080308.060007.994/accounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/ldap_latest.xml): Operation not
java.io.IOException: link(/opt/zimbra/backup/tmp/incr-20080331.050010.798/accounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/ldap.xml, /opt/zimbra/backup/sessions/full-20080308.060007.994/accounts/e08/bc6/e08bc6bd-d835-4262-8a56-7365c3313789/ldap_latest.xml): Operation not
        at com.zimbra.znative.IO.link0(Native Method)
        at com.zimbra.znative.IO.link(IO.java:88)
        at com.zimbra.cs.backup.util.Utils.link(Utils.java:345)
        at com.zimbra.cs.backup.FileBackupTarget$BackupAcctSession.incrementalBackup(FileBackupTarget.java:1530)
        at com.zimbra.cs.backup.BackupSet.startIncrementalBackup(BackupSet.java:666)
        at com.zimbra.cs.backup.FileBackupTarget$FileBackupSet.startIncrementalBackup(FileBackupTarget.java:837)
        at com.zimbra.cs.backup.BackupManager.backupIncremental(BackupManager.java:318)
        at com.zimbra.cs.service.backup.Backup.handleNetworkRequest(Backup.java:143)
        at com.zimbra.cs.service.NetworkDocumentHandler.handle(Unknown Source)
        at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:342)
        at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:208)
        at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:113)
        at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:272)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:174)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
        at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1093)
        at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
        at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:148)
        at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1084)
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
        at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
        at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:716)
        at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:406)
        at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
        at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.handler.RewriteHandler.handle(RewriteHandler.java:176)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
        at org.mortbay.jetty.Server.handle(Server.java:313)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:506)
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:844)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:644)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:381)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:396)
        at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:442)

jhahm · #6 (**permalink**) 03-31-2008, 10:52 AM

It looks like the error message was cut off due to buffer length. I wonder what the "Operation not" really was in the link error. I'm guessing it was EPERM (errno=1), "Operation not permitted". Are you using SELinux by any chance? If so, disable it.

Also, what about file descriptor count? Monitor /proc/sys/fs/file-nr output during backup to see if you are running out.

smcgrath1111 · #7 (**permalink**) 03-31-2008, 12:30 PM

Quote:

Originally Posted by jhahm

It looks like the error message was cut off due to buffer length. I wonder what the "Operation not" really was in the link error. I'm guessing it was EPERM (errno=1), "Operation not permitted". Are you using SELinux by any chance? If so, disable it.

Nope, definitely not

Quote:

Also, what about file descriptor count? Monitor /proc/sys/fs/file-nr output during backup to see if you are running out.

Contents before backup execution:
4512 0 406115

...I tried watching the contents of the file, after the backup started, but the backup apparently fails instantly, and I wasn't able to observe any change.

I noticed you had also asked about the output of ulimit -n
zimbra@phosphor:/proc/sys/fs$ ulimit -n
1024

And by the way, thanks a lot for trying to help me out.
-Scott

mmorse · #8 (**permalink**) 03-31-2008, 12:37 PM

Quote:

Originally Posted by smcgrath1111

Running Release 5.0.1_GA_1902.UBUNTU6 (Network Edition)

Could you apply the fix(s) as in Bug 24897 - update /etc/pam.d/su on ubuntu so ulimits get set properly then note this post: [SOLVED] Too many open files error after increasing zimbra_session_limit_imap

smcgrath1111 · #9 (**permalink**) 03-31-2008, 01:18 PM

I applied the fix, and ran the ulimit command again as user Zimbra. This time I got:

zimbra@phosphor:/etc/pam.d$ ulimit -n
10000

I'm going to try the backup again
-Scott

smcgrath1111 · #10 (**permalink**) 03-31-2008, 01:28 PM

Well, I tried do a full backup of just one account... good news and bad news. The backup definitely got further this time, but there is a new error having to do with blob.dat

Code:

2008-03-31 16:15:40,774 INFO  [btpool0-3812] [name=admin@leddynamics.com;ip=192.168.2.52;ua=ZimbraWebClient - FF2.0 (Win);] backup - Backup request started
2008-03-31 16:15:40,974 INFO  [btpool0-3812] [name=admin@leddynamics.com;ip=192.168.2.52;ua=ZimbraWebClient - FF2.0 (Win);] backup - Backup r
equest finished
2008-03-31 16:15:40,975 INFO  [FullBackupThread] [] io - AsyncFileCopier is starting
2008-03-31 16:15:40,977 INFO  [FullBackupThread] [] backup - Full backup started for backup set; label: full-20080331.201540.793
2008-03-31 16:15:42,253 INFO  [FullBackupThread] [] backup - redo log file sequence is 55 at full backup for smcgrath@leddynamics.com
2008-03-31 16:15:42,374 INFO  [FullBackupThread] [] backup - Full backup started for account smcgrath@leddynamics.com (61669eee-0709-4f1b-9c7c-3457afa69a31) mailbox 3
2008-03-31 16:15:42,479 INFO  [FullBackupThread] [] mailbox - Locking mailbox 3 for maintenance.
2008-03-31 16:15:42,523 INFO  [BackupSetWorkerThread-INDEX] [] backup - Stored 11 index files
2008-03-31 16:15:42,541 INFO  [BackupSetWorkerThread-MSGS] [] backup - Number of blobs to backup for mailbox 3: 2941
2008-03-31 16:15:43,257 ERROR [AsyncFileCopierWorker-6] [] backup - Error reported by FileCopier: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/shared_blobs/a/AOg2
,JQcjqrXyWUGpBHzVwKbiBU=/blob.dat, /opt/zimbra/backup/tmp/full-20080331.201540.793/shared_blobs/a/AOg2,JQcjqrXyWUGpBHzVwKbiBU=/blob.dat): Operation not permitted
java.io.IOException: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/shared_blobs/a/AOg2,JQcjqrXyWUGpBHzVwKbiBU=/blob.dat, /opt/zimbra/backup/tmp/full-20080331.20154
0.793/shared_blobs/a/AOg2,JQcjqrXyWUGpBHzVwKbiBU=/blob.dat): Operation not permitted
        at com.zimbra.znative.IO.link0(Native Method)
        at com.zimbra.znative.IO.link(IO.java:88)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.link(AsyncFileCopier.java:159)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.run(AsyncFileCopier.java:122)
2008-03-31 16:15:43,291 ERROR [AsyncFileCopierWorker-4] [] backup - Error reported by FileCopier: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/accounts/616/69e/61
669eee-0709-4f1b-9c7c-3457afa69a31/blobs/1/0/AOg2,JQcjqrXyWUGpBHzVwKbiBU=515-713.msg3, /opt/zimbra/backup/tmp/full-20080331.201540.793/accounts/616/69e/61669eee-0709-4f1b-9c7c
-34
java.io.IOException: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/accounts/616/69e/61669eee-0709-4f1b-9c7c-3457afa69a31/blobs/1/0/AOg2,JQcjqrXyWUGpBHzVwKbiBU=515-
713.msg3, /opt/zimbra/backup/tmp/full-20080331.201540.793/accounts/616/69e/61669eee-0709-4f1b-9c7c-34
        at com.zimbra.znative.IO.link0(Native Method)
        at com.zimbra.znative.IO.link(IO.java:88)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.link(AsyncFileCopier.java:159)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.run(AsyncFileCopier.java:122)
2008-03-31 16:15:43,294 ERROR [AsyncFileCopierWorker-7] [] backup - Error reported by FileCopier: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/accounts/616/69e/61
669eee-0709-4f1b-9c7c-3457afa69a31/blobs/1/0/DP3VQRs49tdoFEMfSSotNyDEZ58=2088-3048.msg1, /opt/zimbra/backup/tmp/full-20080331.201540.793/accounts/616/69e/61669eee-0709-4f1b-9c
7c-
java.io.IOException: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/accounts/616/69e/61669eee-0709-4f1b-9c7c-3457afa69a31/blobs/1/0/DP3VQRs49tdoFEMfSSotNyDEZ58=2088
-3048.msg1, /opt/zimbra/backup/tmp/full-20080331.201540.793/accounts/616/69e/61669eee-0709-4f1b-9c7c-
        at com.zimbra.znative.IO.link0(Native Method)
        at com.zimbra.znative.IO.link(IO.java:88)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.link(AsyncFileCopier.java:159)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.run(AsyncFileCopier.java:122)
2008-03-31 16:15:44,330 INFO  [FullBackupThread] [] mailbox - Ending maintenance and marking mailbox 3 as unavailable.
2008-03-31 16:15:44,331 INFO  [FullBackupThread] [] backup - Full backup finished for account smcgrath@leddynamics.com (61669eee-0709-4f1b-9c7c-3457afa69a31) mailbox 3
2008-03-31 16:15:44,331 WARN  [FullBackupThread] [] backup - Error occurred during full backup for account smcgrath@leddynamics.com; aborted backup and deleting /opt/zimbra/ba
ckup/tmp/full-20080331.201540.793/accounts/616/69e/61669eee-0709-4f1b-9c7c-3457afa69a31
java.io.IOException: link(/opt/zimbra/backup/sessions/full-20080329.050009.342/shared_blobs/a/AOg2,JQcjqrXyWUGpBHzVwKbiBU=/blob.dat, /opt/zimbra/backup/tmp/full-20080331.20154
0.793/shared_blobs/a/AOg2,JQcjqrXyWUGpBHzVwKbiBU=/blob.dat): Operation not permitted
        at com.zimbra.znative.IO.link0(Native Method)
 at com.zimbra.znative.IO.link0(Native Method)
        at com.zimbra.znative.IO.link(IO.java:88)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.link(AsyncFileCopier.java:159)
        at com.zimbra.common.io.AsyncFileCopier$WorkerThread.run(AsyncFileCopier.java:122)
2008-03-31 16:15:46,027 INFO  [FullBackupThread] [] backup - Account smcgrath@leddynamics.com in backup set full-20080331.201540.793: All pending file IO completed (14 out of 
14)
2008-03-31 16:15:46,028 INFO  [FullBackupThread] [] backup - Finished backing up 1 of 1 accounts
2008-03-31 16:15:49,168 INFO  [FullBackupThread] [] backup - Backup set full-20080331.201540.793: All pending file IO completed (0 out of 0)
2008-03-31 16:15:49,175 INFO  [FullBackupThread] [] io - AsyncFileCopier is shut down
2008-03-31 16:15:49,175 INFO  [FullBackupThread] [] backup - Full backup finished for backup set; label: full-20080331.201540.793
2008-03-31 16:15:49,210 INFO  [FullBackupThread] [] backup - full backup took 8235 millisec
2008-03-31 16:15:49,404 ERROR [FullBackupThread] [] backup - Error occurred during full backup
java.io.IOException: Cannot remove /opt/zimbra/backup/tmp/full-20080331.201540.793/accounts/616/69e/61669eee-0709-4f1b-9c7c-3457afa69a31/index/0/_6pn.cfs
        at com.zimbra.common.util.FileUtil.deleteDir(FileUtil.java:311)
        at com.zimbra.common.util.FileUtil.deleteDir(FileUtil.java:308)
        at com.zimbra.common.util.FileUtil.deleteDir(FileUtil.java:308)
        at com.zimbra.cs.backup.FileBackupTarget$BackupAcctSession.endFullBackup(FileBackupTarget.java:1509)
        at com.zimbra.cs.backup.BackupSet.startFullBackup(BackupSet.java:332)
        at com.zimbra.cs.backup.FileBackupTarget$FileBackupSet.startFullBackup(FileBackupTarget.java:790)
        at com.zimbra.cs.backup.BackupManager.doBackupFull(BackupManager.java:729)
        at com.zimbra.cs.backup.BackupManager$FullBackupThread.run(BackupManager.java:219)

It is similar (operation not permitted)... Could this be some kind of leftover issue?