Discussion:
New SASL generic failure
(too old to reply)
Rick Zeman
2016-07-09 00:47:11 UTC
Permalink
Working system that suddenly started crapping out on
SASL-authenticated connections to its relay. Nothing's changed for
this 2.11.0 Apple-supplied postfix, and the username/password
authenticates fine to smtp.comcast.com (relay). I'm not see what's
wrong (must be what "generic" means lol). Thoughts? Thanks.

Logs with smtp.comcast.com in debug_peer and real username changed to
username and likewise to password for the password:

Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220
resomta-ch2-13v.sys.comcast.net comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220
resomta-ch2-12v.sys.comcast.net comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587:
250-resomta-ch2-13v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2949]: server features: 0x103b
size 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587:
250-resomta-ch2-12v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2955]: server features: 0x103b
size 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220 2.0.0 Ready to start
TLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: send attr request = seed
Jul 8 20:32:21 miniserv postfix/smtp[2949]: send attr size = 32
Jul 8 20:32:21 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute name: status
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute value: 0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute name: seed
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute value:
zppl+JDHdZFETR/Usnxz8Xs+6ccWx0OtD+/Kk7BbEA4=
Jul 8 20:32:21 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute name: (end)
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220 2.0.0 Ready to start
TLS
Jul 8 20:32:21 miniserv postfix/smtp[2955]: send attr request = seed
Jul 8 20:32:21 miniserv postfix/smtp[2955]: send attr size = 32
Jul 8 20:32:21 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute name: status
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute value: 0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute name: seed
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute value:
W+qOQMUBZL56QBljE+MBCR7uxVF87YE0rrYG7Z/DQdg=
Jul 8 20:32:21 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute name: (end)
Jul 8 20:32:21 miniserv postfix/smtp[2949]: Untrusted TLS connection
established to smtp.comcast.net[2001:558:fe21:2a::5]:587: TLSv1.2 with
cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2955]: Untrusted TLS connection
established to smtp.comcast.net[2001:558:fe21:2a::5]:587: TLSv1.2 with
cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587:
250-resomta-ch2-13v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2949]: server features: 0x102b
size 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: maps_find:
smtp_sasl_passwd: smtp.comcast.net: not found
Jul 8 20:32:21 miniserv postfix/smtp[2949]: maps_find:
smtp_sasl_passwd:
hash:/Library/Server/Mail/Config/postfix/sasl/passwd(0,lock|fold_fix):
smtp.comcast.net:587 = username:password
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_sasl_passwd_lookup:
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:21 miniserv postfix/smtp[2949]: starting new SASL client
Jul 8 20:32:21 miniserv postfix/smtp[2949]: name_mask: noanonymous
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_sasl_authenticate:
smtp.comcast.net[2001:558:fe21:2a::5]:587: SASL mechanisms LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: 9EEAC2E273DB: SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[2001:558:fe21:2a::5]: generic failure
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: QUIT
Jul 8 20:32:21 miniserv postfix/smtp[2949]: name_mask: resource
Jul 8 20:32:21 miniserv postfix/smtp[2949]: name_mask: software
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587:
250-resomta-ch2-12v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2955]: server features: 0x102b
size 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2955]: maps_find:
smtp_sasl_passwd: smtp.comcast.net: not found
Jul 8 20:32:21 miniserv postfix/smtp[2955]: maps_find:
smtp_sasl_passwd:
hash:/Library/Server/Mail/Config/postfix/sasl/passwd(0,lock|fold_fix):
smtp.comcast.net:587 = username:password
Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_sasl_passwd_lookup:
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:21 miniserv postfix/smtp[2955]: starting new SASL client
Jul 8 20:32:21 miniserv postfix/smtp[2955]: name_mask: noanonymous
Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_sasl_authenticate:
smtp.comcast.net[2001:558:fe21:2a::5]:587: SASL mechanisms LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2955]: C3E412E27574: SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[2001:558:fe21:2a::5]: generic failure
Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: QUIT
Jul 8 20:32:21 miniserv postfix/smtp[2955]: name_mask: resource
Jul 8 20:32:21 miniserv postfix/smtp[2955]: name_mask: software
Jul 8 20:32:21 miniserv postfix/smtp[2949]: disposing SASL state information
Jul 8 20:32:21 miniserv postfix/smtp[2955]: disposing SASL state information
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 220 resomta-ch2-03v.sys.comcast.net
comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 220 resomta-ch2-02v.sys.comcast.net
comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-03v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2949]: server features: 0x103b
size 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: STARTTLS
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-02v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-STARTTLS
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:22 miniserv postfix/smtp[2955]: server features: 0x103b
size 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: STARTTLS
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 220 2.0.0 Ready to start TLS
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr request = seed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr size = 32
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: seed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute value:
YR+QFSTCy//LhNIkj6VMHBHrtPsGEufktzBSgdQvxC0=
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 220 2.0.0 Ready to start TLS
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr request = seed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr size = 32
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: seed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute value:
jnfiC0uGO2P8ieWqWVbQiyOVYbTq4NSqT8ZAvCCq0WE=
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: Untrusted TLS connection
established to smtp.comcast.net[68.87.20.6]:587: TLSv1.2 with cipher
DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:22 miniserv postfix/smtp[2955]: Untrusted TLS connection
established to smtp.comcast.net[68.87.20.6]:587: TLSv1.2 with cipher
DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-03v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:22 miniserv postfix/smtp[2949]: server features: 0x102b
size 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2949]: maps_find:
smtp_sasl_passwd: smtp.comcast.net: not found
Jul 8 20:32:22 miniserv postfix/smtp[2949]: maps_find:
smtp_sasl_passwd:
hash:/Library/Server/Mail/Config/postfix/sasl/passwd(0,lock|fold_fix):
smtp.comcast.net:587 = username:password
Jul 8 20:32:22 miniserv postfix/smtp[2949]: smtp_sasl_passwd_lookup:
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:22 miniserv postfix/smtp[2949]: starting new SASL client
Jul 8 20:32:22 miniserv postfix/smtp[2949]: name_mask: noanonymous
Jul 8 20:32:22 miniserv postfix/smtp[2949]: smtp_sasl_authenticate:
smtp.comcast.net[68.87.20.6]:587: SASL mechanisms LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2949]: connect to subsystem private/defer
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr nrequest = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr queue_id = 9EEAC2E273DB
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr
original_recipient = ***@icloud.com
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr recipient =
***@icloud.com
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr offset = 604
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr dsn_orig_rcpt =
rfc822;***@icloud.com
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr notify_flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr status = 4.7.0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr diag_type = x-sasl
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr diag_text =
generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr mta_type =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr mta_mname =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr action = delayed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr reason = SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-02v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:22 miniserv postfix/smtp[2955]: server features: 0x102b
size 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2955]: maps_find:
smtp_sasl_passwd: smtp.comcast.net: not found
Jul 8 20:32:22 miniserv postfix/smtp[2955]: maps_find:
smtp_sasl_passwd:
hash:/Library/Server/Mail/Config/postfix/sasl/passwd(0,lock|fold_fix):
smtp.comcast.net:587 = username:password
Jul 8 20:32:22 miniserv postfix/smtp[2955]: smtp_sasl_passwd_lookup:
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:22 miniserv postfix/smtp[2955]: starting new SASL client
Jul 8 20:32:22 miniserv postfix/smtp[2955]: name_mask: noanonymous
Jul 8 20:32:22 miniserv postfix/smtp[2955]: smtp_sasl_authenticate:
smtp.comcast.net[68.87.20.6]:587: SASL mechanisms LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2955]: connect to subsystem private/defer
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr nrequest = 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr queue_id = C3E412E27574
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr
original_recipient = ***@icloud.com
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr recipient =
***@icloud.com
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr offset = 604
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/defer socket:
wanted attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr dsn_orig_rcpt =
rfc822;***@icloud.com
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr notify_flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr status = 4.7.0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr diag_type = x-sasl
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/defer socket:
wanted attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr diag_text =
generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr mta_type =
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr mta_mname =
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr action = delayed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr reason = SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2949]: 9EEAC2E273DB:
to=<***@icloud.com>, relay=smtp.comcast.net[68.87.20.6]:587,
delay=1178, delays=1176/0.39/1.5/0, dsn=4.7.0, status=deferred (SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: flush_add: site
icloud.com id 9EEAC2E273DB
Jul 8 20:32:22 miniserv postfix/smtp[2949]: match_hostname:
icloud.com ~? pointyears.net
Jul 8 20:32:22 miniserv postfix/smtp[2949]: match_hostname:
icloud.com ~? pointyears.org
Jul 8 20:32:22 miniserv postfix/smtp[2949]: match_list_match:
icloud.com: no match
Jul 8 20:32:22 miniserv postfix/smtp[2949]: flush_add: site
icloud.com id 9EEAC2E273DB status 4
Jul 8 20:32:22 miniserv postfix/smtp[2949]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: QUIT
Jul 8 20:32:22 miniserv postfix/smtp[2949]: name_mask: resource
Jul 8 20:32:22 miniserv postfix/smtp[2949]: name_mask: software
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/defer socket:
wanted attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/defer socket:
wanted attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: C3E412E27574:
to=<***@icloud.com>, relay=smtp.comcast.net[68.87.20.6]:587,
delay=807, delays=805/0.38/1.5/0, dsn=4.7.0, status=deferred (SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: flush_add: site
icloud.com id C3E412E27574
Jul 8 20:32:22 miniserv postfix/smtp[2955]: match_hostname:
icloud.com ~? pointyears.net
Jul 8 20:32:22 miniserv postfix/smtp[2955]: match_hostname:
icloud.com ~? pointyears.org
Jul 8 20:32:22 miniserv postfix/smtp[2955]: match_list_match:
icloud.com: no match
Jul 8 20:32:22 miniserv postfix/smtp[2955]: flush_add: site
icloud.com id C3E412E27574 status 4
Jul 8 20:32:22 miniserv postfix/smtp[2955]: smtp_stream_setup:
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: QUIT
Jul 8 20:32:22 miniserv postfix/smtp[2955]: name_mask: resource
Jul 8 20:32:22 miniserv postfix/smtp[2955]: name_mask: software
Jul 8 20:32:22 miniserv postfix/smtp[2955]: disposing SASL state information
Jul 8 20:32:22 miniserv postfix/smtp[2949]: disposing SASL state information
Wietse Venema
2016-07-09 01:15:01 UTC
Permalink
Your SASL library cannot authenticate with PLAIN or LOGIN.

What have you changed on your system? Did you change Postfix settings?
Did you lose the SASL plugins that your SASL library needs? Did you
turn on chroot in master.cf, so that the SASL plugins are no longer
found?

Basically strace (or whatever) the smtpd process and make sense
of failing system calls. See DEBUG_README for suggestions how to trace
a Postfix daemon process.

Wietse
Post by Rick Zeman
Working system that suddenly started crapping out on
SASL-authenticated connections to its relay. Nothing's changed for
this 2.11.0 Apple-supplied postfix, and the username/password
authenticates fine to smtp.comcast.com (relay). I'm not see what's
wrong (must be what "generic" means lol). Thoughts? Thanks.
Logs with smtp.comcast.com in debug_peer and real username changed to
maxtime=300 enable_deadline=0
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220
resomta-ch2-13v.sys.comcast.net comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220
resomta-ch2-12v.sys.comcast.net comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
250-resomta-ch2-13v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2949]: server features: 0x103b
size 36700160
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
250-resomta-ch2-12v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2955]: server features: 0x103b
size 36700160
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220 2.0.0 Ready to start
TLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: send attr request = seed
Jul 8 20:32:21 miniserv postfix/smtp[2949]: send attr size = 32
Jul 8 20:32:21 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute name: status
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute value: 0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute name: seed
zppl+JDHdZFETR/Usnxz8Xs+6ccWx0OtD+/Kk7BbEA4=
Jul 8 20:32:21 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:21 miniserv postfix/smtp[2949]: input attribute name: (end)
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 220 2.0.0 Ready to start
TLS
Jul 8 20:32:21 miniserv postfix/smtp[2955]: send attr request = seed
Jul 8 20:32:21 miniserv postfix/smtp[2955]: send attr size = 32
Jul 8 20:32:21 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute name: status
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute value: 0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute name: seed
W+qOQMUBZL56QBljE+MBCR7uxVF87YE0rrYG7Z/DQdg=
Jul 8 20:32:21 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:21 miniserv postfix/smtp[2955]: input attribute name: (end)
Jul 8 20:32:21 miniserv postfix/smtp[2949]: Untrusted TLS connection
established to smtp.comcast.net[2001:558:fe21:2a::5]:587: TLSv1.2 with
cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2955]: Untrusted TLS connection
established to smtp.comcast.net[2001:558:fe21:2a::5]:587: TLSv1.2 with
cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: EHLO
miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
250-resomta-ch2-13v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2949]: server features: 0x102b
size 36700160
smtp_sasl_passwd: smtp.comcast.net: not found
smtp.comcast.net:587 = username:password
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:21 miniserv postfix/smtp[2949]: starting new SASL client
Jul 8 20:32:21 miniserv postfix/smtp[2949]: name_mask: noanonymous
smtp.comcast.net[2001:558:fe21:2a::5]:587: SASL mechanisms LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: 9EEAC2E273DB: SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[2001:558:fe21:2a::5]: generic failure
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: QUIT
Jul 8 20:32:21 miniserv postfix/smtp[2949]: name_mask: resource
Jul 8 20:32:21 miniserv postfix/smtp[2949]: name_mask: software
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
250-resomta-ch2-12v.sys.comcast.net hello [2601:982:8200:774f::162],
pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-AUTH LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[2001:558:fe21:2a::5]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2955]: server features: 0x102b
size 36700160
smtp_sasl_passwd: smtp.comcast.net: not found
smtp.comcast.net:587 = username:password
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:21 miniserv postfix/smtp[2955]: starting new SASL client
Jul 8 20:32:21 miniserv postfix/smtp[2955]: name_mask: noanonymous
smtp.comcast.net[2001:558:fe21:2a::5]:587: SASL mechanisms LOGIN PLAIN
XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2955]: C3E412E27574: SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[2001:558:fe21:2a::5]: generic failure
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[2001:558:fe21:2a::5]:587: QUIT
Jul 8 20:32:21 miniserv postfix/smtp[2955]: name_mask: resource
Jul 8 20:32:21 miniserv postfix/smtp[2955]: name_mask: software
Jul 8 20:32:21 miniserv postfix/smtp[2949]: disposing SASL state information
Jul 8 20:32:21 miniserv postfix/smtp[2955]: disposing SASL state information
maxtime=300 enable_deadline=0
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 220 resomta-ch2-03v.sys.comcast.net
comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 220 resomta-ch2-02v.sys.comcast.net
comcast ESMTP server ready
Jul 8 20:32:21 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-03v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-STARTTLS
Jul 8 20:32:21 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:21 miniserv postfix/smtp[2949]: server features: 0x103b
size 36700160
maxtime=300 enable_deadline=0
Jul 8 20:32:21 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: STARTTLS
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-02v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-STARTTLS
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:22 miniserv postfix/smtp[2955]: server features: 0x103b
size 36700160
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: STARTTLS
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 220 2.0.0 Ready to start TLS
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr request = seed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr size = 32
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: seed
YR+QFSTCy//LhNIkj6VMHBHrtPsGEufktzBSgdQvxC0=
Jul 8 20:32:22 miniserv postfix/smtp[2949]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 220 2.0.0 Ready to start TLS
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr request = seed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr size = 32
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: seed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: seed
jnfiC0uGO2P8ieWqWVbQiyOVYbTq4NSqT8ZAvCCq0WE=
Jul 8 20:32:22 miniserv postfix/smtp[2955]: private/tlsmgr: wanted
attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: Untrusted TLS connection
established to smtp.comcast.net[68.87.20.6]:587: TLSv1.2 with cipher
DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:22 miniserv postfix/smtp[2955]: Untrusted TLS connection
established to smtp.comcast.net[68.87.20.6]:587: TLSv1.2 with cipher
DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: EHLO miniserv.pointyears.net
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-03v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:22 miniserv postfix/smtp[2949]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:22 miniserv postfix/smtp[2949]: server features: 0x102b
size 36700160
smtp_sasl_passwd: smtp.comcast.net: not found
smtp.comcast.net:587 = username:password
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:22 miniserv postfix/smtp[2949]: starting new SASL client
Jul 8 20:32:22 miniserv postfix/smtp[2949]: name_mask: noanonymous
smtp.comcast.net[68.87.20.6]:587: SASL mechanisms LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2949]: connect to subsystem private/defer
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr nrequest = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr queue_id = 9EEAC2E273DB
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr recipient =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr offset = 604
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr dsn_orig_rcpt =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr notify_flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr status = 4.7.0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr diag_type = x-sasl
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr diag_text =
generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr mta_type =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr mta_mname =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr action = delayed
Jul 8 20:32:22 miniserv postfix/smtp[2949]: send attr reason = SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-resomta-ch2-02v.sys.comcast.net
hello [73.130.72.129], pleased to meet you
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-HELP
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-AUTH LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-SIZE 36700160
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-ENHANCEDSTATUSCODES
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250-8BITMIME
Jul 8 20:32:22 miniserv postfix/smtp[2955]: <
smtp.comcast.net[68.87.20.6]:587: 250 OK
Jul 8 20:32:22 miniserv postfix/smtp[2955]: server features: 0x102b
size 36700160
smtp_sasl_passwd: smtp.comcast.net: not found
smtp.comcast.net:587 = username:password
host `smtp.comcast.net' user `username' pass `password'
Jul 8 20:32:22 miniserv postfix/smtp[2955]: starting new SASL client
Jul 8 20:32:22 miniserv postfix/smtp[2955]: name_mask: noanonymous
smtp.comcast.net[68.87.20.6]:587: SASL mechanisms LOGIN PLAIN XOAUTH2
Jul 8 20:32:22 miniserv postfix/smtp[2955]: connect to subsystem private/defer
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr nrequest = 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr queue_id = C3E412E27574
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr recipient =
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr offset = 604
wanted attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr dsn_orig_rcpt =
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr notify_flags = 0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute value: 0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr status = 4.7.0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr diag_type = x-sasl
wanted attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr diag_text =
generic failure
Jul 8 20:32:22 miniserv postfix/smtp[2949]: input attribute name: (end)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr mta_type =
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr mta_mname =
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr action = delayed
Jul 8 20:32:22 miniserv postfix/smtp[2955]: send attr reason = SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure
delay=1178, delays=1176/0.39/1.5/0, dsn=4.7.0, status=deferred (SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure)
Jul 8 20:32:22 miniserv postfix/smtp[2949]: flush_add: site
icloud.com id 9EEAC2E273DB
icloud.com ~? pointyears.net
icloud.com ~? pointyears.org
icloud.com: no match
Jul 8 20:32:22 miniserv postfix/smtp[2949]: flush_add: site
icloud.com id 9EEAC2E273DB status 4
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2949]: >
smtp.comcast.net[68.87.20.6]:587: QUIT
Jul 8 20:32:22 miniserv postfix/smtp[2949]: name_mask: resource
Jul 8 20:32:22 miniserv postfix/smtp[2949]: name_mask: software
wanted attribute: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: status
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute value: 0
wanted attribute: (list terminator)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: input attribute name: (end)
delay=807, delays=805/0.38/1.5/0, dsn=4.7.0, status=deferred (SASL
authentication failed; cannot authenticate to server
smtp.comcast.net[68.87.20.6]: generic failure)
Jul 8 20:32:22 miniserv postfix/smtp[2955]: flush_add: site
icloud.com id C3E412E27574
icloud.com ~? pointyears.net
icloud.com ~? pointyears.org
icloud.com: no match
Jul 8 20:32:22 miniserv postfix/smtp[2955]: flush_add: site
icloud.com id C3E412E27574 status 4
maxtime=300 enable_deadline=0
Jul 8 20:32:22 miniserv postfix/smtp[2955]: >
smtp.comcast.net[68.87.20.6]:587: QUIT
Jul 8 20:32:22 miniserv postfix/smtp[2955]: name_mask: resource
Jul 8 20:32:22 miniserv postfix/smtp[2955]: name_mask: software
Jul 8 20:32:22 miniserv postfix/smtp[2955]: disposing SASL state information
Jul 8 20:32:22 miniserv postfix/smtp[2949]: disposing SASL state information
Viktor Dukhovni
2016-07-09 01:17:50 UTC
Permalink
Post by Wietse Venema
Your SASL library cannot authenticate with PLAIN or LOGIN.
Another possibility is that it supports and prefers XOAUTH2, but lacks
the necessary credentials or configuration to do so. In that case filtering
out that mechanism might resolve the problem. It could be that the server
side has only recently enabled that mechanism.
--
Viktor.
Rick Zeman
2016-07-09 02:09:52 UTC
Permalink
On Fri, Jul 8, 2016 at 9:17 PM, Viktor Dukhovni
Post by Viktor Dukhovni
Post by Wietse Venema
Your SASL library cannot authenticate with PLAIN or LOGIN.
Another possibility is that it supports and prefers XOAUTH2, but lacks
the necessary credentials or configuration to do so. In that case filtering
out that mechanism might resolve the problem. It could be that the server
side has only recently enabled that mechanism.
Answering Wietse here, too, but I haven't touched the config and it's
been months since the config's been touched at all, and the server
got rebooted a few weeks ago for a UPS replacement, so it seems likely
that comcast changed something. According to
https://www.iana.org/assignments/sasl-mechanisms/sasl-mechanisms.xml
XOAUTH2 is totally obsolete and I can't imagine Comcast requiring that
at this late date (I've been doing PLAIN over TLS for the last two
years with this postfix instance).

