Hi,
Running 3.8 on FreeBSD 14, with postfixadmin 3.4.
I'm trying to send a message and got this bounce message.
<gid...@secluded.site>: host mx.nixnet.email[5.161.67.119] said: 530 5.7.0
Must issue a STARTTLS command first (in reply to MAIL FROM command)
The default maillog is not any more helpful.
Feb 15 14:52:05 mail postfix/smtp[71197]: 3C900C012: to=<gid...@secluded.site>,
relay=mx.
nixnet.email[5.161.67.119]:25, delay=0.56, delays=0.12/0.01/0.37/0.06,
dsn=5.7.0, status=
bounced (host mx.nixnet.email[5.161.67.119] said: 530 5.7.0 Must issue a
STARTTLS command first (in reply to MAIL FROM command))
It seems to be saying that I'm not even trying STARTTLS? My
understanding was that smtpd_tls_security_level=may would enable
opportunistic STARTTLS if present, but that doesn't seem to be
happening? Out-of-band communication with the other site shows I
disconnect and immediately hang up.
Any suggestions on how to debug this? postfinger and debug log
below. (I *think* the debug log includes only this session, but tried
to err on the side of including stuff.)
Thanks,
==ml
postfinger - postfix configuration on Thu Feb 15 18:18:02 EST 2024
version: 1.30
Warning: postfinger output may show private configuration information,
such as ip addresses and/or domain names which you do not want to show
to the public. If this is the case it is your responsibility to modify
the output to hide this private information. [Remove this warning with
the --nowarn option.]
--System Parameters--
mail_version = 3.8.4
hostname = mail.ratoperatedvehicle.com
uname = FreeBSD mail.ratoperatedvehicle.com 14.0-RELEASE-p5 FreeBSD
14.0-RELEASE-p5 #0: Tue Feb 13 23:37:36 UTC 2024
r...@amd64-builder.daemonology.net:/usr/obj/usr/src/amd64.amd64/sys/GENERIC
amd64
--Packaging information--
--main.cf non-default parameters--
compatibility_level = 3.7
debug_peer_list = 5.161.67.119
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd
$daemon_directory/$process_name $process_id & sleep 5
home_mailbox = Maildir/
mailbox_command = /usr/local/libexec/dovecot/dovecot-lda -f "$SENDER" -a
"$RECIPIENT"
mynetworks = hash:/etc/postfix/relay-clients.cidr
postscreen_access_list = permit_mynetworks,
cidr:/etc/postfix/postscreen_spf_allowlist.cidr
postscreen_bare_newline_enable = yes
postscreen_dnsbl_action = drop
postscreen_dnsbl_sites = zen.spamhaus.org*2 all.spamrats.com dnsbl.sorbs.net
postscreen_dnsbl_threshold = 2
postscreen_forbidden_commands = yes
postscreen_greet_action = drop
postscreen_pipelining_enable = yes
smtp_tls_CApath = /etc/ssl/certs
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain = $myhostname
smtpd_sasl_path = private/dovecot-sasl
smtpd_sender_login_maps = $virtual_alias_maps
smtpd_sender_restrictions = hash:/etc/postfix/bad-domains
smtpd_tls_chain_files = /etc/certs/mail.ratoperatedvehicle.com/privkey.pem,
/etc/certs/mail.ratoperatedvehicle.com/fullchain.pem
smtpd_tls_ciphers = high
smtpd_tls_mandatory_ciphers = high
smtpd_tls_mandatory_protocols = $smtpd_tls_protocols
smtpd_tls_protocols = >=TLSv1.2
smtpd_tls_security_level = may
transport_maps = hash:/etc/postfix/transport
virtual_alias_maps = proxy:mysql:/etc/postfix/sql/mysql_virtual_alias_maps.cf,
proxy:mysql:/etc/postfix/sql/mysql_virtual_alias_domain_maps.cf,
proxy:mysql:/etc/postfix/sql/mysql_virtual_alias_domain_catchall_maps.cf
virtual_gid_maps = static:5000
virtual_mailbox_base = /vhosts
virtual_mailbox_domains =
proxy:mysql:/etc/postfix/sql/mysql_virtual_domains_maps.cf
virtual_mailbox_maps =
proxy:mysql:/etc/postfix/sql/mysql_virtual_mailbox_maps.cf,
proxy:mysql:/etc/postfix/sql/mysql_virtual_alias_domain_mailbox_maps.cf
virtual_minimum_uid = 1000
virtual_transport = lmtp:unix:private/dovecot-lmtp
virtual_uid_maps = static:5000
--master.cf--
smtp inet n - n - 1 postscreen
smtpd pass - - n - - smtpd
-o
smtpd_milters=unix:/var/run/pyspf-milter/pyspf-milter.sock,unix:/var/run/opendkim/opendkim.sock,inet:localhost:11332
dnsblog unix - - n - 0 dnsblog
tlsproxy unix - - n - 0 tlsproxy
pickup unix n - n 60 1 pickup
cleanup unix n - n - 0 cleanup
qmgr unix n - n 300 1 qmgr
tlsmgr unix - - n 1000? 1 tlsmgr
rewrite unix - - n - - trivial-rewrite
bounce unix - - n - 0 bounce
defer unix - - n - 0 bounce
trace unix - - n - 0 bounce
verify unix - - n - 1 verify
flush unix n - n 1000? 0 flush
proxymap unix - - n - - proxymap
proxywrite unix - - n - 1 proxymap
smtp unix - - n - - smtp
relay unix - - n - - smtp
-o syslog_name=postfix/$service_name
showq unix n - n - - showq
error unix - - n - - error
retry unix - - n - - error
discard unix - - n - - discard
local unix - n n - - local
virtual unix - n n - - virtual
lmtp unix - - n - - lmtp
anvil unix - - n - 1 anvil
scache unix - - n - 1 scache
postlog unix-dgram n - n - 1 postlogd
submission inet n - n - - smtpd
-o smtpd_tls_security_level=encrypt
-o smtpd_sasl_auth_enable=yes
-o
smtpd_client_restrictions=permit_mynetworks,permit_sasl_authenticated,reject
-o smtpd_sender_restrictions=reject_sender_login_mismatch
-o
smtpd_recipient_restrictions=reject_non_fqdn_recipient,reject_unknown_recipient_domain,permit_sasl_authenticated,reject
-o smtpd_milters=unix:/var/run/opendkim/opendkim.sock
trickle unix - - n - - smtp
-o syslog_name=postfix-trickle
-o trickle_destination_concurrency_limit=1
-o trickle_destination_rate_delay=1m
-o trickle_destination_recipient_limit=5
-o trickle_destination_concurrency_failed_cohort_limit=10
-- end of postfinger output --
debug_peer log:
Feb 15 18:14:53 mail postfix/qmgr[45613]: 49EC181FB: from=<m...@mwl.io>,
size=817, nrcpt=1 (queue active)
Feb 15 18:14:53 mail postfix/smtp[52971]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
220 mx.nixnet.email ESMTP Postfix (Debian/GNU)
Feb 15 18:14:53 mail postfix/smtp[52971]: > mx.nixnet.email[5.161.67.119]:25:
EHLO mail.ratoperatedvehicle.com
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-mx.nixnet.email
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-PIPELINING
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-SIZE 10240000
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-VRFY
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-ETRN
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-STARTTLS
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-ENHANCEDSTATUSCODES
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-8BITMIME
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-DSN
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250-SMTPUTF8
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
250 CHUNKING
Feb 15 18:14:53 mail postfix/smtp[52971]: server features: 0x20901f size
10240000
Feb 15 18:14:53 mail postfix/smtp[52971]: Using ESMTP PIPELINING, TCP send
buffer size is 33580, PIPELINING buffer size is 4096
Feb 15 18:14:53 mail postfix/smtp[52971]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
Feb 15 18:14:53 mail postfix/smtp[52971]: > mx.nixnet.email[5.161.67.119]:25:
MAIL FROM:<m...@mwl.io> SIZE=817
Feb 15 18:14:53 mail postfix/smtp[52971]: > mx.nixnet.email[5.161.67.119]:25:
RCPT TO:<gid...@secluded.site> ORCPT=rfc822;gid...@secluded.site
Feb 15 18:14:53 mail postfix/smtp[52971]: > mx.nixnet.email[5.161.67.119]:25:
DATA
Feb 15 18:14:53 mail postfix/smtp[52971]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
530 5.7.0 Must issue a STARTTLS command first
Feb 15 18:14:53 mail postfix/smtp[52971]: connect to subsystem private/bounce
Feb 15 18:14:53 mail postfix/smtp[52971]: private/bounce socket: wanted
attribute: protocol
Feb 15 18:14:53 mail postfix/smtp[52971]: input attribute name: protocol
Feb 15 18:14:53 mail postfix/smtp[52971]: input attribute value:
delivery_status_protocol
Feb 15 18:14:53 mail postfix/smtp[52971]: private/bounce socket: wanted
attribute: (list terminator)
Feb 15 18:14:53 mail postfix/smtp[52971]: input attribute name: (end)
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr nrequest = 0
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr flags = 0
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr queue_id = 49EC181FB
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr original_recipient =
gid...@secluded.site
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr recipient =
gid...@secluded.site
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr offset = 915
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr dsn_orig_rcpt =
rfc822;gid...@secluded.site
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr notify_flags = 0
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr status = 5.7.0
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr diag_type = smtp
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr diag_text = 530 5.7.0 Must
issue a STARTTLS command first
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr mta_type = dns
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr mta_mname = mx.nixnet.email
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr action = failed
Feb 15 18:14:53 mail postfix/smtp[52971]: send attr reason = host
mx.nixnet.email[5.161.67.119] said: 530 5.7.0 Must issue a STARTTLS command
first (in reply to MAIL FROM command)
Feb 15 18:14:53 mail postfix/smtp[52971]: private/bounce socket: wanted
attribute: status
Feb 15 18:14:53 mail postfix/smtp[52971]: input attribute name: status
Feb 15 18:14:53 mail postfix/smtp[52971]: input attribute value: 0
Feb 15 18:14:53 mail postfix/smtp[52971]: private/bounce socket: wanted
attribute: (list terminator)
Feb 15 18:14:53 mail postfix/smtp[52971]: input attribute name: (end)
Feb 15 18:14:53 mail postfix/smtp[52971]: 49EC181FB: to=<gid...@secluded.site>,
relay=mx.nixnet.email[5.161.67.119]:25, delay=0.44, delays=0.09/0.01/0.28/0.06,
dsn=5.7.0, status=bounced (host mx.nixnet.email[5.161.67.119] said: 530 5.7.0
Must issue a STARTTLS command first (in reply to MAIL FROM command))
Feb 15 18:14:53 mail postfix/smtp[52971]: smtp_stream_setup: maxtime=300
enable_deadline=0 min_data_rate=0
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
530 5.7.0 Must issue a STARTTLS command first
Feb 15 18:14:53 mail postfix/smtp[52971]: smtp_stream_setup: maxtime=120
enable_deadline=0 min_data_rate=0
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
530 5.7.0 Must issue a STARTTLS command first
Feb 15 18:14:53 mail postfix/smtp[52971]: > mx.nixnet.email[5.161.67.119]:25:
RSET
Feb 15 18:14:53 mail postfix/smtp[52971]: > mx.nixnet.email[5.161.67.119]:25:
QUIT
Feb 15 18:14:53 mail postfix/smtp[52971]: smtp_stream_setup: maxtime=20
enable_deadline=0 min_data_rate=0
Feb 15 18:14:53 mail postfix/smtp[52971]: < mx.nixnet.email[5.161.67.119]:25:
530 5.7.0 Must issue a STARTTLS command first
Feb 15 18:14:53 mail postfix/smtp[52971]: name_mask: resource
Feb 15 18:14:53 mail postfix/smtp[52971]: name_mask: software
Feb 15 18:14:53 mail postfix/cleanup[52642]: C36BC83C1:
message-id=<20240215231453.c36bc8...@mail.ratoperatedvehicle.com>
Feb 15 18:14:53 mail postfix/bounce[53616]: 49EC181FB: sender non-delivery
notification: C36BC83C1
Feb 15 18:14:53 mail postfix/qmgr[45613]: C36BC83C1: from=<>, size=3416,
nrcpt=1 (queue active)
Feb 15 18:14:53 mail postfix/qmgr[45613]: 49EC181FB: removed
--
Michael W. Lucas https://mwl.io/
author of: Absolute OpenBSD, SSH Mastery, git commit murder,
Absolute FreeBSD, Butterfly Stomp Waltz, TLS Mastery, etc...
### New books: DNSSEC Mastery, Letters to ed(1), $ git sync murder ###
_______________________________________________
Postfix-users mailing list -- postfix-users@postfix.org
To unsubscribe send an email to postfix-users-le...@postfix.org
