This is probably the weirdest thing I've seen since we started using Zimbra 6 months ago. It's not a widespread problem; I got a specific report that a user was not receiving mail from a particular listserv. So I got a date and time when a message was sent and traced the logs from our mailman server, to the MTA, to the mailbox server...except there wasn't anything logged on the mailbox server for this recipient.

Here is a log sample from the MTA. I generated this by grepping on the ID ("5079E6204CA"). I have anonymized the addresses but otherwise changed nothing:

Dec 2 16:55:01 shiva postfix/smtpd[7885]: 5079E6204CA: client=localhost.localdomain[127.0.0.1]
Dec 2 16:55:01 shiva postfix/cleanup[6801]: 5079E6204CA: message-id=<432381256.2072651228253326164.JavaMail.root@ga nesh.example.com>
Dec 2 16:55:01 shiva postfix/qmgr[31256]: 5079E6204CA: from=<listserv-bounces@example.com>, size=6168, nrcpt=6 (queue active)
Dec 2 16:55:01 shiva postfix/smtp[11982]: 2E1456203EC: to=<outside-forwarded-address@example2.com>, orig_to=<user2@example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5079E6204CA)
Dec 2 16:55:01 shiva postfix/smtp[11982]: 2E1456203EC: to=<user1@example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5079E6204CA)
Dec 2 16:55:01 shiva postfix/smtp[11982]: 2E1456203EC: to=<user2@example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5079E6204CA)
Dec 2 16:55:01 shiva postfix/smtp[11982]: 2E1456203EC: to=<user3@example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5079E6204CA)
Dec 2 16:55:01 shiva postfix/smtp[11982]: 2E1456203EC: to=<user4@example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5079E6204CA)
Dec 2 16:55:01 shiva postfix/smtp[11982]: 2E1456203EC: to=<user5@example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5079E6204CA)
Dec 2 16:55:04 shiva postfix/lmtp[1763]: 5079E6204CA: to=<user1@example.com>, relay=zmailbox.example.com[<ip removed>]:7025, delay=3, delays=0.01/0.01/0/2.9, dsn=2.1.5, status=sent (250 2.1.5 OK)
Dec 2 16:55:04 shiva postfix/lmtp[1763]: 5079E6204CA: to=<user2@example.com>, relay=zmailbox.example.com[<ip removed>]:7025, delay=3, delays=0.01/0.01/0/2.9, dsn=2.1.5, status=sent (250 2.1.5 OK)
Dec 2 16:55:04 shiva postfix/lmtp[1763]: 5079E6204CA: to=<user3@example.com>, relay=zmailbox.example.com[<ip removed>]:7025, delay=3, delays=0.01/0.01/0/2.9, dsn=2.1.5, status=sent (250 2.1.5 OK)
Dec 2 16:55:04 shiva postfix/lmtp[1763]: 5079E6204CA: to=<user4@example.com>, relay=zmailbox.example.com[<ip removed>]:7025, delay=3, delays=0.01/0.01/0/2.9, dsn=2.1.5, status=sent (250 2.1.5 OK)
Dec 2 16:55:04 shiva postfix/lmtp[1763]: 5079E6204CA: to=<user5@example.com>, relay=zmailbox.example.com[<ip removed>]:7025, delay=3, delays=0.01/0.01/0/2.9, dsn=2.1.5, status=sent (250 2.1.5 OK)
Dec 2 16:55:06 shiva postfix/smtp[11757]: 5079E6204CA: to=<outside-forwarded-address@example2.com>, relay=mta.example2.com[<ip removed>]:25, delay=5.4, delays=0.01/0.01/5.3/0.14, dsn=2.0.0, status=sent (250 2.0.0 mB2Lt6cD003232 Message accepted for delivery)
Dec 2 16:55:06 shiva postfix/qmgr[31256]: 5079E6204CA: removed


So, the original message had 5 recipients, one had a forward set to an outside account, so nrcpt=6. The forwarded message was passed to the outside account, and the other 5 are passed on to our mailbox server. So far, so good. Now, we look at the mailbox server mailbox.log. I generated this by grepping on the LmtpServer id ("LmtpServer-88936") that handled this message:

2008-12-02 16:55:01,389 INFO [LmtpServer-88936] [ip=<ip removed>;] lmtp - Delivering message: size=6168 bytes, nrcpts=5, sender=listserv-bounces@example.com, msgid=<432381256.2072651228253326164.JavaMail.root @ganesh.example.com>
2008-12-02 16:55:01,391 INFO [LmtpServer-88936] [name=user1@example.com;mid=5375;] mailop - Adding Message: id=3235, Message-ID=<432381256.2072651228253326164.JavaMail.root@ga nesh.example.com>, parentId=-1, folderId=2, folderName=Inbox.
2008-12-02 16:55:02,361 INFO [LmtpServer-88936] [] lmtp - accepted and discarded message for user2@example.com: local delivery is disabled
2008-12-02 16:55:02,362 INFO [LmtpServer-88936] [name=user3@example.com;mid=5637;] mailop - Adding Message: id=1352, Message-ID=<432381256.2072651228253326164.JavaMail.root@ga nesh.example.com>, parentId=-1, folderId=2, folderName=Inbox.
2008-12-02 16:55:03,393 INFO [LmtpServer-88936] [name=user5@example.com;mid=2524;] mailop - Adding Message: id=7914, Message-ID=<432381256.2072651228253326164.JavaMail.root@ga nesh.example.com>, parentId=-1, folderId=2, folderName=Inbox.
2008-12-02 16:55:04,296 INFO [LmtpServer-88936] [] ProtocolHandler - Handler exiting normally


So here's the burning question: What happened to the message for user4@example.com? The mailbox server still shows nrcpts=5, but it only attempts to deliver to 4 users! There is no error message or anything for user4@example.com.

Any ideas?

-Andrew L