Enormous IMAP traffic from Outlook clients to ZCS server

[Labsy]

Hi,

from time to time some newer Outlook client (especially Outlook 2021) begins generating enormous traffic against my ZCS server via IMAP protocol. By enormous I mean 5-12 GB/day towards IMAP port 993.

On Outlook client it results in messages being delayed, non-stop syncing and not being able to send mail for an hour or so.

On ZCS serve5r side it looks like flood of LOG entries like this, today there were over 17.000 of such parts with just "Deleted altertag" in log file:

Code: Select all

2022-03-20 08:53:38,038 INFO  [ImapServer-105] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:38,111 INFO  [ImapServer-109] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] mailop - Adding Message: id=227969, Message-ID=<06ee01d83c27$91793320$b46b9960$@email.com>, parentId=-1, folderId=2, folderName=Inbox acct=350e8ff6-956b-475c-9afb-dd544930cefc.
2022-03-20 08:53:38,115 INFO  [ImapServer-109] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - APPEND elapsed=7 (NIO)
2022-03-20 08:53:38,129 INFO  [ImapServer-103] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:38,142 INFO  [ImapServer-110] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:38,156 INFO  [ImapServer-104] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - NOOP elapsed=0 (NIO)
2022-03-20 08:53:38,167 INFO  [ImapServer-100] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IMAP client has flagged the item with id 227968 to be Deleted altertag
2022-03-20 08:53:38,172 INFO  [ImapServer-100] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - UID STORE elapsed=5 (NIO)
2022-03-20 08:53:38,187 INFO  [ImapServer-101] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:38,197 INFO  [ImapServer-106] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=1 (NIO)
2022-03-20 08:53:38,212 INFO  [ImapServer-108] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] mailop - Deleting Message (id=227968).
2022-03-20 08:53:38,215 INFO  [ImapServer-108] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - UID EXPUNGE elapsed=3 (NIO)
2022-03-20 08:53:38,228 INFO  [ImapServer-99] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:38,244 INFO  [ImapServer-98] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:38,262 INFO  [ImapServer-105] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - NOOP elapsed=0 (NIO)
2022-03-20 08:53:38,277 INFO  [ImapServer-107] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - UID FETCH elapsed=0 (NIO)
2022-03-20 08:53:38,287 INFO  [ImapServer-102] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)
2022-03-20 08:53:39,443 INFO  [ImapServer-109] [name=client@email.com;mid=8;ip=10.10.11.50;oip=84.52.152.47;via=10.10.11.50(nginx/1.20.0);ua=Microsoft Outlook/16.0.14332.20255;cid=208652;] imap - IDLE elapsed=0 (NIO)

And this is going on for at least 2 weeks now for this client, and in the menatime some other client jumps-in with similar problem. When dozen of such clients collide at the same day, whole server becomes less responsive, mails are delayed for all users and then all hell breaks loose.

Any idea what's going on?

EDIT
I examined Webmail and found endless list of ONE EXACT MAIL repeating indefinitely in "Restore deleted items" in Trash. Maybe some mail gets stuck and cannot delete itself?
Another anomaly - user has only few thousands mails, but when I started mailbox reindexing it says 105.873 mails... Where from??? After reindexing finished, still the same issue on the list of "Restore deleted items" - thousands of copies of same message on the list. Cannot get rid of those and it all sems they might cause initial IMAP traffic issue.

[L. Mark Stone]

At the risk of telling you something you likely already know...

Email deletion via IMAP clients is a two-stage process.

First, the IMAP client marks the email as Deleted, so to the user the message does appear as deleted in their IMAP client, but on the server the message is still there.

Second, the IMAP client will "periodically" run an EXPUNGE task, which is what actually deletes the email from the server.

"Periodically" because different IMAP clients and different versions of Outlook give the user different levels of control over when/how often the expunge process will run.

