Bulk delete etc. failing in Zimbra 8

Shortly after upgrading to Zimbra 8, I ran into annoying behavior when trying to delete large numbers of messages, both via IMAP and the web interface. If deleting the messages one-by-one (even in quick succession), then everything was fine, but if I selected several messages and deleted them all at once then it would fail with a “UID COPY failed” message in my IMAP client or a “An unknown error (zclient.UPLOAD_FAILED) has occurred” message in the Zimbra web interface.

Looking in the Zimbra mailboxd log file (/opt/zimbra/log/mailbox.log), I found that mailboxd was returning HTTP 503 Service Unavailable messages for these delete requests.

When using IMAP:

2013-08-04 10:13:09,188 WARN [ImapSSLServer-41] [name=test@example.com;mid=5;ip=195.170.173.21;oip=192.168.1.1;via=192.168.10.1(nginx/1.2.0-zimbra);ua=Zimbra/8.0.4_GA_5737;] imap – UID COPY failed
com.zimbra.common.service.ServiceException: system failure: error while proxying request to target server: HTTP/1.1 503 Service Unavailable
ExceptionId:ImapSSLServer-41:1375607589188:562b18b52488c9e9
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:258)
at com.zimbra.client.ZMailbox.invoke(ZMailbox.java:623)
at com.zimbra.client.ZMailbox.invoke(ZMailbox.java:607)
at com.zimbra.client.ZMailbox.addMessage(ZMailbox.java:2196)
at com.zimbra.cs.service.mail.ItemActionHelper.executeRemote(ItemActionHelper.java:614)
at com.zimbra.cs.service.mail.ItemActionHelper.schedule(ItemActionHelper.java:382)
at com.zimbra.cs.service.mail.ItemActionHelper.COPY(ItemActionHelper.java:158)
at com.zimbra.cs.imap.ImapHandler.doCOPY(ImapHandler.java:4214)
at com.zimbra.cs.imap.ImapHandler.executeRequest(ImapHandler.java:407)
at com.zimbra.cs.imap.NioImapHandler.processRequest(NioImapHandler.java:124)
at com.zimbra.cs.imap.NioImapHandler.messageReceived(NioImapHandler.java:61)
at com.zimbra.cs.server.NioHandlerDispatcher.messageReceived(NioHandlerDispatcher.java:88)
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 com.zimbra.cs.server.NioLoggingFilter.messageReceived(NioLoggingFilter.java:60)
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.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:722)
Caused by: com.zimbra.common.service.ServiceException: error while proxying request to target server: HTTP/1.1 503 Service Unavailable
ExceptionId:ImapSSLServer-41:1375607589188:562b18b52488c9e9
Code:service.PROXY_ERROR Arg:(url, STR, “https://mailbox.example.com:443/service/soap/AddMsgRequest”)
at com.zimbra.common.service.ServiceException.PROXY_ERROR(ServiceException.java:327)
at com.zimbra.common.soap.SoapHttpTransport.invoke(SoapHttpTransport.java:242)
at com.zimbra.common.soap.SoapHttpTransport.invoke(SoapHttpTransport.java:167)
at com.zimbra.common.soap.SoapTransport.invoke(SoapTransport.java:386)
at com.zimbra.client.ZMailbox.invoke(ZMailbox.java:613)
… 28 more

When using the web interface:

2013-08-04 10:12:15,141 INFO [qtp820657724-13204:https://192.168.1.1:443/service/soap/ConvActionRequest] [name=test@example.com;mid=5;ip=192.168.10.1;ua=ZimbraWebClient – SAF5.1 (Mac)/8.0.4_GA_5737;] SoapEngine – handler exception
com.zimbra.common.zclient.ZClientException: Attachment post failed, status=503
ExceptionId:qtp820657724-13204:https://192.168.10.1:443/service/soap/ConvActionRequest:1375607535141:562b18b52488c9e9
Code:zclient.UPLOAD_FAILED
at com.zimbra.common.zclient.ZClientException.UPLOAD_FAILED(ZClientException.java:57)
at com.zimbra.client.ZMailbox.uploadContentAsStream(ZMailbox.java:2056)
at com.zimbra.client.ZMailbox.uploadContentAsStream(ZMailbox.java:2027)
at com.zimbra.client.ZMailbox.addMessage(ZMailbox.java:2182)
at com.zimbra.cs.service.mail.ItemActionHelper.executeRemote(ItemActionHelper.java:626)
at com.zimbra.cs.service.mail.ItemActionHelper.schedule(ItemActionHelper.java:382)
at com.zimbra.cs.service.mail.ItemActionHelper.COPY(ItemActionHelper.java:158)
at com.zimbra.cs.service.mail.ItemAction.handleCommon(ItemAction.java:170)
at com.zimbra.cs.service.mail.ConvAction.handle(ConvAction.java:39)
at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:522)
at com.zimbra.soap.DocumentHandler.proxyRequest(DocumentHandler.java:530)
at com.zimbra.soap.DocumentHandler.proxyRequest(DocumentHandler.java:472)
at com.zimbra.cs.service.mail.ItemAction.proxyRemoteItems(ItemAction.java:350)
at com.zimbra.cs.service.mail.ItemAction.handleCommon(ItemAction.java:127)
at com.zimbra.cs.service.mail.ConvAction.handle(ConvAction.java:39)
at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:522)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:385)
at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:258)
at com.zimbra.soap.SoapServlet.doWork(SoapServlet.java:293)
at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:209)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:208)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:652)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1320)
at com.zimbra.cs.servlet.RequestStringFilter.doFilter(RequestStringFilter.java:52)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1291)
at com.zimbra.cs.servlet.SetHeaderFilter.doFilter(SetHeaderFilter.java:57)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1291)
at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:82)
at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:256)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1291)
at com.zimbra.cs.servlet.ETagHeaderFilter.doFilter(ETagHeaderFilter.java:45)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1291)
at com.zimbra.cs.servlet.ZimbraQoSFilter.doFilter(ZimbraQoSFilter.java:114)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1291)
at org.eclipse.jetty.servlets.DoSFilter.doFilterChain(DoSFilter.java:473)
at org.eclipse.jetty.servlets.DoSFilter.doFilter(DoSFilter.java:344)
at org.eclipse.jetty.servlets.DoSFilter.doFilter(DoSFilter.java:315)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1291)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:443)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:556)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1044)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:372)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:189)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:978)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:317)
at org.eclipse.jetty.server.handler.DebugHandler.handle(DebugHandler.java:81)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java:369)
at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:486)
at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:944)
at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1005)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:861)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
at org.eclipse.jetty.io.nio.SslConnection.handle(SslConnection.java:196)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:668)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
at java.lang.Thread.run(Thread.java:722)

