for the record, solved off-list on IRC: permission on directories within the queue had been altered.
January 6, 2020 2:19 AM, "jrmu" <j...@ircnow.org> wrote: > Greetings, > > I am running OpenBSD 6.6 GENERIC#3 amd64 and getting an > inexplicable 421 4.3.0 Temporary Error when using > sendmail with opensmtpd. > > Here is my current mail setup: > > Inside bnc3.ircnow.org, I have /etc/mail/smtpd.conf: > > table aliases file:/etc/mail/aliases > table secrets file:/etc/mail/secrets > > listen on lo0 > > action "local_mail" mbox alias <aliases> > action "outbound" relay host smtp+tls://supp...@ircnow.org:587 \ > auth <secrets> > > match for local action "local_mail" > match for any action "outbound" > > Inside /etc/mail/secrets: > > support supp...@ircnow.org:PASSWORD > > I am using ircnow.org as a mail relay. Here is its > /etc/mail/smtpd.conf: > > pki mail.ircnow.org cert "/etc/ssl/ircnow.org.fullchain.pem" > pki mail.ircnow.org key "/etc/ssl/private/ircnow.org.key" > > # tables setup > table aliases file:/etc/mail/aliases > table domains file:/etc/mail/domains > table passwd passwd:/etc/mail/passwd > table virtuals file:/etc/mail/virtuals > table hosts file:/etc/mail/hosts > > listen on lo0 mask-src > listen on lo0 port 10028 tag DKIM mask-src > listen on egress port 25 tls pki mail.ircnow.org mask-src > listen on egress port 587 tls-require pki mail.ircnow.org auth <passwd> > mask-src > action "lmtp" lmtp "/var/dovecot/lmtp" rcpt-to virtual <virtuals> > action "relay" relay > action "relay_dkim" relay host smtp://127.0.0.1:10027 > > match from any for domain <domains> action "lmtp" > match tag DKIM for any action "relay" > match from src <hosts> for any action "relay_dkim" > match auth from any for any action "relay_dkim" > > On bnc3.ircnow.org, I run this command: > > $ /usr/sbin/sendmail -tv -F support -f support < samplemail > > samplemail contains this message: > > From: support <supp...@ircnow.org> > To: u...@example.com > Subject: Welcome to IRCNow! > MIME-Version: 1.0 > Content-Type: text/plain; charset=us-ascii > Content-Disposition: inline > > Welcome to IRCNow! > > When running the above command, I get this output: > > <<< 220 bnc3.ircnow.org ESMTP OpenSMTPD > >> EHLO localhost > > <<< 250-bnc3.ircnow.org Hello localhost [local], pleased to meet you > <<< 250-8BITMIME > <<< 250-ENHANCEDSTATUSCODES > <<< 250-SIZE 36700160 > <<< 250 HELP >> MAIL FROM:<supp...@bnc3.ircnow.org> > > <<< 421 4.3.0 Temporary Error > sendmail: command failed: 421 4.3.0 Temporary Error > > On bnc3.ircnow.org, I see this in /var/log/maillog: > > Jan 3 08:26:27 bnc3 smtpd[]: smtp disconnected reason=quit > Jan 3 08:38:36 bnc3 smtpd[]: smtp connected address=local host=bnc3.ircnow.org > Jan 3 08:38:36 bnc3 smtpd[]: smtp failed-command command="MAIL > FROM:<supp...@bnc3.ircnow.org> " > result="421 4.3.0 Temporary Error" > Jan 3 08:38:36 bnc3 smtpd[]: smtp disconnected reason=quit > > The mail relay (ircnow.org) never even sees the email, since > bnc3.ircnow.org is not sending it. Instead, the mail is discarded. > > I then tried running $ nc localhost 25: > > 220 bnc3.ircnow.org ESMTP OpenSMTPD > ehlo bnc3 > 250-bnc3.ircnow.org Hello bnc3 [127.0.0.1], pleased to meet you > 250-8BITMIME > 250-ENHANCEDSTATUSCODES > 250-SIZE 36700160 > 250-DSN > 250 HELP > mail from: <supp...@ircnow.org> > 421 4.3.0 Temporary Error > > About 50-70% of the time, I get the above message. Could opensmtpd > be greylisting sendmail from localhost? > > I tried enabling debugging: > > # smtpd -dv > > Then, I attempt to use sendmail: > > $ /usr/sbin/sendmail -tv -F support -f support < samplemail > > mta delivery evpid= from=<supp...@bnc3.ircnow.org> to=<u...@example.com> > rcpt=<-> > source="209.141.50.204" relay="209.141.46.110 (mail.ircnow.org)" delay=0s > result="Ok" stat="250 > 2.0.0 Message accepted for delivery" > debug: mta: : no task for relay > [relay:ircnow.org,port=587,smtp+tls,auth=secrets:support,mx] > mta: debug: last connection: hanging on for 10s > debug: mta: flush for (-> u...@example.com) > debug: mta: ... timeout for > [relay:ircnow.org,port=587,smtp+tls,auth=secrets:support,mx] > debug: mta: draining > [relay:ircnow.org,port=587,smtp+tls,auth=secrets:support,mx] refcount=2, > ntask=0, nconnector=1, nconn=1 > debug: mta: all done for > [relay:ircnow.org,port=587,smtp+tls,auth=secrets:support,mx] > smtp connected address=local host=bnc3.ircnow.org smtp failed-command > command="MAIL > FROM:<supp...@bnc3.ircnow.org> " result="421 4.3.0 Temporary Error" > smtp disconnected reason=quit > debug: control -> client: pipe closed > debug: clearing p=client, fd=11, pid=0 > mta: timeout for session hangon > > I tried adding tracing: > > # smtpd -dv -T all > > Then calling: > > $ /usr/sbin/sendmail -tv -F support -f support < samplemail > > mproc: lka -> pony: enabled > debug: smtpd: scanning offline queue... > debug: smtpd: offline scanning done > mproc: control -> client-proc: enabled > ramstat: increment: control.session > ramstat: control.session (0x): 0 -> 1 > mproc: control -> pony : 4 IMSG_CTL_SMTP_SESSION > imsg: pony <- control: IMSG_CTL_SMTP_SESSION (len=4) > smtp: 0x: connected to listener 0x [hostname=bnc3.ircnow.org, port=0, > tag=local] > smtp: 0x: STATE_NEW -> STATE_CONNECTED > smtp connected address=local host=bnc3.ircnow.org > mproc: pony -> lka: realloc 0 -> 128 > mproc: pony -> lka : 86 IMSG_REPORT_SMTP_LINK_CONNECT > smtp: 0: >>> 220 bnc3.ircnow.org ESMTP OpenSMTPD > mproc: pony -> lka : 70 IMSG_REPORT_SMTP_PROTOCOL_SERVER > mproc: pony -> lka : 50 IMSG_??? (128) > mproc: pony -> control: realloc 0 -> 128 > mproc: pony -> control : 46 IMSG_STAT_INCREMENT > mproc: pony -> control : 52 IMSG_STAT_INCREMENT > mproc: pony -> control : 0 IMSG_CTL_SMTP_SESSION > smtp: 0x: IO_LOWAT <io:0x fd=12 to=300000 fl=W ib=0 ob=0> > imsg: lka <- pony: IMSG_REPORT_SMTP_LINK_CONNECT (len=86) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=70) > imsg: control <- pony: IMSG_STAT_INCREMENT (len=46) > imsg: lka <- pony: IMSG_??? (128) (len=50) > ramstat: increment: smtp.session > ramstat: smtp.session (0x): 0 -> 1 > imsg: control <- pony: IMSG_STAT_INCREMENT (len=52) > ramstat: increment: smtp.session.local > ramstat: smtp.session.local (0x): 0 -> 1 > imsg: control <- pony: IMSG_CTL_SMTP_SESSION (len=0, fd=12) > mproc: control -> client-proc : 0 IMSG_CTL_OK > smtp: 0x: IO_DATAIN <io:0x fd=12 to=300000 fl=R ib=15 ob=0> > > smtp: 0x: <<< EHLO localhost > mproc: pony -> lka : 49 IMSG_REPORT_SMTP_PROTOCOL_CLIENT > mproc: pony -> lka : 50 IMSG_??? (129) > smtp: 0x: STATE_CONNECTED -> STATE_HELO > smtp: 0x: >>> 250-bnc3.ircnow.org Hello localhost [local], > pleased to meet you > mproc: pony -> lka : 99 IMSG_REPORT_SMTP_PROTOCOL_SERVER > smtp: 0x: >>> 250-8BITMIME > mproc: pony -> lka : 47 IMSG_REPORT_SMTP_PROTOCOL_SERVER > smtp: 0x: >>> 250-ENHANCEDSTATUSCODES > mproc: pony -> lka : 58 IMSG_REPORT_SMTP_PROTOCOL_SERVER > smtp: 0x: >>> 250-SIZE 36700160 > mproc: pony -> lka : 52 IMSG_REPORT_SMTP_PROTOCOL_SERVER > smtp: 0x: >>> 250 HELP > mproc: pony -> lka : 43 IMSG_REPORT_SMTP_PROTOCOL_SERVER > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_CLIENT (len=49) > imsg: lka <- pony: IMSG_??? (129) (len=50) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=99) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=47) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=58) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=52) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=43) > smtp: 0x: IO_LOWAT <io: fd=12 to=300000 fl=W i > b=0 ob=0> > smtp: 0x: IO_DATAIN <io: fd=12 to=300000 fl=R > ib=38 ob=0> > smtp: 0x: <<< MAIL FROM:<supp...@bnc3.ircnow.org> > mproc: pony -> lka : 72 IMSG_REPORT_SMTP_PROTOCOL_CLIENT > mproc: pony -> queue: realloc 0 -> 128 > mproc: pony -> queue : 8 IMSG_SMTP_MESSAGE_CREATE > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_CLIENT (len=72) > imsg: queue <- pony: IMSG_SMTP_MESSAGE_CREATE (len=8) > queue-backend: queue_message_create() -> 0 (00000000) > mproc: queue -> pony: realloc 0 -> 128 > mproc: queue -> pony : 12 IMSG_SMTP_MESSAGE_CREATE > imsg: pony <- queue: IMSG_SMTP_MESSAGE_CREATE (len=12) > smtp: 0x21f72a63000: >>> 421 4.3.0 Temporary Error > mproc: pony -> lka : 66 IMSG_??? (134) > 430fa6be3663e10f smtp failed-command command="MAIL FROM:<support@bnc3. > ircnow.org> " result="421 4.3.0 Temporary Error" > mproc: pony -> lka : 60 IMSG_REPORT_SMTP_PROTOCOL_SERVER > smtp: 0x: STATE_HELO -> STATE_QUIT > smtp: 0x: IO_LOWAT <io:0x fd=12 to=300000 fl=W i > b=0 ob=0> > smtp disconnected reason=quit > mproc: pony -> lka : 33 IMSG_REPORT_SMTP_LINK_DISCONNECT > mproc: pony -> control : 46 IMSG_STAT_DECREMENT > imsg: lka <- pony: IMSG_??? (134) (len=66) > imsg: lka <- pony: IMSG_REPORT_SMTP_PROTOCOL_SERVER (len=60) > imsg: lka <- pony: IMSG_REPORT_SMTP_LINK_DISCONNECT (len=33) > debug: control -> client: pipe closed > debug: clearing p=client, fd=11, pid=0 > > ramstat: decrement: control.session > ramstat: control.session (0xd): 1 -> 0 > imsg: control <- pony: IMSG_STAT_DECREMENT (len=46) > ramstat: decrement: smtp.session > ramstat: smtp.session (0x): 1 -> 0 > > I wonder if perhaps there are corrupt data files somewhere, but > I'm also getting a similar 421 4.3.0 Temporary error on a 2nd > OpenBSD 6.6 box I am running. > > Any clues about what is causing the error?
