SASL configuration issue

Wed, 27 Mar 2019 14:41:27 -0700 

Hello,
  postfix 3.3.1
  opensuse 15.0 (linux )

  AFAICT the configuration on this computer is the same as that on
another where postfix works just fine. Obviously, something is different.
  The report of a mystery error is not much help.
  I cannot determine the failure. Postfix finds the authentication data,
and promptly fails authentication.
  What has this gone wrong?

  Below are the log entries for one failure, and an excerpt from <main.cf>.

----[ log entry ]----
  (see attached file)
----[ end ]----

############################################################
# SASL stuff
############################################################
smtp_sasl_auth_enable = yes
smtp_sasl_security_options =
smtp_sasl_password_maps = hash:/etc/postfix/sasl_passwd
smtpd_sasl_auth_enable = no
#smtpd_sasl_path = private/auth
#smtpd_sasl_type = dovecot
############################################################
# TLS stuff
############################################################
tls_append_default_CA = no
relay_clientcerts =
#tls_random_source = dev:/dev/urandom

smtp_use_tls = yes
#smtp_tls_loglevel = 0
smtp_enforce_tls = no
smtp_tls_CAfile =
smtp_tls_CApath = /etc/ssl/cacerts
smtp_tls_cert_file =
smtp_tls_key_file =
#smtp_tls_session_cache_timeout = 3600s
smtp_tls_session_cache_database =
btree:/var/lib/postfix/smtp_tls_session_cache

smtpd_use_tls = no
#smtpd_tls_loglevel = 0
smtpd_tls_CAfile =
smtpd_tls_CApath =
smtpd_tls_cert_file =
smtpd_tls_key_file =
smtpd_tls_ask_ccert = no
smtpd_tls_received_header = no


-- 
James Moe
moe dot james at sohnen-moe dot com
520.743.3936
Think.

