Postfix problem: lost connection after CONNECT from unknown

Discussion in 'Server Operation' started by fernando_torrez, Nov 26, 2007.

  1. fernando_torrez

    fernando_torrez New Member

    Hi everybody

    I'm fighting with a terrible problem for 1 month. sometimes, when a client tried to send mails the server sends this error:

    Sending of message failed.
    The message could not be sent because connecting to SMTP server myserver.com failed. The server may be unavailable or is refusing SMTP connections. Please verify that your SMTP server setting is correct and try again, or else contact your network administrator

    I saw the postfix log and found that for some reason the connection is closed before the message is processed. this is a piece of the postfix log file:


    Nov 26 08:52:36 mail postfix/smtpd[2241]: connect from unknown[192.168.0.2]
    Nov 26 08:52:36 mail postfix/smtpd[2241]: lost connection after CONNECT from unknown[192.168.0.2]
    Nov 26 08:52:36 mail postfix/smtpd[2241]: disconnect from unknown[192.168.0.2]

    it means that for some reason a local client is losing the connection with myserver, then the client tries to send 3 more times (or so) before the message is sent, and in the worst cases I restart the whole mail server (reboot de server).
    this is appending once a day... lately .... and I'm so :mad:


    Here is a larger piece of the postfix log file:

    Nov 26 08:55:07 mail postfix/smtpd[2342]: connect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: lost connection after CONNECT from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: disconnect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: connect from unknown[125.134.123.148]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: lost connection after CONNECT from unknown[125.134.123.148]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: disconnect from unknown[125.134.123.148]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: connect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: lost connection after CONNECT from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: disconnect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: connect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: lost connection after CONNECT from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: disconnect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: connect from unknown[192.168.0.2]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: lost connection after CONNECT from unknown[192.168.0.2]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: disconnect from unknown[192.168.0.2]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: connect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: lost connection after CONNECT from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: disconnect from unknown[87.226.180.6]
    Nov 26 08:55:07 mail postfix/smtpd[2295]: disconnect from unknown[125.134.123.148]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:07 mail postfix/smtpd[2291]: connect from unknown[62.105.25.12]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: lost connection after CONNECT from unknown[62.105.25.12]
    Nov 26 08:55:07 mail postfix/smtpd[2291]: disconnect from unknown[62.105.25.12]
    Nov 26 08:55:07 mail postfix/smtpd[2342]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:07 mail postfix/smtpd[2342]: connect from unknown[62.105.25.12]
    Nov 26 08:55:07 mail postfix/smtpd[2295]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:07 mail postfix/smtpd[2295]: connect from unknown[62.105.25.12]
    Nov 26 08:55:07 mail postfix/smtpd[2295]: lost connection after CONNECT from unknown[62.105.25.12]
    Nov 26 08:55:07 mail postfix/smtpd[2295]: disconnect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2291]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:08 mail postfix/smtpd[2291]: connect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2291]: lost connection after CONNECT from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2291]: disconnect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2295]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:08 mail postfix/smtpd[2295]: connect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2295]: lost connection after CONNECT from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2295]: disconnect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2291]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:08 mail postfix/smtpd[2291]: connect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2291]: lost connection after CONNECT from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2291]: disconnect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2295]: warning: 62.105.25.12: hostname adsl-ppp-12.reus.ru verification failed: Host not found
    Nov 26 08:55:08 mail postfix/smtpd[2295]: connect from unknown[62.105.25.12]
    Nov 26 08:55:08 mail postfix/smtpd[2295]: lost connection after CONNECT from unknown[62.105.25.12]


    It seem that the postfix is rejecting either internal an external mails :(


    here's is my postfix configuration (postconf -n)

    alias_database = hash:/etc/aliases
    alias_maps = hash:/etc/aliases, ldap:ldapaliases
    body_checks = pcre:/etc/postfix/body_checks
    canonical_maps = hash:/etc/postfix/canonical
    command_directory = /usr/sbin
    daemon_directory = /usr/lib/postfix
    debug_peer_level = 2
    default_destination_concurrency_limit = 10
    default_privs = nobody
    defer_transports =
    disable_dns_lookups = no
    header_checks = pcre:/etc/postfix/header_checks
    local_destination_concurrency_limit = 2
    mail_name = Postfix on SuSE Linux eMail Server 3.1
    mail_owner = postfix
    mailbox_transport = lmtp:unix:public/lmtp
    masquerade_domains = $mydomain
    masquerade_exceptions = root
    maximal_queue_lifetime = 2d
    message_size_limit = 10485760
    mydestination = $mydomain, $myhostname, localhost.$mydomain, [190.129.91.2]
    myhostname = mail.bago.com.bo
    myorigin = $mydomain
    program_directory = /usr/lib/postfix
    queue_directory = /var/spool/postfix
    recipient_delimiter = +
    relayhost =
    relocated_maps = hash:/etc/postfix/relocated
    sender_canonical_maps = ldap:ldapcanonical
    smtp_tls_loglevel = 0
    smtp_tls_note_starttls_offer = yes
    smtp_tls_session_cache_database = sdbm:/etc/postfix/smtp_scache
    smtpd_banner = $myhostname ESMTP $mail_name
    smtpd_client_restrictions = permit_sasl_authenticated
    smtpd_recipient_restrictions = ldap:ldapmailenab, permit_tls_clientcerts, permit_sasl_authenticated, permit_mynetworks, check_client_access btree:/etc/postfix/dracd, check_sender_access hash:/etc/postfix/access_usernames, check_recipient_access hash:/etc/postfix/access_usernames, check_relay_domains
    smtpd_sasl_auth_enable = yes
    smtpd_sasl_security_options = noanonymous
    smtpd_sender_restrictions = hash:/etc/postfix/access_usernames
    smtpd_tls_ask_ccert = yes
    smtpd_tls_received_header = yes
    smtpd_tls_session_cache_database = sdbm:/etc/postfix/smtpd_scache
    tls_daemon_random_source = dev:/dev/urandom
    tls_random_source = dev:/dev/urandom
    transport_maps = hash:/etc/postfix/transport
    virtual_maps = hash:/etc/postfix/virtual, ldap:ldapvuser


    and this is my master.cf

    smtp inet n - y - - smtpd
    localhost:10025 inet n - n - - smtpd -o content_filter=
    smtps inet n - y - - smtpd -o smtpd_tls_wrappermode=yes -o smtpd_sasl_auth_enable=yes
    pickup unix n n y 60 1 pickup
    cleanup unix - - y - 0 cleanup
    qmgr unix n - y 300 1 qmgr
    tlsmgr fifo - - n 300 1 tlsmgr
    rewrite unix - - y - - trivial-rewrite
    bounce unix - - y - 0 bounce
    defer unix - - y - 0 bounce
    flush unix - - n 1000? 0 flush
    smtp unix - - y - - smtp
    showq unix n - y - - showq
    error unix - - y - - error
    local unix - n n - - local
    lmtp unix - - y - - lmtp
    cyrus unix - n n - - pipe
    flags=R user=cyrus argv=/cyrus/bin/deliver -e -m ${extension} ${user}
    uucp unix - n n - - pipe
    flags=F user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
    ifmail unix - n n - - pipe
    flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
    bsmtp unix - n n - - pipe
    flags=F. user=foo argv=/usr/local/sbin/bsmtp -f $sender $nexthop $recipient
    procmail unix - n n - - pipe
    flags=R user=cyrus argv=/usr/bin/procmail -t -m USER=${user} EXT=${extension} /etc/procmailrc

    I'll really appreciate any help

    Thanks in advance
     
  2. falko

    falko Super Moderator Howtoforge Staff

    What'S the output of
    Code:
    telnet localhost 25
    ? Are there any other errors in your logs? What's the output of
    Code:
    postconf -d|grep mydomain
    ?
     
  3. fernando_torrez

    fernando_torrez New Member

    I run (telnet from a client PC)
    telnet mail.myserver.com.bo
    and after 45 seconds a got this message:

    220 mail.myserver.com.bo ESMTP Postfix on SuSE Linux eMail Server 3.1


    I also run the code: postconf -d | grep mydomain
    and this is the output:

    append_dot_mydomain = yes
    mydestination = $myhostname, localhost.$mydomain
    mydomain = mail

    I also verified 'myhostaname' parameter, it's set with a fqdn

    myhostname = mail.myserver.com.bo


    I checked the postfix mail log with this command:

    cat mail | grep -ie 'reject' -ie 'warn' -ie 'fatal' -ie ' error'

    and got messages like these

    Nov 27 00:15:12 mail postfix/smtp[25615]: 4EC5612F9DD: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=7386, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 00:15:12 mail postfix/smtp[25587]: warning: no MX host for musichannel.com has a valid A record
    Nov 27 00:15:12 mail postfix/smtp[25587]: C60DC12FB7E: to=<[email protected]>, relay=none, delay=7299, status=deferred (Name service error for dev.null: Host not found)
    Nov 27 00:15:12 mail postfix/smtp[25589]: 44C9912FADF: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=7337, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 00:15:12 mail postfix/smtp[25591]: 911B712F9B5: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=7408, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 00:15:28 mail postfix/smtp[25331]: CAC6012F9FF: to=<[email protected]>, relay=none, delay=3501, status=deferred (Name service error for thutrang.info: Host not found, try again)
    Nov 27 00:16:38 mail postfix/smtpd[25694]: warning: 85.96.218.50: hostname dsl.dynamic859621850.ttnet.net.tr verification failed: Host not found
    Nov 27 00:17:06 mail postfix/smtpd[25710]: warning: 87.13.130.36: hostname host36-130-dynamic.13-87-r.retail.telecomitalia.it verification failed: Host not found
    Nov 27 00:17:44 mail postfix/smtp[25589]: D32B312FD5C: to=<[email protected]>, relay=smtp-in.his.com[216.194.216.44], delay=36, status=deferred (host smtp-in.his.com[216.194.216.44] said: 451 4.7.1 <[email protected]>: Recipient address rejected: Greylisting in effect - you can deliver your mail for capitaleducators.com in 300 seconds ...)
    Nov 27 00:19:26 mail postfix/smtpd[25694]: warning: 189.149.118.100: hostname dsl-189-149-118-100.prod-infinitum.com.mx verification failed: Host not found
    Nov 27 00:20:26 mail postfix/smtp[25181]: 735B012FE12: to=<[email protected]>, relay=barney.cair.du.edu[130.253.1.27], delay=1064, status=bounced (host barney.cair.du.edu[130.253.1.27] said: 550 5.7.1 <[email protected]>: Recipient address rejected: blocked due to excessive spam)
    Nov 27 00:21:02 mail postfix/smtpd[25153]: warning: 200.121.207.10: hostname client-200.121.207.10.speedy.net.pe verification failed: Host not found
    ...
    Nov 27 00:31:51 mail postfix/smtp[26115]: 5B95012F9E8: to=<[email protected]>, relay=none, delay=7775, status=deferred (Name service error for smtp: Host not found)
    Nov 27 00:31:51 mail postfix/smtp[26132]: A9C4212FDEA: to=<[email protected]>, relay=mx.bol.com.br[200.221.29.128], delay=3792, status=deferred (host mx.bol.com.br[200.221.29.128] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 00:31:54 mail postfix/smtp[26124]: A21CE12FE23: to=<[email protected]>, relay=mailer.mapfre.com.br[200.246.177.30], delay=2, status=bounced (host mailer.mapfre.com.br[200.246.177.30] said: 550 #5.1.0 Rejected by bounce verification.)
    Nov 27 00:31:54 mail postfix/smtp[26123]: D847C12FB4B: to=<[email protected]>, relay=none, delay=7423, status=deferred (Name service error for lifelikej.net: Host not found, try again)
    Nov 27 00:31:56 mail postfix/smtp[25980]: warning: no MX host for forhealthyskin.com has a valid A record
    Nov 27 00:31:56 mail postfix/smtp[25980]: 7900312FE07: to=<[email protected]>, relay=none, delay=3739, status=deferred (Name service error for dev.null: Host not found)
    Nov 27 00:31:58 mail postfix/smtp[26132]: 8748D12FE23: to=<[email protected]>, relay=mailer.mapfre.com.br[200.211.99.154], delay=2, status=bounced (host mailer.mapfre.com.br[200.211.99.154] said: 550 #5.1.0 Rejected by bounce verification.)
    Nov 27 00:32:01 mail postfix/smtp[26116]: 22B1012FC67: to=<[email protected]>, relay=none, delay=17674, status=deferred (Name service error for dobvod.ru: Host not found, try again)
    Nov 27 00:32:42 mail postfix/smtp[26116]: 0E90D12FE30: to=<[email protected]>, relay=mx5.carle.com[199.184.120.181], delay=1, status=bounced (host mx5.carle.com[199.184.120.181] said: 550 5.1.1 <[email protected]>: Recipient address rejected: User unknown)
    ...
    Nov 27 00:37:32 mail postfix/smtpd[25985]: warning: 203.113.26.17: hostname 203-113-26-17.totisp.net verification failed: Host not found
    Nov 27 00:37:32 mail postfix/smtpd[25972]: warning: 203.113.26.17: hostname 203-113-26-17.totisp.net verification failed: Host not found
    Nov 27 00:37:35 mail postfix/smtpd[25971]: warning: 203.113.26.17: hostname 203-113-26-17.totisp.net verification failed: Host not found
    ...
    Nov 27 15:18:27 mail postfix/smtp[13244]: 1704112FE28: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=36360, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 15:18:28 mail postfix/smtp[13253]: 1167912FABD: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=171420, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 15:18:29 mail postfix/smtp[13277]: 6F3F912FBF9: to=<[email protected]>, relay=filter2.win.net[216.24.27.102], delay=1671, status=bounced (host filter2.win.net[216.24.27.102] said: 554 5.7.1 <[email protected]>: Recipient address rejected: User unknown in virtual mailbox table)
    Nov 27 15:18:30 mail postfix/smtp[13255]: 64CD712FB17: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=171458, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    Nov 27 15:18:31 mail postfix/smtp[13275]: 61A4012FC19: to=<[email protected]>, relay=mx.uol.com.br[200.221.29.129], delay=82894, status=deferred (host mx.uol.com.br[200.221.29.129] said: 450 Client host rejected: cannot find your hostname, [190.129.91.2])
    ...
    Nov 27 15:25:57 mail postfix/smtpd[13515]: warning: 201.53.170.22: hostname c935aa16.virtua.com.br verification failed: Host not found
    Nov 27 15:26:04 mail postfix/smtpd[13517]: warning: 201.53.170.22: hostname c935aa16.virtua.com.br verification failed: Host not found
    Nov 27 15:26:53 mail postfix/smtpd[13530]: warning: 201.53.170.22: hostname c935aa16.virtua.com.br verification failed: Host not found
    Nov 27 15:27:56 mail postfix/smtpd[13546]: warning: 75.148.0.66: hostname 75-148-0-66-WashingtonDC.hfc.comcastbusiness.net verification failed: Host not found
    ...
    Nov 27 15:11:55 mail postfix/smtp[12691]: 5CCBE12FA6C: to=<[email protected]>, relay=mfgw5.ocn.ad.jp[125.206.187.87], delay=3, status=bounced (host mfgw5.ocn.ad.jp[125.206.187.87] said: 554 5.7.1 <[email protected]>: Recipient address rejected: Access denied)
    Nov 27 15:12:00 mail postfix/smtp[12690]: 63DFC12FA6C: to=<[email protected]>, relay=mfgw5.ocn.ad.jp[125.206.188.198], delay=3, status=bounced (host mfgw5.ocn.ad.jp[125.206.188.198] said: 554 5.7.1 <[email protected]>: Recipient address rejected: Access denied)
    Nov 27 15:12:00 mail postfix/smtp[12691]: ED6D412F767: to=<[email protected]>, relay=mfgw5.ocn.ad.jp[125.206.188.199], delay=3, status=bounced (host mfgw5.ocn.ad.jp[125.206.188.199] said: 554 5.7.1 <[email protected]>: Recipient address rejected: Access denied)
    Nov 27 15:12:06 mail postfix/smtp[12690]: 557C412FA6C: to=<[email protected]>, relay=mfgw5.ocn.ad.jp[125.206.188.198], delay=2, status=bounced (host mfgw5.ocn.ad.jp[125.206.188.198] said: 554 5.7.1 <[email protected]>: Recipient address rejected: Access denied)
    ...
    Nov 27 15:05:14 mail postfix/qmgr[18780]: 716E612F9D0: to=<[email protected]>, relay=none, delay=77244, status=deferred (Name service error for jrtr.org: Host not found, try again)
    Nov 27 15:05:14 mail postfix/qmgr[18780]: 808E812F9BF: to=<[email protected]>, relay=none, delay=77230, status=deferred (Name service error for jrtr.org: Host not found, try again)


    no fatal errors found

    I just saw that postfix log has around 8000 reject or error lines over 104000
    it means that around 7 percent of postfix logs implies error o reject messages
    I think that this is normal for a postfix with around 150 users


    I don't know what else to do...
    Any suggestion with be very appreciated

    thanks
     
  4. falko

    falko Super Moderator Howtoforge Staff

    Please try
    Code:
    postconf -e 'mydomain = mail.bago.com.bo'
    /etc/init.d/postfix restart
    Also, what's in /etc/resolv.conf?
     
  5. fernando_torrez

    fernando_torrez New Member

    Yesterday I did:
    postconf -e 'mydomain = mail.bago.com.bo'
    /etc/init.d/postfix restart

    same results... it still reject some clients

    this is the my /etc/resolv.conf
    domain bago.com.bo
    nameserver 200.87.100.10
    nameserver 200.87.100.40

    and this is my postfix version:
    postfix-20010228pl03-56

    At around 3 months the ISP changed our public IP and
    I just found that the reverse DNS of the new public IP is not working,
    and There's a Lot of spam that is comming to the mail server lately...

    Is it posible that those problems are crashing the smtp daemons?

    I don't know what else todo


    thanks for help
     
  6. falko

    falko Super Moderator Howtoforge Staff

    That could be the problem. Please ask your ISP to update the reverse DNS.

    If that doesn't help, I'd try two other nameservers in /etc/resolv.conf.
     

Share This Page