SASL issue with Postfix on CentOS 7 with "noplaintext" option

chriswoods · January 13, 2022, 9:27pm

SYSTEM INFORMATION

OS type and version:	CentOS 7.9.2009
Webmin version:	1.984
Virtualmin version:	6.17
Related products version:	Postfix 2.10.1

The issue I’ve just noticed is on a server which until now has not been handling email. It appears to be related to @granroth’s unresolved issue from over a year ago. Postfix + SASL on CentOS 7 after Migration from Ubuntu?

Fundamentally, Postfix is unable to send or receive email, though it starts up ok. As soon as an inbound or outbound email is attempted, it fails in the same way.

Outbound email test:

Jan 13 20:05:30 l04 postfix/postfix-script[11096]: starting the Postfix mail system
Jan 13 20:05:30 l04 postfix/master[11098]: daemon started -- version 2.10.1, configuration /etc/postfix
Jan 13 20:05:55 l04 postfix/postfix-script[11135]: refreshing the Postfix mail system
Jan 13 20:05:55 l04 postfix/master[11098]: reload -- version 2.10.1, configuration /etc/postfix
Jan 13 20:10:16 l04 postfix/postfix-script[11755]: stopping the Postfix mail system
Jan 13 20:10:16 l04 postfix/master[11098]: terminating on signal 15
Jan 13 20:10:17 l04 postfix/postfix-script[11835]: starting the Postfix mail system
Jan 13 20:10:17 l04 postfix/master[11837]: daemon started -- version 2.10.1, configuration /etc/postfix
Jan 13 20:10:28 l04 dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Jan 13 20:10:28 l04 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
Jan 13 20:10:28 l04 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Jan 13 20:10:28 l04 dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Jan 13 20:10:28 l04 dovecot: auth: Debug: auth client connected (pid=11874)
Jan 13 20:10:28 l04 dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=dREVR3zVBuZ/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=58886#011resp=AG90QG92ZXJ0aHJvd3RoZW0uY29tAEphZGGmaW5jaDczIQ== (previous base64 data may contain sensitive data)
Jan 13 20:10:28 l04 dovecot: auth-worker(11876): Debug: Loading modules from directory: /usr/lib64/dovecot/auth
Jan 13 20:10:28 l04 dovecot: auth-worker(11876): Debug: Module loaded: /usr/lib64/dovecot/auth/lib20_auth_var_expand_crypt.so
Jan 13 20:10:28 l04 dovecot: auth-worker(11876): Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Jan 13 20:10:28 l04 dovecot: auth-worker(11876): Debug: pam(example@example.com,127.0.0.1,<dREVR3zVBuZ/AAAB>): lookup service=dovecot
Jan 13 20:10:28 l04 dovecot: auth-worker(11876): Debug: pam(example@example.com,127.0.0.1,<dREVR3zVBuZ/AAAB>): #1/1 style=1 msg=Password:
Jan 13 20:10:28 l04 dovecot: auth: Debug: client passdb out: OK#0111#011user=example@example.com
Jan 13 20:10:28 l04 dovecot: auth: Debug: master in: REQUEST#011462684161#01111874#0111#011c85720bc28752e0de62fc82e25ee4e98#011session_pid=11877#011request_auth_token
Jan 13 20:10:28 l04 dovecot: auth-worker(11876): Debug: passwd(example@example.com,127.0.0.1,<dREVR3zVBuZ/AAAB>): lookup
Jan 13 20:10:28 l04 dovecot: auth: Debug: master userdb out: USER#011462684161#011example@example.com#011system_groups_user=example@example.com#011uid=1006#011gid=1005#011home=/home/exampleuser/homes/ot#011auth_mech=PLAIN#011auth_token=d31b1fbc0fb2386d108780895d48a028e3fd41bb
Jan 13 20:10:28 l04 dovecot: imap-login: Login: user=<example@example.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=11877, secured, session=<dREVR3zVBuZ/AAAB>
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: all
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: subnet
Jan 13 20:10:28 l04 postfix/smtpd[11880]: inet_addr_local: configured 3 IPv4 addresses
Jan 13 20:10:28 l04 postfix/smtpd[11880]: inet_addr_local: configured 12 IPv6 addresses
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: 127.0.0.0/8: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: 191.96.110.0/24: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: 191.96.110.0/24: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [::1]/128: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fcfc:f00:82e4::20]/64: 1
Jan 13 20:10:28 l04 postfix/smtpd[11880]: been_here: [fe80::]/64: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: mynetworks: 127.0.0.0/8 191.96.110.0/24 [::1]/128 [fcfc:f00:82e4::20]/64 [fe80::]/64
Jan 13 20:10:28 l04 postfix/smtpd[11880]: process generation: 3 (3)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: mynetworks ~? debug_peer_list
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: mynetworks ~? fast_flush_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: mynetworks ~? mynetworks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: relay_domains ~? debug_peer_list
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: relay_domains ~? fast_flush_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: relay_domains ~? mynetworks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: relay_domains ~? permit_mx_backup_networks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: relay_domains ~? qmqpd_authorized_clients
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: relay_domains ~? relay_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: permit_mx_backup_networks ~? debug_peer_list
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: permit_mx_backup_networks ~? fast_flush_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: permit_mx_backup_networks ~? mynetworks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: permit_mx_backup_networks ~? permit_mx_backup_networks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: connect to subsystem private/proxymap
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr request = open
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr table = unix:passwd.byname
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr flags = 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/proxymap socket: wanted attribute: status
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: status
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute value: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/proxymap socket: wanted attribute: flags
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: flags
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute value: 16
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/proxymap socket: wanted attribute: (list terminator)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: (end)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: dict_proxy_open: connect to map=unix:passwd.byname status=0 server_flags=fixed
Jan 13 20:10:28 l04 postfix/smtpd[11880]: dict_open: proxy:unix:passwd.byname
Jan 13 20:10:28 l04 postfix/smtpd[11880]: Compiled against Berkeley DB: 5.3.21?
Jan 13 20:10:28 l04 postfix/smtpd[11880]: Run-time linked against Berkeley DB: 5.3.21?
Jan 13 20:10:28 l04 postfix/smtpd[11880]: dict_open: hash:/etc/aliases
Jan 13 20:10:28 l04 postfix/smtpd[11880]: Compiled against Berkeley DB: 5.3.21?
Jan 13 20:10:28 l04 postfix/smtpd[11880]: Run-time linked against Berkeley DB: 5.3.21?
Jan 13 20:10:28 l04 postfix/smtpd[11880]: dict_open: hash:/etc/postfix/virtual
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? debug_peer_list
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? fast_flush_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? mynetworks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? permit_mx_backup_networks
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? qmqpd_authorized_clients
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? relay_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: smtpd_access_maps ~? smtpd_access_maps
Jan 13 20:10:28 l04 postfix/smtpd[11880]: unknown_helo_hostname_tempfail_action = defer_if_permit
Jan 13 20:10:28 l04 postfix/smtpd[11880]: unknown_address_tempfail_action = defer_if_permit
Jan 13 20:10:28 l04 postfix/smtpd[11880]: unverified_recipient_tempfail_action = defer_if_permit
Jan 13 20:10:28 l04 postfix/smtpd[11880]: unverified_sender_tempfail_action = defer_if_permit
Jan 13 20:10:28 l04 postfix/smtpd[11880]: xsasl_cyrus_server_init: SASL config file is smtpd.conf
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: auto_clnt_create: transport=local endpoint=private/tlsmgr
Jan 13 20:10:28 l04 postfix/smtpd[11880]: auto_clnt_open: connected to private/tlsmgr
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr request = seed
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr size = 32
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/tlsmgr: wanted attribute: status
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: status
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute value: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/tlsmgr: wanted attribute: seed
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: seed
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute value: VrrV1zHcBDWoW78cZfO70qOoFL6aSLfWu52alRqTUzs=
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/tlsmgr: wanted attribute: (list terminator)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: (end)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr request = policy
Jan 13 20:10:28 l04 postfix/smtpd[11880]: send attr cache_type = smtpd
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/tlsmgr: wanted attribute: status
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: status
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute value: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/tlsmgr: wanted attribute: cachable
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: cachable
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute value: 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: private/tlsmgr: wanted attribute: (list terminator)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: input attribute name: (end)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: fast_flush_domains ~? debug_peer_list
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_string: fast_flush_domains ~? fast_flush_domains
Jan 13 20:10:28 l04 postfix/smtpd[11880]: auto_clnt_create: transport=local endpoint=private/anvil
Jan 13 20:10:28 l04 postfix/smtpd[11880]: connection established
Jan 13 20:10:28 l04 postfix/smtpd[11880]: master_notify: status 0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: resource
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: software
Jan 13 20:10:28 l04 postfix/smtpd[11880]: connect from localhost[127.0.0.1]
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_list_match: localhost: no match
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_list_match: 127.0.0.1: no match
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_list_match: localhost: no match
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_list_match: 127.0.0.1: no match
Jan 13 20:10:28 l04 postfix/smtpd[11880]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_hostname: localhost ~? 127.0.0.0/8
Jan 13 20:10:28 l04 postfix/smtpd[11880]: match_hostaddr: 127.0.0.1 ~? 127.0.0.0/8
Jan 13 20:10:28 l04 postfix/smtpd[11880]: > localhost[127.0.0.1]: 220 l04.example.com ESMTP Postfix
Jan 13 20:10:28 l04 postfix/smtpd[11880]: xsasl_cyrus_server_create: SASL service=smtp, realm=(null)
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: noanonymous
Jan 13 20:10:28 l04 postfix/smtpd[11880]: name_mask: noplaintext
Jan 13 20:10:28 l04 postfix/smtpd[11880]: warning: xsasl_cyrus_server_get_mechanism_list: no applicable SASL mechanisms
Jan 13 20:10:28 l04 postfix/smtpd[11880]: fatal: no SASL authentication mechanisms
Jan 13 20:10:29 l04 postfix/master[11837]: warning: process /usr/libexec/postfix/smtpd pid 11880 exit status 1
Jan 13 20:10:29 l04 postfix/master[11837]: warning: /usr/libexec/postfix/smtpd: bad command startup -- throttling
Jan 13 20:10:29 l04 dovecot: imap(example@example.com): Connection closed (list finished 1.107 secs ago) in=45 out=921