So I would check your mailbox.log to make sure, for all of the problematic users you've identified, that you see "EXPUNGE" entries. I'm given to understand that IMAP clients that are not doing any expunging or are doing very infrequent expunging can cause Java memory heap pressure. Zimbra's zmstats in the Admin Console can give you insights, or you can run the following to see in real time how frequently the Java garbage collector is running and how it is performing. You may need to increase mailboxd_java_heap_size in localconfig. It's rare that the Java heap size should need to be set larger than 10GB.

Code: Select all

tail -f ~/log/zmmailboxd.out | grep -v "at \|PROCESSING\|native formatter failure"

One easy if crude way to check if you have an expunge client configuration issue is to count how many entries you have in mailbox.log for where the IMAP client marked a message as being deleted, and compare that against the number of entries you have for expunge activities. They should be pretty close, and assuming mailbox.log got rotated when the server was quiesced, you should have a little less expunging entries than marked for deletion entries, like so:

Code: Select all

zimbra@mb21:~$ cat ~/log/mailbox.log | grep -i expunge | wc -l
29
zimbra@mb21:~$ cat ~/log/mailbox.log | grep "Deleted altertag" | wc -l
33
zimbra@mb21:~$ 

Hope that helps,
Mark

[adrian.gibanel.btactic]

Hi,

from time to time some newer Outlook client (especially Outlook 2021) begins generating enormous traffic against my ZCS server via IMAP protocol. By enormous I mean 5-12 GB/day towards IMAP port 993.

On Outlook client it results in messages being delayed, non-stop syncing and not being able to send mail for an hour or so.

On ZCS serve5r side it looks like flood of LOG entries like this, today there were over 17.000 of such parts with just "Deleted altertag" in log file:

We are experiencing the same thing on a Release 8.8.15.GA.4177.UBUNTU20.64 UBUNTU20_64 NETWORK edition, Patch 8.8.15_P37 system.
An email in the Inbox folder gets created and immediately deleted. Then that same email (Not sure if headers are the same but contents are the same) gets created and again and immediately deleted again.
As a consequence those deleted emails go to the Restore Deleted Items folder as a consequence of having dumpster enabled.

In our case the client is an Outlook 2016 also known as Outlook 365 .

Blocking that Outlook from reaching ZCS server seems to stop the problem but, of course, it's not a viable long-term solution.

Did you ever find a workaround or solution for this problem?
Did you open a support ticket with Zimbra?

Thanks for your feedback!

[mocha]

I've had a similar problem and it turns out that it could be caused by Eset Endpoint Security. It's also worth noting that in my experience this only happens with mailboxes configured in Outlook via IMAP on more than one PC (sometimes 5 or more Outlooks at the same time).

https://forum.eset.com/topic/40888-dete ... ame-email/
https://forum.eset.com/topic/33024-outl ... conflicts/
https://forum.eset.com/topic/34659-eset ... -messages/

If you are experiencing this problem and are using Eset, try temporarily uninstalling it on all PCs connected to the mailbox affected by this problem (and probably re-add the IMAP account to Outlook as well).

If you don't use Eset, please add your detailed experience here so that we can rule it out as a possible cause.

[adrian.gibanel.btactic]

As per Duplicate email uploads exceeding users quota - ZBUG-4613 and uploads exceeding users quota - ZBUG-4613 threads this has been classified as ZBUG-4613 by Zimbra.

[adrian.gibanel.btactic]

I personally think that Zimbra cannot do too much on fixing this bug but that Outlook is the software to be fixed.

I also think that we might explore asking for a ZRFE where a mailbox Dumpster ignores saving into itself a new email if that email id is exactly the same one as the previous email id (or as the two previous emails).

You wouldn't stop the Outlook which it's behaving badly but it wouldn't consume your disk space ad infinitum.
Do you think this would be a valid workaround?
Or would you maybe approach it in another way?

[ghen]

We are experiencing the same issue, but with Apple users, copying the same message(s) to Trash thousands of times while not contributing to quota.
This leads to mailboxes exceeding their quota by a factor 10 or more...

We are drastically lowering zimbraMailTrashLifetime for the mailboxes we spot with this behaviour, to keep their Trash folder under control...