Re: Can't deliver messages: connection closed unexpectedly
Il 29/09/2014 21:46, Gilles Chehade ha scritto: In this case, we detect that the first MX was broken and try to pass to the next MX before reporting a failure on the message. However, we also forget to log th reason why the first MX was broken. This is a bug, not a feature, a ticket has just been opened: https://github.com/OpenSMTPD/OpenSMTPD/issues/483 Dear Gilles, good to know about it. Thank you for your work, Fabio -- You received this mail because you are subscribed to misc@opensmtpd.org To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org
Re: Can't deliver messages: connection closed unexpectedly
On Thu, Aug 21, 2014 at 11:13:44PM +0200, Fabio Riga wrote: Il 21/08/2014 22:38, Giovanni Bechis ha scritto: try this one: # /etc/rc.d/smtpd stop smtpd -dv # smtpctl trace smtp Post your logs. Anyway I tried from my smtpd server (~OpenBSD 5.6) and it is working fine. Cheers Giovanni Dear Giovanni, thanks for your help. I found the solution trying to connect to a mx server via telnet (from my server) and this is the result: [fabio@mail ~]$ telnet mxd1.aruba.it 25 Trying 62.149.128.160... Connected to mxd1.aruba.it. Escape character is '^]'. 554 mxcmd04.ad.aruba.it bizsmtp hYzf1o0274Aa5Bp01 Connection refused from 149.210.142.193. See http://csi.cloudmark.com/reset-request/?ip=149.210.142.193 for more information. Connection closed by foreign host. So my server is blacklisted by this cloudmark, I just sent the reset request and hopefully I'll resolve the problem. Anyway, openSMTPd didn't report this. Another blacklist system was blocking me some time ago and was reported in the log. I don't understand why this wasn't found. Cheers, Fabio ehlo, The reason is simple and not what you guys think. The MTA has a logic that it tries to find a MX where it can establish a valid session (go beyond EHLO) otherwise it considers the host broken and passes to the next MX. In this case, we detect that the first MX was broken and try to pass to the next MX before reporting a failure on the message. However, we also forget to log th reason why the first MX was broken. This is a bug, not a feature, a ticket has just been opened: https://github.com/OpenSMTPD/OpenSMTPD/issues/483 -- Gilles Chehade https://www.poolp.org @poolpOrg -- You received this mail because you are subscribed to misc@opensmtpd.org To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org
Can't deliver messages: connection closed unexpectedly
Hi list, I run an OpenBSD 5.5 server on a VPS with OpenSMTPd. I get the message Connection closed unexpectedly and a TempFail for every message sent to every domain of a very big Italian ISP. The TempFail last 4 days, then the message expires. I don't know if the laconic message is an OpenSMTPd issue or a ISP one, but maybe somebody has a clue of the possible causes. I tryed as well to ask to the ISP, maybe I'll get an answer... Here it is a part of maillog: Aug 21 14:10:54 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.160:25 (mxd1.aruba.it) on session 8315c24701be60d4... Aug 21 14:10:54 mail smtpd[2917]: smtp-out: Connected on session 8315c24701be60d4 Aug 21 14:10:55 mail smtpd[2917]: smtp-out: Error on session 8315c24701be60d4: Connection closed unexpectedly Aug 21 14:10:55 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.160 (mxd1.aruba.it) for 800s Aug 21 14:10:56 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.72:25 (mxd4.aruba.it) on session 8315c2487e80cbb2... Aug 21 14:10:56 mail smtpd[2917]: smtp-out: Connected on session 8315c2487e80cbb2 Aug 21 14:10:57 mail smtpd[2917]: smtp-out: Error on session 8315c2487e80cbb2: Connection closed unexpectedly Aug 21 14:10:57 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.72 (mxd4.aruba.it) for 800s Aug 21 14:10:58 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.166:25 (mxd3.aruba.it) on session 8315c249622d1e9c... Aug 21 14:10:58 mail smtpd[2917]: smtp-out: Connected on session 8315c249622d1e9c Aug 21 14:10:59 mail smtpd[2917]: smtp-out: Error on session 8315c249622d1e9c: Connection closed unexpectedly Aug 21 14:10:59 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.166 (mxd3.aruba.it) for 800s Aug 21 14:11:01 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.151:25 (mxavas.aruba.it) on session 8315c24a7b46d1c9... Aug 21 14:11:01 mail smtpd[2917]: smtp-out: Connected on session 8315c24a7b46d1c9 Aug 21 14:11:02 mail smtpd[2917]: smtp-out: Error on session 8315c24a7b46d1c9: Conne ction closed unexpectedly Aug 21 14:11:02 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.151 (mxavas.aruba.it) for 800s Aug 21 14:11:02 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.163:25 (mxd2.aruba.it) on session 8315c24b88bb1b06... Aug 21 14:11:02 mail smtpd[2917]: smtp-out: Connected on session 8315c24b88bb1b06 Aug 21 14:11:03 mail smtpd[2917]: smtp-out: Error on session 8315c24b88bb1b06: Connection closed unexpectedly Aug 21 14:11:03 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.163 (mxd2.aruba.it) for 800s Aug 21 14:11:04 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.157:25 (mxd8.aruba.it) on session 8315c24c811cee27... Aug 21 14:11:04 mail smtpd[2917]: smtp-out: Connected on session 8315c24c811cee27 Aug 21 14:11:05 mail smtpd[2917]: smtp-out: Error on session 8315c24c811cee27: Connection closed unexpectedly Aug 21 14:11:05 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.157 (mxd8.aruba.it) for 800s Aug 21 14:11:06 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.74:25 (mxd5.aruba.it) on session 8315c24d41fd3581... Aug 21 14:11:06 mail smtpd[2917]: smtp-out: Connected on session 8315c24d41fd3581 Aug 21 14:11:07 mail smtpd[2917]: smtp-out: Error on session 8315c24d41fd3581: Connection closed unexpectedly Aug 21 14:11:07 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.74 (mxd5.aruba.it) for 800s Aug 21 14:11:08 mail smtpd[2917]: smtp-out: Connecting to smtp+tls://62.149.128.154:25 (mxd7.aruba.it) on session 8315c24ed35dce6f... Aug 21 14:11:08 mail smtpd[2917]: smtp-out: Connected on session 8315c24ed35dce6f Aug 21 14:11:09 mail smtpd[2917]: smtp-out: Error on session 8315c24ed35dce6f: Connection closed unexpectedly Aug 21 14:11:09 mail smtpd[2917]: smtp-out: Disabling route [] - 62.149.128.154 (mxd7.aruba.it) for 800s Aug 21 14:11:10 mail smtpd[2917]: smtp-out: No valid route for [connector:[]-[relay:x.it],0x0] Aug 21 14:11:15 mail smtpd[2917]: relay: TempFail for cca1f6fbb1727b93: session=, from=x...@xxx.xxx, to=x...@x.it, rcpt=-, source=-, relay=x.it, delay=1d20h27m1s, stat=Network error on destination MXs Thank for your help. Fabio -- You received this mail because you are subscribed to misc@opensmtpd.org To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org
Re: Can't deliver messages: connection closed unexpectedly
On 08/21/14 15:59, Fabio Riga wrote: Hi list, I run an OpenBSD 5.5 server on a VPS with OpenSMTPd. I get the message Connection closed unexpectedly and a TempFail for every message sent to every domain of a very big Italian ISP. The TempFail last 4 days, then the message expires. I don't know if the laconic message is an OpenSMTPd issue or a ISP one, but maybe somebody has a clue of the possible causes. I tryed as well to ask to the ISP, maybe I'll get an answer... Here it is a part of maillog: I think it could a network problem on their side, from Italy (OpenBSD 5.6) I cannot deliver (see log file), from outside Italy there are no problems. Cheers Giovanni Script started on Thu Aug 21 17:28:16 2014 $ sm sudo smtpd -dv debug: init ssl-tree info: OpenSMTPD 5.4.3 starting debug: bounce warning after 4h debug: using fs queue backend debug: using ramqueue scheduler backend debug: using ram stat backend info: startup [debug mode] debug: parent_send_config_ruleset: reloading debug: parent_send_config: configuring pony process debug: parent_send_config: configuring ca process debug: init ssl-tree debug: ca_engine_init: using RSAX engine support debug: smtp: listen on 127.0.0.1 port 25 flags 0x400 pki debug: smtp: listen on IPv6:fe80::1%lo0 port 25 flags 0x400 pki debug: smtp: listen on IPv6:::1 port 25 flags 0x400 pki debug: smtp: will accept at most 2037 clients debug: init private ssl-tree debug: queue: done loading queue into scheduler debug: smtpd: scanning offline queue... debug: smtpd: offline scanning done debug: smtp: new client on listener: 0x4536b769300 smtp: 0x4565257e000: STATE_NEW - STATE_CONNECTED smtp-in: New session aa25a6d9509a520a from host 1000@localhost [local] smtp: 0x4565257e000: 220 localhost ESMTP OpenSMTPD smtp: 0x4565257e000: EHLO localhost smtp: 0x4565257e000: STATE_CONNECTED - STATE_HELO smtp: 0x4565257e000: 250-localhost Hello localhost [local], pleased to meet you smtp: 0x4565257e000: 250-8BITMIME smtp: 0x4565257e000: 250-ENHANCEDSTATUSCODES smtp: 0x4565257e000: 250-SIZE 36700160 smtp: 0x4565257e000: 250 HELP smtp: 0x4565257e000: MAIL FROM:giova...@bigio.paclan.it smtp: 0x4565257e000: 250 2.0.0: Ok smtp: 0x4565257e000: RCPT TO:t...@staff.aruba.it smtp: 0x4565257e000: 250 2.1.5 Destination address valid: Recipient ok smtp: 0x4565257e000: DATA smtp: 0x4565257e000: STATE_HELO - STATE_BODY smtp: 0x4565257e000: 354 Enter mail, end with . on a line by itself [MSG] From: Giovanni Bechis giova...@bigio.paclan.it [MSG] Date: Thu, 21 Aug 2014 17:28:35 +0200 (CEST) [MSG] Message-Id: 5588509546345635123.enqu...@bigio.paclan.it [MSG] To: t...@staff.aruba.it [MSG] Subject: test [MSG] [MSG] test debug: 0x4565257e000: end of message, msgflags=0x smtp: 0x4565257e000: 250 2.0.0: e8eb560f Message accepted for delivery smtp-in: Accepted message e8eb560f on session aa25a6d9509a520a: from=giova...@bigio.paclan.it, to=t...@staff.aruba.it, size=196, ndest=1, proto=ESMTP debug: scheduler: evp:e8eb560f60257862 scheduled (mta) smtp: 0x4565257e000: STATE_BODY - STATE_HELO smtp: 0x4565257e000: QUIT smtp: 0x4565257e000: 221 2.0.0: Bye smtp: 0x4565257e000: STATE_HELO - STATE_QUIT smtp-in: Closing session aa25a6d9509a520a debug: smtp: 0x4565257e000: deleting session: done debug: mta: received evp:e8eb560f60257862 for t...@staff.aruba.it debug: mta: draining [relay:staff.aruba.it] refcount=1, ntask=1, nconnector=0, nconn=0 debug: mta: querying MX for [relay:staff.aruba.it]... debug: mta: [relay:staff.aruba.it] waiting for MX debug: MXs for domain staff.aruba.it: 62.149.157.49 preference 10 debug: mta: ... got mx (0x45611e38220, staff.aruba.it, [relay:staff.aruba.it]) debug: mta: draining [relay:staff.aruba.it] refcount=1, ntask=1, nconnector=0, nconn=0 debug: mta: querying source for [relay:staff.aruba.it]... debug: mta: ... got source for [relay:staff.aruba.it]: [] debug: mta: new [connector:[]-[relay:staff.aruba.it],0x1] debug: mta: connecting with [connector:[]-[relay:staff.aruba.it],0x0] debug: mta-routing: searching new route for [connector:[]-[relay:staff.aruba.it],0x0]... debug: mta-routing: selecting candidate route [] - 62.149.157.49 debug: mta-routing: spawning new connection on [] - 62.149.157.49 debug: mta: 0x45666484000: spawned for relay [relay:staff.aruba.it] debug: mta: connecting with [connector:[]-[relay:staff.aruba.it],0x0] debug: mta: cannot use [relay:staff.aruba.it] before 2s debug: mta-routing: no route available for [connector:[]-[relay:staff.aruba.it],0x0]: must wait a bit debug: mta: retrying to connect on [connector:[]-[relay:staff.aruba.it],0x0] in 2s... debug: mta: draining [relay:staff.aruba.it] refcount=3, ntask=1, nconnector=1, nconn=1 debug: mta: scheduling relay [relay:staff.aruba.it] in 1s... smtp-out: Connecting to smtp+tls://62.149.157.49:25 (staff.aruba.it) on session aa25a6dc79081475... smtp-out: Connected on session aa25a6dc79081475 debug: mta: ... timeout for [relay:staff.aruba.it] debug: mta: draining
Re: Can't deliver messages: connection closed unexpectedly
On 08/21/14 17:33, Giovanni Bechis wrote: On 08/21/14 15:59, Fabio Riga wrote: Hi list, I run an OpenBSD 5.5 server on a VPS with OpenSMTPd. I get the message Connection closed unexpectedly and a TempFail for every message sent to every domain of a very big Italian ISP. The TempFail last 4 days, then the message expires. I don't know if the laconic message is an OpenSMTPd issue or a ISP one, but maybe somebody has a clue of the possible causes. I tryed as well to ask to the ISP, maybe I'll get an answer... Here it is a part of maillog: I think it could a network problem on their side, from Italy (OpenBSD 5.6) I cannot deliver (see log file), from outside Italy there are no problems. Cheers Giovanni Discard the message, my connection is in Spamhaus, from outside Italy I can confirm I can deliver to aruba.it. Cheers Giovanni -- You received this mail because you are subscribed to misc@opensmtpd.org To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org
Re: Can't deliver messages: connection closed unexpectedly
Il 21/08/2014 17:37, Giovanni Bechis ha scritto: On 08/21/14 17:33, Giovanni Bechis wrote: On 08/21/14 15:59, Fabio Riga wrote: Hi list, I run an OpenBSD 5.5 server on a VPS with OpenSMTPd. I get the message Connection closed unexpectedly and a TempFail for every message sent to every domain of a very big Italian ISP. The TempFail last 4 days, then the message expires. I don't know if the laconic message is an OpenSMTPd issue or a ISP one, but maybe somebody has a clue of the possible causes. I tryed as well to ask to the ISP, maybe I'll get an answer... Here it is a part of maillog: I think it could a network problem on their side, from Italy (OpenBSD 5.6) I cannot deliver (see log file), from outside Italy there are no problems. Cheers Giovanni Discard the message, my connection is in Spamhaus, from outside Italy I can confirm I can deliver to aruba.it. Cheers Giovanni Actually my VPS is in Netherlands. I tryed t...@staff.aruba.it and I can deliver to it. What I can't do is deliver to a domain that use Aruba's MXs. I attach the debug output: I think the relevant part is disconnected in state MTA_EHLO. Thanks for your time. Fabio debug: mta: received evp:cca1f6fbb1727b93 for u...@xdomain.it debug: mta: draining [relay:xdomain.it] refcount=1, ntask=1, nconnector=0, nconn=0 debug: mta: querying MX for [relay:xdomain.it]... debug: mta: [relay:xdomain.it] waiting for MX debug: MXs for domain xdomain.it: 62.149.128.72 preference 10 62.149.128.163 preference 10 62.149.128.151 preference 10 62.149.128.154 preference 10 62.149.128.157 preference 10 62.149.128.160 preference 10 62.149.128.166 preference 10 62.149.128.74 preference 10 debug: mta: ... got mx (0x1f94f23b5ea0, xdomain.it, [relay:xdomain.it]) debug: mta: draining [relay:xdomain.it] refcount=1, ntask=1, nconnector=0, nconn=0 debug: mta: querying source for [relay:xdomain.it]... debug: mta: ... got source for [relay:xdomain.it]: [] debug: mta: new [connector:[]-[relay:xdomain.it],0x1] debug: mta: connecting with [connector:[]-[relay:xdomain.it],0x0] debug: mta-routing: searching new route for [connector:[]-[relay:xdomain.it],0x0]... debug: mta-routing: selecting candidate route [] - 62.149.128.72 debug: mta-routing: skipping route [] - 62.149.128.163: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.163 debug: mta-routing: skipping route [] - 62.149.128.151: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.151 debug: mta-routing: skipping route [] - 62.149.128.154: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.154 debug: mta-routing: skipping route [] - 62.149.128.157: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.157 debug: mta-routing: skipping route [] - 62.149.128.160: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.160 debug: mta-routing: skipping route [] - 62.149.128.166: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.166 debug: mta-routing: skipping route [] - 62.149.128.74: current one is better debug: mta: ma_route_unref(): really discarding route [] - 62.149.128.74 debug: mta-routing: spawning new connection on [] - 62.149.128.72 debug: mta: 0x1f94fc3dcc00: spawned for relay [relay:xdomain.it] debug: mta: connecting with [connector:[]-[relay:xdomain.it],0x0] debug: mta: cannot use [relay:xdomain.it] before 2s debug: mta-routing: no route available for [connector:[]-[relay:xdomain.it],0x0]: must wait a bit debug: mta: retrying to connect on [connector:[]-[relay:xdomain.it],0x0] in 2s... debug: mta: draining [relay:xdomain.it] refcount=3, ntask=1, nconnector=1, nconn=1 debug: mta: scheduling relay [relay:xdomain.it] in 1s... smtp-out: Connecting to smtp+tls://62.149.128.72:25 (mxd4.aruba.it) on session 11b87f1b4c145f51... smtp-out: Connected on session 11b87f1b4c145f51 debug: mta: ... timeout for [relay:xdomain.it] debug: mta: draining [relay:xdomain.it] refcount=2, ntask=1, nconnector=1, nconn=1 debug: mta: querying source for [relay:xdomain.it]... debug: mta: ... got source for [relay:xdomain.it]: [] debug: mta: connecting with [connector:[]-[relay:xdomain.it],0x2] debug: mta: canceling connector timeout debug: mta: cannot use [relay:xdomain.it] before 1s debug: mta-routing: no route available for [connector:[]-[relay:xdomain.it],0x2]: must wait a bit debug: mta: retrying to connect on [connector:[]-[relay:xdomain.it],0x2] in 1s... debug: mta: draining [relay:xdomain.it] refcount=3, ntask=1, nconnector=1, nconn=1 debug: mta: scheduling relay [relay:xdomain.it] in 10s... debug: mta: 0x1f94fc3dcc00: disconnected in state MTA_EHLO smtp-out:
Re: Can't deliver messages: connection closed unexpectedly
Il 21/08/2014 23:32, Giovanni Bechis ha scritto: On 08/21/14 23:30, Fabio Riga wrote: Il 21/08/2014 23:18, Giovanni Bechis ha scritto: Is the cloudmark line in your log splitted in two lines ? If it is true this could be why it is not logged: https://github.com/OpenSMTPD/OpenSMTPD/issues/365 Cheers Giovanni No, it isn't. It's one line and it isn't in the log file. Only telnet reported this. Fabio when you connect with telnet is the line splitted ? if it is true the line will not be logged by smtpd. Cheers Giovanni It is one line, and IMHO it should be reported by smtpd. Fabio -- You received this mail because you are subscribed to misc@opensmtpd.org To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org