Inbound test:

Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: all
Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: subnet
Jan 13 20:13:02 l04 postfix/smtpd[12073]: inet_addr_local: configured 3 IPv4 addresses
Jan 13 20:13:02 l04 postfix/smtpd[12073]: inet_addr_local: configured 12 IPv6 addresses
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: 127.0.0.0/8: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: 191.96.110.0/24: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: 191.96.110.0/24: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [::1]/128: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fdf8:f53b:82e4::]/64: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: been_here: [fe80::]/64: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: mynetworks: 127.0.0.0/8 191.96.110.0/24 [::1]/128 [fdf8:f53b:82e4::]/64 [fe80::]/64
Jan 13 20:13:02 l04 postfix/smtpd[12073]: process generation: 6 (6)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: mynetworks ~? debug_peer_list
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: mynetworks ~? fast_flush_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: mynetworks ~? mynetworks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: relay_domains ~? debug_peer_list
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: relay_domains ~? fast_flush_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: relay_domains ~? mynetworks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: relay_domains ~? permit_mx_backup_networks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: relay_domains ~? qmqpd_authorized_clients
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: relay_domains ~? relay_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: permit_mx_backup_networks ~? debug_peer_list
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: permit_mx_backup_networks ~? fast_flush_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: permit_mx_backup_networks ~? mynetworks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: permit_mx_backup_networks ~? permit_mx_backup_networks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: connect to subsystem private/proxymap
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr request = open
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr table = unix:passwd.byname
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr flags = 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/proxymap socket: wanted attribute: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/proxymap socket: wanted attribute: flags
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: flags
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 16
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/proxymap socket: wanted attribute: (list terminator)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: (end)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: dict_proxy_open: connect to map=unix:passwd.byname status=0 server_flags=fixed
Jan 13 20:13:02 l04 postfix/smtpd[12073]: dict_open: proxy:unix:passwd.byname
Jan 13 20:13:02 l04 postfix/smtpd[12073]: Compiled against Berkeley DB: 5.3.21?
Jan 13 20:13:02 l04 postfix/smtpd[12073]: Run-time linked against Berkeley DB: 5.3.21?
Jan 13 20:13:02 l04 postfix/smtpd[12073]: dict_open: hash:/etc/aliases
Jan 13 20:13:02 l04 postfix/smtpd[12073]: Compiled against Berkeley DB: 5.3.21?
Jan 13 20:13:02 l04 postfix/smtpd[12073]: Run-time linked against Berkeley DB: 5.3.21?
Jan 13 20:13:02 l04 postfix/smtpd[12073]: dict_open: hash:/etc/postfix/virtual
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? debug_peer_list
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? fast_flush_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? mynetworks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? permit_mx_backup_networks
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? qmqpd_authorized_clients
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? relay_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: smtpd_access_maps ~? smtpd_access_maps
Jan 13 20:13:02 l04 postfix/smtpd[12073]: unknown_helo_hostname_tempfail_action = defer_if_permit
Jan 13 20:13:02 l04 postfix/smtpd[12073]: unknown_address_tempfail_action = defer_if_permit
Jan 13 20:13:02 l04 postfix/smtpd[12073]: unverified_recipient_tempfail_action = defer_if_permit
Jan 13 20:13:02 l04 postfix/smtpd[12073]: unverified_sender_tempfail_action = defer_if_permit
Jan 13 20:13:02 l04 postfix/smtpd[12073]: xsasl_cyrus_server_init: SASL config file is smtpd.conf
Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: auto_clnt_create: transport=local endpoint=private/tlsmgr
Jan 13 20:13:02 l04 postfix/smtpd[12073]: auto_clnt_open: connected to private/tlsmgr
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr request = seed
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr size = 32
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/tlsmgr: wanted attribute: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/tlsmgr: wanted attribute: seed
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: seed
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: vjy6cWF86BBjACHh2NrBkmq5+8SJ81rOWuf/rtY/eK8=
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/tlsmgr: wanted attribute: (list terminator)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: (end)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr request = policy
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr cache_type = smtpd
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/tlsmgr: wanted attribute: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/tlsmgr: wanted attribute: cachable
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: cachable
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/tlsmgr: wanted attribute: (list terminator)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: (end)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: fast_flush_domains ~? debug_peer_list
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_string: fast_flush_domains ~? fast_flush_domains
Jan 13 20:13:02 l04 postfix/smtpd[12073]: auto_clnt_create: transport=local endpoint=private/anvil
Jan 13 20:13:02 l04 postfix/smtpd[12073]: connection established
Jan 13 20:13:02 l04 postfix/smtpd[12073]: master_notify: status 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: resource
Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: software
Jan 13 20:13:02 l04 postfix/smtpd[12073]: connect from l03.example-sender.com[172.16.0.2]
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_list_match: l03.example-sender.com: no match
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_list_match: 172.16.0.2: no match
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_list_match: l03.example-sender.com: no match
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_list_match: 172.16.0.2: no match
Jan 13 20:13:02 l04 postfix/smtpd[12073]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostname: l03.example-sender.com ~? 127.0.0.0/8
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostaddr: 172.16.0.2 ~? 127.0.0.0/8
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostname: l03.example-sender.com ~? 191.96.110.0/24
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostaddr: 172.16.0.2 ~? 191.96.110.0/24
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostname: l03.example-sender.com ~? [::1]/128
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostaddr: 172.16.0.2 ~? [::1]/128
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostname: l03.example-sender.com ~? [fdf8:f53b:82e4::]/64
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostaddr: 172.16.0.2 ~? [fdf8:f53b:82e4::]/64
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostname: l03.example-sender.com ~? [fe80::]/64
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_hostaddr: 172.16.0.2 ~? [fe80::]/64
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_list_match: l03.example-sender.com: no match
Jan 13 20:13:02 l04 postfix/smtpd[12073]: match_list_match: 172.16.0.2: no match
Jan 13 20:13:02 l04 postfix/smtpd[12073]: auto_clnt_open: connected to private/anvil
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr request = connect
Jan 13 20:13:02 l04 postfix/smtpd[12073]: send attr ident = smtp:172.16.0.2
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/anvil: wanted attribute: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: status
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 0
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/anvil: wanted attribute: count
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: count
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/anvil: wanted attribute: rate
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: rate
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute value: 1
Jan 13 20:13:02 l04 postfix/smtpd[12073]: private/anvil: wanted attribute: (list terminator)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: input attribute name: (end)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: > l03.example-sender.com[172.16.0.2]: 220 l04.example.com ESMTP Postfix
Jan 13 20:13:02 l04 postfix/smtpd[12073]: xsasl_cyrus_server_create: SASL service=smtp, realm=(null)
Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: noanonymous
Jan 13 20:13:02 l04 postfix/smtpd[12073]: name_mask: noplaintext
Jan 13 20:13:02 l04 postfix/smtpd[12073]: warning: xsasl_cyrus_server_get_mechanism_list: no applicable SASL mechanisms
Jan 13 20:13:02 l04 postfix/smtpd[12073]: fatal: no SASL authentication mechanisms
Jan 13 20:13:03 l04 postfix/master[11837]: warning: process /usr/libexec/postfix/smtpd pid 12073 exit status 1
Jan 13 20:13:03 l04 postfix/master[11837]: warning: /usr/libexec/postfix/smtpd: bad command startup -- throttling