2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: smtp_stream_setup: 
maxtime=300 enable_deadline=0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 19 got 65
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 220 sma-inc.us ESMTP CommuniGate Pro 6.1.20 
is glad to see you!
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: > 
mail.sma.com[192.168.69.246]:5025: EHLO sma-station14l.sma.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 19 flush 29
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 19 got 187
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-sma-inc.us we trust you 
sma-station14l.sma.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-STARTTLS
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-DSN
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-SIZE
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5 
GSSAPI
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-NO-SOLICITING
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-8BITMIME
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-HELP
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250 EHLO
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: server features: 
0x903b size 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: smtp_stream_setup: 
maxtime=300 enable_deadline=0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: > 
mail.sma.com[192.168.69.246]:5025: STARTTLS
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 19 flush 10
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 19 got 35
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 220 please start a TLS connection
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
event_request_timer: reset 0x7f9a6f856227 0x557790b193a0 5
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr request 
= lookup
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
cache_type = smtp
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr cache_id 
= 
smtp&[mail.sma.com]:5025&mail.sma.com&192.168.69.246&&CEF2D0F6A08A1C35B5789195205F8DBF55CCADD7775AF5300BDA4C869064136D
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 9 flush 160
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 9 got 1207
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
value: 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: session
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: session
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
value: 
MIIDdwIBAQICAwEEAsATBCB6J4dNffkDKf/mFP0veXyYi5vxSOxQpnmpsIQ9JBWCPQQwWH2IBm9r4MEc3IpgMPc2PNPUrKJ0BrXXTZ4456XxjIsYkUvgafvY0ON4uPiDE3SWoQYCBFyb6EmiBAICHCCjggJMMIICSDCCAbGgAwIBAgIBADANBgkqhkiG9w0BAQQFADBqMQswCQYDVQQGEwJkZTENMAsGA1UECBMEQVNTUDEhMB8GA1UEChMYSW50ZXJuZXQgV2lkZ2l0cyBQdHkgTHRkMQ4wDAYDVQQHEwVsb2NhbDEZMBcGA1UEAxMQd3d3LmFzc3BzbXRwLm9yZzAeFw0wODEwMjAxMzA4MTlaFw0zNjAzMDcxMzA4MTlaMGoxCzAJBgNVBAYTAmRlMQ0wCwYDVQQIEwRBU1NQMSEwHwYDVQQKExhJbnRlcm5ldCBXaWRnaXRzIFB0eSBMdGQxDjAMBgNVBAcTBWxvY2FsMRkwFwYDVQQDExB3d3cuYXNzcHNtdHAub3JnMIGfMA0GCSqGSIb3DQEBAQUAA4GNADCBiQKBgQC6W1ka7T56AVSWIEtb2UWcJPZ3J0VjFDYZEm7aYyKL11s6/l8JiMyK0T566iIm/x1ecnUYQc7lbZF1+e9Mxqm4IQpJIbFGO7uwcc9YoYwWC8/n8A2fMQMgNu+cad6HjVJjzaWOPdGvNQD3Z8DEOQJB3ZylXvrLXjFmepw3VBKiyQIDAQABMA0GCSqGSIb3DQEBBAUAA4GBAHV6jQt3alrhi6gUMsimHeMsjmXFh64DODHfNBkKQTwpwMMdkNlBOWWZ07CqD6njYgGeKSWNBFm7+mrfjI/V8YArt9U2vUefTaX1whDDnsJPFfyhvshfe8o74Xs5LEnd1J+veimwwZcVneLDnBTmS+0rknxq9XKRdiVTMNPuj8E3pAIEAKUDAgESqQQCAhwgqoGjBIGgiQK9d3gmZn9NamyRvBlCtqVIJcMo97QJoqS43mjBYG1PgNUhBO6LsWfyHDyA0nLuvMyx0IYN17KdiFE9Ra8ZiQwE70x5OOPd+Vc6/RxoTTK+0KboMAzaG4/hbc4pY9qPrzI+SOKPQ5pWyTYIKORpEcyFqB8ou926lLNU0Y1uuZ0aQBMEAVKhyab/hs00dXwp4c6f02ipCBpn4rTTV5yaSK0DAgEB
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: (list terminator)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: (end)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
event_request_timer: reset 0x7f9a6f856227 0x557790b193a0 5
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr request 
= seed
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr size = 32
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 9 flush 22
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 9 got 60
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
value: 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: seed
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: seed
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
value: WlyEsDq0yHr7I3nNfIvCUG8nVa3WWrzmAvwSteIm6pI=
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: (list terminator)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: (end)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
event_request_timer: reset 0x7f9a6f856227 0x557790b193a0 5
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr request 
= update
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
cache_type = smtp
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr cache_id 
= 
smtp&[mail.sma.com]:5025&mail.sma.com&192.168.69.246&&CEF2D0F6A08A1C35B5789195205F8DBF55CCADD7775AF5300BDA4C869064136D
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr session 
= [data 891 bytes]
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 9 flush 1357
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 9 got 10
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
value: 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/tlsmgr: 
wanted attribute: (list terminator)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: (end)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: smtp_stream_setup: 
maxtime=300 enable_deadline=0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: > 
mail.sma.com[192.168.69.246]:5025: EHLO sma-station14l.sma.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 19 flush 29
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 19 got 173
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-sma-inc.us we trust you 
sma-station14l.sma.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-DSN
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-SIZE
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-AUTH LOGIN PLAIN CRAM-MD5 DIGEST-MD5 
GSSAPI
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-NO-SOLICITING
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-8BITMIME
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250-HELP
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: < 
mail.sma.com[192.168.69.246]:5025: 250 EHLO
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: server features: 
0x902b size 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: maps_find: 
smtp_sasl_password_maps: mail.sma.com: not found
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: maps_find: 
smtp_sasl_password_maps: 
hash:/etc/postfix/sasl_passwd(0,lock|fold_fix|utf8_request): 
[mail.sma.com]:5025 = moe.james:***password***
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
smtp_sasl_passwd_lookup: host `mail.sma.com' user `moe.james' pass 
`***password***'
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: starting new SASL 
client
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
smtp_sasl_authenticate: mail.sma.com[192.168.69.246]:5025: SASL mechanisms 
LOGIN PLAIN CRAM-MD5 DIGEST-MD5 GSSAPI
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: GSSAPI client step 
1
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: warning: SASL 
authentication failure: GSSAPI Error: Unspecified GSS failure.  Minor code may 
provide more information (No Kerberos credentials available (default cache: 
DIR:/run/user/51/krb5cc))
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: connect to 
subsystem private/defer
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr nrequest 
= 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr flags = 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr queue_id 
= B67371DC63A
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
original_recipient = moe.ja...@sohnen-moe.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
recipient = moe.ja...@sohnen-moe.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr offset = 
1720
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
dsn_orig_rcpt =
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
notify_flags = 1
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr status = 
4.7.0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
diag_type = x-sasl
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
diag_text = generic failure
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr mta_type 
=
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr 
mta_mname =
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr action = 
delayed
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: send attr reason = 
SASL authentication failed; cannot authenticate to server 
mail.sma.com[192.168.69.246]: generic failure
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 20 flush 365
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_buf_get_ready: fd 20 got 10
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/defer 
socket: wanted attribute: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: status
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
value: 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: private/defer 
socket: wanted attribute: (list terminator)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: input attribute 
name: (end)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: B67371DC63A: 
to=<moe.ja...@sohnen-moe.com>, relay=mail.sma.com[192.168.69.246]:5025, 
delay=185635, delays=185634/0.35/0.33/0, dsn=4.7.0, status=deferred (SASL 
authentication failed; cannot authenticate to server 
mail.sma.com[192.168.69.246]: generic failure)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: flush_add: site 
sohnen-moe.com id B67371DC63A
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: match_hostname: 
fast_flush_domains: sohnen-moe.com ~? sma-station14l.sma.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: match_hostname: 
fast_flush_domains: sohnen-moe.com ~? localhost.sma.com
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: match_hostname: 
fast_flush_domains: sohnen-moe.com ~? 
hash:/etc/postfix/relay(0,lock|utf8_request)
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: match_hostname: 
fast_flush_domains: lookup hash:/etc/postfix/relay.db sohnen-moe.com: notfound
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: match_hostname: 
fast_flush_domains: lookup hash:/etc/postfix/relay.db com: notfound
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: match_list_match: 
sohnen-moe.com: no match
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: flush_add: site 
sohnen-moe.com id B67371DC63A status 4
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: smtp_stream_setup: 
maxtime=300 enable_deadline=0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: > 
mail.sma.com[192.168.69.246]:5025: QUIT
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: name_mask: resource
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: name_mask: software
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 19 flush 6
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: 
vstream_fflush_some: fd 19 flush 0
2019-03-27T14:16:57-0700 sma-station14l postfix/smtp[19939]: disposing SASL 
state information

Attachment: signature.asc
Description: OpenPGP digital signature

Reply via email to