After a bit research, I found that Zimbra have implemented a “DoS filter” in the Zimbra 8, which is supposed to rate limit the number of requests from one IP address. You can see if you’re triggering this by locking for messages like this in /opt/zimbra/log/zmmailboxd.out:

2013-08-04 10:19:41.096:WARN:oejs.DoSFilter:DOS ALERT: ip=192.168.1.1,session=null,user=null

In Zimbra 8.0.3 and later you can use zmprov to modify the settings for DoSFilter

• zimbraHttpDosFilterDelayMillis can be used to configure whether you should reject any requests over the limit (set to -1) or impose a delay on the handling of the request (in miliseconds). By default it is set to -1 and so will reject any requests over the limit.
• zimbraHttpDosFilterMaxRequestsPerSec sets the threshold (in requests per second) at which the DoSFilter feature is triggered. This is set to 30 by default, which seems rather low.
• zimbraHttpThrottleSafeIPs allows you to whitelist IP addresses which you want to be exempt from the DoSFilter feature. The list needs to be comma seperated uf configuring multiple IP addresses. If you are running a multi-server setup, then the other servers are automatically whitelisted.

Because these settings affect mailboxd, you need to restart it in order for them to take effect.

zmprov mcf zimbraHttpDosFilterDelayMillis 500
zmprov mcf zimbraHttpDosFilterMaxRequestsPerSec 250
zmprov mcf zimbraHttpThrottleSafeIPs 192.168.1.1,192.168.1.2
zmmailboxdctl restart