The sending server MTA doesn’t error at send time, but queues the mail for retry, reporting lost connection with mail.overthrowthem.com[ip.add.re.ss] while receiving the initial server greeting.

The config began as the baseline install overseen by Webmin at the end of last year, with some minor additions to more closely match the settings on an existing CentOS box and I think this is causing issues.

Per other discussions, testsaslauthd works:

testsaslauthd -u user@example.com -p iloveyou -s smtp
0: OK "Success."

Similarly, /var/spool/postfix/var/run/saslauthd doesn’t exist.

SASL packages installed:

cyrus-sasl.x86_64                   2.1.26-23.el7                @base
cyrus-sasl-gssapi.x86_64            2.1.26-23.el7                @base
cyrus-sasl-lib.x86_64               2.1.26-23.el7                @anaconda
cyrus-sasl-plain.x86_64             2.1.26-23.el7                @base

Disabling SASL authentication allows mail to flow in both directions. If I enable the smtps server in master.cf (normally I would do this in master.cf, but this time I did it through Webmin) then I can send email with the “noplaintext” option in place, but I still cannot receive email.

I’m not sure why restricting plaintext over TLS is causing delivery failure of incoming emails. Any ideas?

postconf -n:

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
allow_percent_hack = no
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/libexec/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5
disable_vrfy_command = yes
home_mailbox = Maildir/
html_directory = no
inet_interfaces = all
inet_protocols = all
mail_owner = postfix
mailbox_command = /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME
mailbox_size_limit = 0
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
mydestination = $myhostname, localhost.$mydomain, localhost, l04.example.com
newaliases_path = /usr/bin/newaliases.postfix
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.10.1/README_FILES
sample_directory = /usr/share/doc/postfix-2.10.1/samples
sender_bcc_maps = hash:/etc/postfix/bcc
sender_dependent_default_transport_maps = hash:/etc/postfix/dependent
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtp_tls_security_level = may
smtpd_helo_required = yes
smtpd_recipient_restrictions = permit_mynetworks permit_sasl_authenticated reject_unauth_destination permit_inet_interfaces reject_unknown_reverse_client_hostname permit_mx_backup
smtpd_relay_restrictions = permit_mynetworks permit_sasl_authenticated defer_unauth_destination reject_unknown_reverse_client_hostname permit_inet_interfaces
smtpd_sasl_auth_enable = yes
smtpd_sasl_security_options = noanonymous noplaintext
smtpd_sender_restrictions = check_sender_access pcre:/etc/postfix/sender_restrictions_bad_tlds.regexp
smtpd_tls_CAfile = /etc/postfix/postfix.ca.pem
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/postfix/postfix.cert.pem
smtpd_tls_key_file = /etc/postfix/postfix.key.pem
smtpd_tls_mandatory_protocols = !SSLv2, !SSLv3, !TLSv1, !TLSv1.1
smtpd_tls_security_level = may
unknown_local_recipient_reject_code = 550
virtual_alias_maps = hash:/etc/postfix/virtual