How might 'filtering out that mechanism" be done, Viktor? Doesn't
sound (or look like, based on SASL_README) that it's something done in
postfix.

smtp sasl options in main.cf:

smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/Library/Server/Mail/Config/postfix/sasl/passwd
smtp_sasl_security_options = noanonymous
Viktor Dukhovni
2016-07-09 13:57:17 UTC
Permalink
Post by Rick Zeman
How might 'filtering out that mechanism" be done, Viktor? Doesn't
sound (or look like, based on SASL_README) that it's something done in
postfix.
The first occurrence of the word "filter" in SASL_README is the section
that describes filtering of SASL mechanisms in the Postfix SMTP client:

http://www.postfix.org/SASL_README.html#client_sasl_filter

You really should have been able to find this...
--
Viktor.
Rick Zeman
2016-07-11 13:27:20 UTC
Permalink
On Sat, Jul 9, 2016 at 9:57 AM, Viktor Dukhovni
Post by Viktor Dukhovni
Post by Rick Zeman
How might 'filtering out that mechanism" be done, Viktor? Doesn't
sound (or look like, based on SASL_README) that it's something done in
postfix.
The first occurrence of the word "filter" in SASL_README is the section
http://www.postfix.org/SASL_README.html#client_sasl_filter
You really should have been able to find this...
You are entirely correct: I should have been able to find that (after
all, I was so close, and that was the readme I used when I set up the
damn thing), and I just missed it on my skim. Explicitly filtering
in:

smtp_sasl_mechanism_filter = plain, login

did the trick. I didn't need to filter out XOAUTH2.

As always, thank you, Viktor.
Viktor Dukhovni
2016-07-11 14:12:12 UTC
Permalink
Post by Rick Zeman
smtp_sasl_mechanism_filter = plain, login
did the trick. I didn't need to filter out XOAUTH2.
Whether through an explicit deny, or by omission, either way
the effect is to disable XOAUTH2. So the best hypothesis as
to the cause of the problem is that XOAUTH2 is supported and
preferred by Apple's SASL stack, but is not usable without
additional configuration and/or supporting application code.

So either Comcast added support for it recently, or your
machine was recently upgraded to support the new mechanism.
--
Viktor.
Continue reading on narkive:
Loading...