Page 1 of 3 123 LastLast
Results 1 to 10 of 23

Thread: Lmtp

  1. #1
    kollross is offline Senior Member
    Join Date
    Nov 2005
    Posts
    50
    Rep Power
    9

    Default Lmtp

    We currently have a 2 machine zimbra setup. One machine is a dedicated spam/filter and the second machine is mailstore/smtp/imap/pop. We noticed that every couple of days the spam filter would stop sending email to the to the mailstore. Also the outgoing smtp on the mailstore also stops sending outbound messages. I issued postqueue -f on the spam filter but that appears to have no effect. Here is the results from postqueue -p

    7EB1D27863D 2643 Tue Nov 29 15:43:02 asdf@asdf.com
    (delivery temporarily suspended: connect to mail.store.com[69.9.xxx.xxx]: read timeout)
    I obviously changed a few of the the names.

    Thus far the only way i've been able to correct the problem is by doing a
    zmcontrol stop
    zmcontrol start
    On the mailstore server
    Followed by a postqueue -f on the spam filter server.

    Currently this email system is not processing a huge amount of email (a few hundred a day at most).

  2. #2
    marcmac is offline Expert Member
    Join Date
    Sep 2005
    Posts
    2,103
    Rep Power
    13

    Default logs?

    Is there anything else in the logs around that time, on the store servere? Either in /var/log/zimbra.log or /opt/zimbra/log/zimbra.log?

    Do you have backups running? We've fixed a bug that caused some delivery delays (and duped messages) when backups were running.

  3. #3
    kollross is offline Senior Member
    Join Date
    Nov 2005
    Posts
    50
    Rep Power
    9

    Default logs

    /var/log/zimbra.log

    Nov 29 17:04:50 white postfix/smtp[26151]: C33D9433939F: to=<heather@bcsp.org>, relay=BCSPMX.bcsp.org[68.21.76.2], delay=1, status=sent (250 Requested ma
    il action okay, completed)
    Nov 29 17:04:50 white postfix/qmgr[7420]: C33D9433939F: removed
    Nov 29 17:08:09 white postfix/anvil[26144]: statistics: max connection rate 1/60s for (smtp:70.225.179.38) at Nov 29 17:04:47
    Nov 29 17:08:09 white postfix/anvil[26144]: statistics: max connection count 1 for (smtp:70.225.179.38) at Nov 29 17:04:47
    Nov 29 17:08:09 white postfix/anvil[26144]: statistics: max cache size 1 at Nov 29 17:04:47
    Nov 29 17:10:01 white postfix/sendmail[27072]: fatal: parameter inet_interfaces: no local interface found for 192.168.223.35
    Nov 29 17:10:01 white zimbramon[27073]: 27073:info: 2005-11-29 17:10:01, QUEUE: 809 4
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, STATUS: white.soltec.net: ldap: Running
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, STATUS: white.soltec.net: logger: Running
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, STATUS: white.soltec.net: mailbox: Running
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, STATUS: white.soltec.net: mta: Running
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, STATUS: white.soltec.net: snmp: Running
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, STATUS: white.soltec.net: spell: Running
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, DISK: white.soltec.net: dev: /dev/mapper/VolGroup00-LogVol00, mp: /, tot: 212283
    , avail: 41%
    Nov 29 17:10:03 white zimbramon[27081]: 27081:info: 2005-11-29 17:10:01, DISK: white.soltec.net: dev: /dev/sda1, mp: /boot, tot: 99, avail: 82
    Nov 29 17:18:58 white zimbramon[30178]: 30178:info: Stopping services
    Nov 29 17:18:58 white zimbramon[30178]: 30178:info: Stopping antispam
    Nov 29 17:18:58 white zimbramon[30178]: 30178:info: Stopping antivirus
    Nov 29 17:18:58 white zimbramon[30178]: 30178:info: Stopping ldap
    Nov 29 17:18:58 white zimbramon[30178]: 30178:info: Stopping logger
    Nov 29 17:19:00 white zimbramon[30178]: 30178:info: Stopping mailbox
    Nov 29 17:19:03 white amavis[6209]: Net::Server: 2005/11/29-17:19:03 Server closing!

    No backups are being run during these times (we are running M2)

  4. #4
    marcmac is offline Expert Member
    Join Date
    Sep 2005
    Posts
    2,103
    Rep Power
    13

    Default logs

    Are the clocks out of sync? The failure you posted was at 15:43, and the logs you posted are from 2 hours later.

    Also - in the logs, it shows the servers being shut down - was that intentional?

  5. #5
    tron is offline Senior Member
    Join Date
    Oct 2005
    Posts
    52
    Rep Power
    9

    Default

    The clocks are not out of sync. Matt copied that part of the log because that is when he noticed this problem of non-delivery is occuring. I looked at the log for entries prior to 15:30:00 and did not see anything odd. I would be happy to post the whole log somewhere for you to download if you need it.

    Matt shutdown and restarted the mailstore server in order to get the delivery going again. So that was intentional.

    Quote Originally Posted by marcmac
    Are the clocks out of sync? The failure you posted was at 15:43, and the logs you posted are from 2 hours later.

    Also - in the logs, it shows the servers being shut down - was that intentional?

  6. #6
    marcmac is offline Expert Member
    Join Date
    Sep 2005
    Posts
    2,103
    Rep Power
    13

    Default logs

    I don't need the whole log - but his original post mentioned that incoming and outgoing mail were both not functioning - and the first line of the logs posted show a successful outbound delivery...

    So - if there's nothing in our logs for the time - check /var/log/messages and see if the system was complaining about anything?

  7. #7
    tron is offline Senior Member
    Join Date
    Oct 2005
    Posts
    52
    Rep Power
    9

    Default

    I don't see the system complaining about anything in /var/log/messages either. Here is an excerpt from 15:20. Now, one thing peculiar I did notice is that, according to /var/log/messages, amavisd is running even though I have disabled SPAM/Virus filtering on mailstore server through the admin GUI. Is that the correct behavior?

    Nov 29 15:20:01 white zimbramon[4597]: 4597:info: 2005-11-29 15:20:01, QUEUE: 0
    0
    Nov 29 15:20:01 white crond(pam_unix)[4596]: session closed for user zimbra
    Nov 29 15:20:01 white crond(pam_unix)[4591]: session closed for user root
    Nov 29 15:20:02 white crond(pam_unix)[4593]: session closed for user root
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, STATUS: w
    hite.soltec.net: ldap: Running
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, STATUS: w
    hite.soltec.net: logger: Running
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, STATUS: w
    hite.soltec.net: mailbox: Running
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, STATUS: w
    hite.soltec.net: mta: Running
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, STATUS: w
    hite.soltec.net: snmp: Running
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, STATUS: w
    hite.soltec.net: spell: Running
    Nov 29 15:20:03 white zimbramon[4603]: 4603:info: 2005-11-29 15:20:01, DISK: whi
    te.soltec.net: dev: /dev/mapper/VolGroup00-LogVol00, mp: /, tot: 212297, avail:
    41%


    Quote Originally Posted by marcmac
    I don't need the whole log - but his original post mentioned that incoming and outgoing mail were both not functioning - and the first line of the logs posted show a successful outbound delivery...

    So - if there's nothing in our logs for the time - check /var/log/messages and see if the system was complaining about anything?

  8. #8
    kollross is offline Senior Member
    Join Date
    Nov 2005
    Posts
    50
    Rep Power
    9

    Default Logs

    Here are the logs from the exact time as as the time out email. The previous snipit of log was right before i zmcontrol stop on the mailstore server. So basically there are timeouts between the spam server and the mailstore server for a few hours. If you would like to vew the entire log (82 Meg) i've uploaded it too http://www.soltec.net/zimbra.tar.gz


    Nov 29 15:43:02 black postfix/cleanup[16479]: D9824278634: message-id=<15425121@cwmzajykpmonZ-lajjs>
    Nov 29 15:43:02 black postfix/qmgr[2755]: D9824278634: from=<Clinton.vwwr@endogenter.com>, size=2239, nrcpt=1 (queue active)
    Nov 29 15:43:02 black amavis[13721]: (13721-04) ESMTP::10024 /opt/zimbra/amavisd/tmp/amavis-20051129T153040-13721: <Clinton.vwwr@
    endogenter.com> -> <penny@gardencourts.com> Received: SIZE=2239 BODY=8BITMIME from black.soltec.net ([127.0.0.1]) by localhost (b
    lack.soltec.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 13721-04 for <penny@gardencourts.com>; Tue, 29 Nov 2005 15:4
    3:02 -0500 (EST)
    Nov 29 15:43:02 black amavis[13721]: (13721-04) body hash: a1a89965eab718fb60057dbacc9caa6a
    Nov 29 15:43:02 black amavis[13721]: (13721-04) Checking: ySA6RJrxvnXU [72.11.147.31] <Clinton.vwwr@endogenter.com> -> <penny@gar
    dencourts.com>
    Nov 29 15:43:02 black amavis[13721]: (13721-04) p003 1 Content-Type: multipart/alternative
    Nov 29 15:43:02 black amavis[13721]: (13721-04) p001 1/1 Content-Type: text/plain, size: 1 B, name:
    Nov 29 15:43:02 black amavis[13721]: (13721-04) p002 1/2 Content-Type: text/html, size: 1344 B, name:
    Nov 29 15:43:02 black amavis[13721]: (13721-04) Checking for banned types and filenames
    Nov 29 15:43:02 black amavis[13721]: (13721-04) collect banned table[0]: penny@gardencourts.com, tables: DEFAULT=>Amavis::Lookup:
    :RE=ARRAY(0x8914944)
    Nov 29 15:43:02 black amavis[13721]: (13721-04) p.path penny@gardencourts.com: "P=p003,L=1,M=multipart/alternative | P=p001,L=1/1
    ,M=text/plain,T=dat"
    Nov 29 15:43:02 black amavis[13721]: (13721-04) p.path penny@gardencourts.com: "P=p003,L=1,M=multipart/alternative | P=p002,L=1/2
    ,M=text/html,T=html"
    Nov 29 15:43:02 black amavis[13721]: (13721-04) lookup_ldap_attr(amavisspamkilllevel) (WARN: no such attribute in LDAP entry), "p
    enny@gardencourts.com" result=undef
    Nov 29 15:43:02 black postfix/smtpd[16517]: connect from localhost.localdomain[127.0.0.1]
    Nov 29 15:43:02 black amavis[13721]: (13721-04) AUTH not needed, user='', MTA offers 'LOGIN PLAIN'
    Nov 29 15:43:02 black postfix/smtpd[16517]: 7EB1D27863D: client=localhost.localdomain[127.0.0.1]
    Nov 29 15:43:02 black amavis[13721]: (13721-04) response to RCPT TO for <penny@gardencourts.com>: "250 Ok"
    Nov 29 15:43:02 black postfix/cleanup[16479]: 7EB1D27863D: message-id=<15425121@cwmzajykpmonZ-lajjs>
    Nov 29 15:43:02 black postfix/qmgr[2755]: 7EB1D27863D: from=<Clinton.vwwr@endogenter.com>, size=2643, nrcpt=1 (queue active)
    Nov 29 15:43:02 black postfix/smtpd[16517]: disconnect from localhost.localdomain[127.0.0.1]
    Nov 29 15:43:02 black amavis[13721]: (13721-04) FWD via SMTP: <Clinton.vwwr@endogenter.com> -> <penny@gardencourts.com>, 250 2.6.
    0 Ok, id=13721-04, from MTA([127.0.0.1]:10025): 250 Ok: queued as 7EB1D27863D
    Nov 29 15:43:02 black postfix/qmgr[2755]: 7EB1D27863D: to=<penny@gardencourts.com>, relay=none, delay=0, status=deferred (deliver
    y temporarily suspended: conversation with white.soltec.net[69.9.180.194] timed out while sending end of data -- message may be s
    ent more than once)
    Nov 29 15:43:02 black amavis[13721]: (13721-04) lookup_ldap_attr(amavisspamtag2level) (WARN: no such attribute in LDAP entry), "p
    enny@gardencourts.com" result=undef
    Nov 29 15:43:02 black amavis[13721]: (13721-04) Passed CLEAN, [72.11.147.31] [72.11.147.31] <Clinton.vwwr@endogenter.com> -> <pen
    ny@gardencourts.com>, Message-ID: <15425121@cwmzajykpmonZ-lajjs>, mail_id: ySA6RJrxvnXU, Hits: -, 356 ms
    Nov 29 15:43:02 black amavis[13721]: (13721-04) TIMING [total 384 ms] - SMTP EHLO: 2 (0%)0, SMTP pre-MAIL: 1 (0%)1, lookup_ldap:
    13 (3%)4, SMTP pre-DATA-flush: 1 (0%)4, SMTP DATA: 27 (7%)11, body_hash: 1 (0%)11, gen_mail_id: 0 (0%)11, mime_decode: 9 (2%)14,
    get-file-type2: 7 (2%)16, parts_decode: 0 (0%)16, update_cache: 3 (1%)16, deal_with_mail_size: 0 (0%)16, fwd-connect: 3 (1%)17, f
    wd-mail-from: 3 (1%)18, fwd-rcpt-to: 45 (12%)30, write-header: 1 (0%)30, fwd-data: 0 (0%)30, fwd-data-end: 91 (24%)54, fwd-rundow
    n: 85 (22%)76, main_log_entry: 91 (24%)100, update_snmp: 1 (0%)100, unlink-2-files: 1 (0%)100, rundown: 0 (0%)100
    Nov 29 15:43:02 black postfix/smtp[16515]: D9824278634: to=<penny@gardencourts.com>, relay=127.0.0.1[127.0.0.1], delay=1, status=
    sent (250 2.6.0 Ok, id=13721-04, from MTA([127.0.0.1]:10025): 250 Ok: queued as 7EB1D27863D)


    Here actually is the entry from the original time out email that i posted

  9. #9
    marcmac is offline Expert Member
    Join Date
    Sep 2005
    Posts
    2,103
    Rep Power
    13

    Default amavisd running

    That is the correct behaviour - postfix tends to remember where things in the queue are supposed to be sent - so if you were running amavis, and stopped it, even if you took it out of the content_filter line, you could (potentially) trap msgs in your queue forever.

  10. #10
    marcmac is offline Expert Member
    Join Date
    Sep 2005
    Posts
    2,103
    Rep Power
    13

    Default scanning

    These logs are from the MTA, right?

    Is there anything interesting about the network, or are the boxes on the same LAN?


    Is this an accurate description of what you're seeing:

    Periodically, mail from the mta->mailstore will stop delivering, with the "delivery temporarily suspended" message. At the same time, mail from the mailstore->world will start to timeout?

    If that is the case, then I don't think it's just the mailstore, since that wouldn't explain why the MTA instance on the mailstore is timing out. Is it pointing to a relay_host, or is it delivering mail directly to the world? I'm curious to see if the problem could be DNS related.

Page 1 of 3 123 LastLast

Thread Information

Users Browsing this Thread

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

Similar Threads

  1. LMTP problem (amoung other things)
    By kollross in forum Administrators
    Replies: 3
    Last Post: 02-18-2007, 10:36 PM
  2. MTA and LMTP
    By dlochart in forum Administrators
    Replies: 4
    Last Post: 12-08-2006, 09:00 AM
  3. Using SMTP or LMTP?
    By Achim.Theobald in forum Users
    Replies: 1
    Last Post: 05-25-2006, 08:02 AM
  4. lmtp vs dns?
    By centaury in forum Installation
    Replies: 2
    Last Post: 03-20-2006, 09:27 AM
  5. Local Delivery LMTP Problem
    By CaptainFiesta in forum Installation
    Replies: 4
    Last Post: 10-04-2005, 08:07 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
  •