chriswoods · January 13, 2022, 10:44pm

I read conflicting things about enforcing “noplaintext” for smtpd (incoming mail) handler. Shouldn’t its scope only be SASL authentication attempts, not inbound email delivery?

I also tweaked the config to add a handful lines per this guide and applied stricter TLS ciphers (per my other servers).

Current postconf -n:

postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_sender_restrictions
postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_client_restrictions
postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_helo_restrictions
postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_sender_restrictions
postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_client_restrictions
postconf: warning: /etc/postfix/master.cf: undefined parameter: mua_helo_restrictions
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
allow_percent_hack = no
broken_sasl_auth_clients = yes
command_directory = /usr/sbin
config_directory = /etc/postfix
daemon_directory = /usr/libexec/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5
disable_vrfy_command = yes
home_mailbox = Maildir/
html_directory = no
inet_interfaces = all
inet_protocols = all
mail_owner = postfix
mailbox_command = /usr/bin/procmail-wrapper -o -a $DOMAIN -d $LOGNAME
mailbox_size_limit = 0
mailq_path = /usr/bin/mailq.postfix
manpage_directory = /usr/share/man
milter_default_action = accept
mime_header_checks = pcre:/etc/postfix/attachment_check.regexp
mydestination = $myhostname, localhost.$mydomain, localhost, l04.example.com
newaliases_path = /usr/bin/newaliases.postfix
non_smtpd_milters = inet:localhost:8891
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.10.1/README_FILES
sample_directory = /usr/share/doc/postfix-2.10.1/samples
sender_bcc_maps = hash:/etc/postfix/bcc
sender_dependent_default_transport_maps = hash:/etc/postfix/dependent
sendmail_path = /usr/sbin/sendmail.postfix
setgid_group = postdrop
smtp_sasl_mechanism_filter = !gssapi, !login, static:all
smtp_tls_security_level = may
smtpd_helo_required = yes
smtpd_milters = inet:localhost:8891
smtpd_recipient_restrictions = permit_mynetworks permit_sasl_authenticated reject_unauth_destination permit_inet_interfaces reject_unknown_reverse_client_hostname permit_mx_backup
smtpd_relay_restrictions = permit_mynetworks permit_sasl_authenticated defer_unauth_destination reject_unknown_reverse_client_hostname permit_inet_interfaces
smtpd_sasl_auth_enable = yes
smtpd_sasl_path = smtpd
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = cyrus
smtpd_sender_restrictions = check_sender_access pcre:/etc/postfix/sender_restrictions_bad_tlds.regexp
smtpd_tls_CAfile = /etc/postfix/postfix.ca.pem
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/postfix/postfix.cert.pem
smtpd_tls_key_file = /etc/postfix/postfix.key.pem
smtpd_tls_mandatory_ciphers = high
smtpd_tls_mandatory_exclude_ciphers = MD5, aDSS, kECDH, kDH, SEED, IDEA, DES, ADH, RC2, RC4, RC5, PSD, SRP, 3DES, eNULL, aNULL
smtpd_tls_mandatory_protocols = !SSLv2, !SSLv3, !TLSv1, !TLSv1.1
smtpd_tls_received_header = yes
smtpd_tls_security_level = may
smtpd_use_tls = yes
strict_rfc821_envelopes = yes
tls_high_cipherlist = EDH+CAMELLIA:EDH+aRSA:EECDH+aRSA+AESGCM:EECDH+aRSA+SHA256:EECDH:+CAMELLIA128:+AES128:+SSLv3:!aNULL:!eNULL:!LOW:!3DES:!MD5:!EXP:!PSK:!DSS:!RC4:!SEED:!IDEA:!ECDSA:kEDH:CAMELLIA128-SHA:AES128-SHA
tls_random_source = dev:/dev/urandom
unknown_local_recipient_reject_code = 550
virtual_alias_maps = hash:/etc/postfix/virtual

Also interesting to note is that enabling smtps via Webmin > Servers > Postfix > Server Processes, it seems to just be uncommenting everything, which inevitably also enables a few -o variables which aren’t accordingly defined in main.cf:

smtpd -o syslog_name=postfix/smtps -o smtpd_tls_wrappermode=yes -o smtpd_sasl_auth_enable=yes -o smtpd_reject_unlisted_recipient=no -o smtpd_client_restrictions=$mua_client_restrictions -o smtpd_helo_restrictions=$mua_helo_restrictions -o smtpd_sender_restrictions=$mua_sender_restrictions -o smtpd_recipient_restrictions=permit_sasl_authenticated,reject -o milter_macro_daemon_name=ORIGINATING

Though those only throw a warning and don’t seem to affect mail.

system · March 14, 2022, 10:45pm

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.