On Sat, Mar 5, 2011 at 4:06 PM, Reindl Harald <h.rei...@thelounge.net> wrote: > Am 05.03.2011 16:02, schrieb Andy: >> Hi all. >> Since yesterday we are having major issues with our outbound relay, >> mostly with Hotmail/Live servers. Gmail & others seems to work fine. >> I updated postfix to the latest squeeze version and turned on debugging: >> >> >> Mar 5 14:43:11 out postfix/smtp[19842]: name_mask: resource >> Mar 5 14:43:11 out postfix/smtp[19842]: name_mask: software >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_buf_get_ready: fd 12 got 310 >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 220 BAY0-MC2-F32.Bay0.hotmail.com >> Sending unsolicited commercial or bulk e-mail to Microsoft's compu >> Mar 5 14:43:12 out postfix/smtp[19842]: > >> mx1.hotmail.com[65.54.188.94]:25: EHLO out.vp44.net >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_fflush_some: fd 12 flush 19 >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_buf_get_ready: fd 12 got 189 >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-BAY0-MC2-F32.Bay0.hotmail.com >> (3.12.0.56) Hello [178.238.138.56] >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-SIZE 36909875 >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-PIPELINING >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-8bitmime >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-BINARYMIME >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-CHUNKING >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-AUTH LOGIN >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250-AUTH=LOGIN >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250 OK >> Mar 5 14:43:12 out postfix/smtp[19842]: server features: 0x100f size >> 36909875 >> Mar 5 14:43:12 out postfix/smtp[19842]: Using ESMTP PIPELINING, TCP >> send buffer size is 4096 >> Mar 5 14:43:12 out postfix/smtp[19842]: > >> mx1.hotmail.com[65.54.188.94]:25: MAIL FROM:<u...@vp44.net> SIZE=2178 >> Mar 5 14:43:12 out postfix/smtp[19842]: > >> mx1.hotmail.com[65.54.188.94]:25: RCPT TO:<u...@hotmail.com> >> Mar 5 14:43:12 out postfix/smtp[19842]: > >> mx1.hotmail.com[65.54.188.94]:25: DATA >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_fflush_some: fd 12 flush 86 >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_buf_get_ready: fd 12 got 33 >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250 u...@vp44.net....Sender OK >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_buf_get_ready: fd 12 got 37 >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 250 u...@hotmail.com >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_buf_get_ready: fd 12 got 46 >> Mar 5 14:43:12 out postfix/smtp[19842]: < >> mx1.hotmail.com[65.54.188.94]:25: 354 Start mail input; end with >> <CRLF>.<CRLF> >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_buf_get_ready: fd 11 got >> 2182 >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 55 data >> Received: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 52 data ?by >> out.vp >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 76 data ?for >> <skor >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 69 data >> DKIM-Signa >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 55 data >> ?:reply-to >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data >> ?:content- >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data ?dQ=; >> b=GM >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data >> ?uYGjZ12iw >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 52 data >> ?ajZOMbrqm >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 69 data >> DomainKey- >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 55 data >> ?:reply-to >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data >> ?:content- >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data >> ?jwPkuIjE4 >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data >> ?ikGtx65I5 >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 26 data >> ?C29xfMA7F >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 61 data >> Received: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 52 data ?by >> out.vp >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 76 data ?for >> <skor >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 48 data >> Received: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 53 data ?by >> mail.v >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 76 data ?for >> <skor >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 48 data >> X-Virus-Sc >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 42 data >> Received: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 67 data ?by >> localh >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 65 data ?with >> ESMT >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 38 data ?Sat, >> 5 M >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 101 data >> Received: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 39 data >> ?(Authenti >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 54 data ?by >> mail.v >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 76 data ?for >> <skor >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 13 data >> Subject: t >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 28 data From: >> Art >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 24 data >> Reply-To: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 34 data To: >> skorpi >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 24 data >> Content-Ty >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 37 data Date: >> Sat, >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 54 data >> Message-ID >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 17 data >> Mime-Versi >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 27 data >> X-Mailer: >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 31 data >> Content-Tr >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 0 data >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 4 data test >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 0 data >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 0 data >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type N len 0 data >> Mar 5 14:43:12 out postfix/smtp[19842]: rec_get: type X len 0 data >> Mar 5 14:43:12 out postfix/smtp[19842]: > mx1.hotmail.com[65.54.188.94]:25: >> . >> Mar 5 14:43:12 out postfix/smtp[19842]: > >> mx1.hotmail.com[65.54.188.94]:25: QUIT >> Mar 5 14:43:12 out postfix/smtp[19842]: vstream_fflush_some: fd 12 flush >> 2187 >> Mar 5 14:44:23 out postfix/smtp[19842]: smtp_get: EOF >> Mar 5 14:44:23 out postfix/smtp[19842]: connect to subsystem private/defer >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr nrequest = 0 >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr flags = 0 >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr queue_id = BEB85788451 >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr original_recipient >> = u...@hotmail.com >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr recipient = >> u...@hotmail.com >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr offset = 617 >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr dsn_orig_rcpt = >> rfc822;u...@hotmail.com >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr notify_flags = 0 >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr status = 4.4.2 >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr diag_type = >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr diag_text = >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr mta_type = >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr mta_mname = >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr action = delayed >> Mar 5 14:44:23 out postfix/smtp[19842]: send attr reason = lost >> connection with mx1.hotmail.com[65.54.188.94] while sending end of >> data -- message may be sent more than once >> Mar 5 14:44:23 out postfix/smtp[19842]: vstream_fflush_some: fd 13 flush 403 >> Mar 5 14:44:23 out postfix/smtp[19842]: vstream_buf_get_ready: fd 13 got 10 >> Mar 5 14:44:23 out postfix/smtp[19842]: private/defer socket: wanted >> attribute: status >> Mar 5 14:44:23 out postfix/smtp[19842]: input attribute name: status >> Mar 5 14:44:23 out postfix/smtp[19842]: input attribute value: 0 >> Mar 5 14:44:23 out postfix/smtp[19842]: private/defer socket: wanted >> attribute: (list terminator) >> Mar 5 14:44:23 out postfix/smtp[19842]: input attribute name: (end) >> Mar 5 14:44:23 out postfix/smtp[19842]: BEB85788451: >> to=<u...@hotmail.com>, relay=mx1.hotmail.com[65.54.188.94]:25, >> delay=132, delays=0.1/0/60/71, dsn=4.4.2, status=deferred (lost >> connection with mx1.hotmail.com[65.54.188.94] while sending end of >> data -- message may be sent more than once) >> Mar 5 14:44:23 out postfix/smtp[19842]: flush_add: site hotmail.com >> id BEB85788451 >> Mar 5 14:44:23 out postfix/smtp[19842]: match_hostname: hotmail.com >> ~? out.vp44.net >> Mar 5 14:44:23 out postfix/smtp[19842]: match_hostname: hotmail.com >> ~? localhost.vp44.net >> Mar 5 14:44:23 out postfix/smtp[19842]: match_hostname: hotmail.com >> ~? localhost >> Mar 5 14:44:23 out postfix/smtp[19842]: match_list_match: hotmail.com: no >> match >> Mar 5 14:44:23 out postfix/smtp[19842]: flush_add: site hotmail.com >> id BEB85788451 status 4 >> >> >> Where should I start looking for the cause of this problem? >> >> Andy >
> Why in the world do you start with a debug-log instead a normal > one with filtered where you see a problem? Because I already went through those. The outbound server has been working perfectly for more than a year with the same configuration, nothing was ever changed. This problem appeared within the last 72hrs and I'm suspecting dropped packets or some new kind of restriction on their side - also, it's working as it should with any other provider.. > >> mx1.hotmail.com[65.54.188.94]:25: 220 BAY0-MC2-F32.Bay0.hotmail.com >> Sending unsolicited commercial or bulk e-mail to Microsoft's compu > > sounds like hotmail is pissed off about to many mails from your server > I don't think so, if that was the case they'd have closed the connection immediately. And that's their default SMTP banner.. Andy
