Page 1 of 2 12 LastLast
Results 1 to 10 of 13

Thread: Message disappears between MTA and mailbox server

  1. #1
    andrew_l is offline Active Member
    Join Date
    Apr 2008
    Posts
    26
    Rep Power
    7

    Default Message disappears between MTA and mailbox server

    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

  2. #2
    uxbod's Avatar
    uxbod is offline Moderator
    Join Date
    Nov 2006
    Location
    UK
    Posts
    8,017
    Rep Power
    24

    Default

    Have a look before the LMTP entries to see what Postfix and Amavis did with them prior to being sent onto the mailboxes.

  3. #3
    andrew_l is offline Active Member
    Join Date
    Apr 2008
    Posts
    26
    Rep Power
    7

    Default

    Wouldn't all the postfix and amavis activity take place on the MTA rather than on the mailbox server? The first chunk of logs I posted came from the MTA (our MTAs are separate from our mailbox server). That MTA log seems to show the messages being handed off to the mailbox server.

    -Andrew L

  4. #4
    uxbod's Avatar
    uxbod is offline Moderator
    Join Date
    Nov 2006
    Location
    UK
    Posts
    8,017
    Rep Power
    24

    Default

    Have a look on your mailbox server in /opt/zimbra/logs and see what mailbox.log says. Make sure there is not another error somewhere.

  5. #5
    andrew_l is offline Active Member
    Join Date
    Apr 2008
    Posts
    26
    Rep Power
    7

    Default

    The second log chunk I posted is from the mailbox.log. I got that one by looking through and finding the name of the LmtpServer thread that seemed to have handled this message, and grepping on that. I also tried grepping on the username, which got me nothing (no entries for that user around the time this message came through). Any other patterns that you can think of that I should try grepping on? Otherwise I would have to go through the mailbox.log line-by-line. Thanks,

    -Andrew L

  6. #6
    Jesster's Avatar
    Jesster is offline Trained Alumni
    Join Date
    Nov 2007
    Location
    Santa Barbara, CA.
    Posts
    109
    Rep Power
    7

    Default

    One time I was troubleshooting a similar issue, and I realized that the mailstore java/lmtp process wouldn't deliver some messages (even thought my external MTA's accepted them).

    In our case, the problem was the recipients already had matching emails in their mailbox (or more specifically, matching/duplicate Message-ID)

  7. #7
    andrew_l is offline Active Member
    Join Date
    Apr 2008
    Posts
    26
    Rep Power
    7

    Default

    I've seen that before too, but it's always logged a "Not delivering message with duplicate Message-ID" error in the mailbox.log. There is no such error for the user in question in the whole day's log. Have you seen cases where it did this without logging the error?

    -Andrew L

  8. #8
    Jesster's Avatar
    Jesster is offline Trained Alumni
    Join Date
    Nov 2007
    Location
    Santa Barbara, CA.
    Posts
    109
    Rep Power
    7

    Default

    Quote Originally Posted by andrew_l View Post
    I've seen that before too, but it's always logged a "Not delivering message with duplicate Message-ID" error in the mailbox.log. There is no such error for the user in question in the whole day's log. Have you seen cases where it did this without logging the error?

    -Andrew L
    You're right, i should have also noted that mailbox.log does log the duplicate. Ofcourse, on a very active system, it's easy to miss the first dozen times (in my case)

    The only other case of a missing email I've worked on related to Amavis rejecting emails with password protected files (excel/word?) I can't remember the details. There was a Zimbra option to disable that Amavis setting, which fixed it for us.

    Update: The Amavis Option I mention above is zimbraVirusBlockEncryptedArchive (global option) - in the UI it says "Block encrypted archives"
    Last edited by Jesster; 12-04-2008 at 01:05 PM.

  9. #9
    ArcaneMagus's Avatar
    ArcaneMagus is offline Moderator
    Join Date
    Feb 2007
    Location
    Portland, OR
    Posts
    1,147
    Rep Power
    10

    Default

    If that was the issue though it would affect all the users on the zimbra server....not just the one that isn't getting the mail.

    If you can repeat this problem try running a tcpdump on the loopback interface as I believe this will catch the communication between the processes and might reveal some issue not shown in the logs (just guessing here but it might help).

  10. #10
    d-petro is offline Starter Member
    Join Date
    Feb 2009
    Posts
    1
    Rep Power
    6

    Default

    I just ran across this, and it turned out to be a filter setup on the receiving users' mailbox. Simple solution, but more explicit log messages in a more commonly viewed log would be appreciated.

Page 1 of 2 12 LastLast

Thread Information

Users Browsing this Thread

There are currently 1 users browsing this thread. (0 members and 1 guests)

Similar Threads

  1. Stand Alone MTA
    By bonoboslr in forum Installation
    Replies: 4
    Last Post: 12-02-2008, 06:48 AM
  2. Zimbra fails after working for 2 weeks
    By Linsys in forum Administrators
    Replies: 10
    Last Post: 10-07-2008, 12:42 AM
  3. Error after installation
    By robsontuxlinux in forum Installation
    Replies: 13
    Last Post: 09-11-2008, 09:48 PM
  4. [SOLVED] Why my MTA Cross???
    By fsloke in forum Installation
    Replies: 6
    Last Post: 07-30-2008, 08:55 PM
  5. error about mta trusted networks on non-mta server
    By bdial in forum Administrators
    Replies: 4
    Last Post: 02-14-2008, 09:50 AM

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •