While preparing the Debian packages of Dovecot 2.4.1, I encountered what
appears to be a regression that impacts the ability of some clients to
successfully negotiate gssapi/krb5 authentication.

The regression has so far been observed in gsasl, which was able to
successfully authenticate to 2.3.19 but cannot authenticate to 2.4.1.
Mutt is able to successfully authenticate with 2.3.19 and 2.4.1.

Doveconf output is attached.

The debug logs for both failed (gsasl) and successful (mutt)
authentications follow.  Note that all logs are from an ephemeral debug
environment, and sensitive data is not redacted.

I can provide additional information as needed, and can test different
code and/or configuration changes.

Failed authentication dovecot debug log:

Apr 30 13:40:09 auth: Debug: Loading modules from directory: 
/usr/lib/dovecot/modules/auth
Apr 30 13:40:09 auth: Debug: Loading modules from directory: 
/usr/lib/dovecot/modules/auth
Apr 30 13:40:09 auth: Debug: Module loaded: 
/usr/lib/dovecot/modules/auth/libmech_gssapi.so
Apr 30 13:40:09 auth: Debug: Read auth token secret from 
/home/noahm/dovecot-root/b/auth-token-secret.dat
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: Server 
accepted connection (fd=18)
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: auth 
client connected (pid=6791)
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: client 
in: AUTH   1       GSSAPI  protocol=imap   final-resp-ok        
session=FhRIDv8zdMzAqAHa        lip=172.18.0.205        rip=192.168.1.218       
lport=17436     rport=52340
Apr 30 13:40:09 auth(?,192.168.1.218,sasl:gssapi)<FhRIDv8zdMzAqAHa>: Debug: 
gssapi: Using all keytab entries
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: client 
passdb out: CONT   1       #
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: client 
in: CONT   1       # (previous base64 data may contain sensitive data)
Apr 30 13:40:09 auth(?,192.168.1.218,sasl:gssapi)<FhRIDv8zdMzAqAHa>: Debug: 
gssapi: Processed incoming packet correctly, waiting for another.
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: client 
passdb out: CONT   1       
YEcGBisGAQUFAqA9MDugDTALBgkqhkiG9xIBAgKjKjAooCYbJG5vdF9kZWZpbmVkX2luX1JGQzQxNzhAcGxlYXNlX2lnbm9yZQ==
Apr 30 13:40:09 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: client 
in: CONT   1       
YIIDAAYJKoZIhvcSAQICAQBuggLvMIIC66ADAgEFoQMCAQ6iBwMFACAAAACjggIDYYIB/zCCAfugAwIBBaENGwtFWEFNUExFLkNPTaIfMB2gAwIBA6EWMBQbBGltYXAbDGRvdmVjb3QtdGVzdKOCAcIwggG+oAMCARKhAwIBAqKCAbAEggGsj4jD3VOwvfNdLxjc2hqxFsBYyCvjdOCX0R1So6ANZEYnEWddqZwMCuz7BxXv4z+cXaL6g6iGlVkU4RxQyJQHDFUQC8JroTlyMQ+XsIM4zuwn5N4/xRsgKa+SisK92UNMYyl9hVIPKvu/A54cU0zYTdDjYfDGnkurG2RgXDrKIzMpU2LtpoBEtwl3F1H+rzKFJAqe96e39C85GjK1D4s8/TOm3IcHJ5eofeHxI2GeUodysi+DlurRQTSnsUkGa1LXSgkY+4QdlMf+4goNRG5xNdZ8OA2CLY97TPAFqIeej1Amvb9uQBIKvWfbTjDdItBWOhuvAetlNfqnxlcCbnjbCmFTOIbVsHhNW8W1JIElL28mGydbMPimi9brc250E+ImO0Bxp3gMn5oXGV0tUJl5Y8W1lHlEUU7vKK0V7khUob0b3P3lCGQVJyWZEGNodgpr5zkTbR2M8orP4eI9SYoYp2UB0Ag+JkeYSNoQrKZNxSoKBYLVPGzwwGNPBKl7T0CdXlDAOhfZS/FSxdoy8LGRhuTdv7ghQAvstOllibSbjN3wos8ZC8wH2I5LFkekgc4wgcugAwIBEqKBwwSBwMCJkwg3LL7QqlEOunOjvQzpXmA/LMbdtEDyW9b0EQNFL9KFkNuRKDC3V8SFkmG1KlEEHFp2GQNij6AN89xvmEGvhj3tqC280awJs8ve3Bbr7GHRJoFO/sikSRsol1HD/K
 
3sC9OMDufEEItsWf94uu8SmEBpB2OBOzedtfw+PRpoWyYUJYEfAL9T4w0KmBD26KVcehzIv8e3vOl52aT3x9Ovjnw8RfFkZa+t/iGhMpYpf8ApWExZDWBZ6uzVJxcAPg==
 (previous base64 data may contain sensitive data)
Apr 30 13:40:09 auth(?,192.168.1.218,sasl:gssapi)<FhRIDv8zdMzAqAHa>: Debug: 
Auth request finished
Apr 30 13:40:09 auth(?,192.168.1.218,sasl:gssapi)<FhRIDv8zdMzAqAHa>: Debug: 
delaying auth failure
Apr 30 13:40:11 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: client 
passdb out: FAIL   1
Apr 30 13:40:11 auth: Debug: conn unix:login (pid=6791,uid=1000) [1]: 
Disconnected: Connection closed (fd=18)

And the corresponding client log:

noahm@42b23a0b5002:~$ gsasl -m GSSAPI -d --no-starttls --imap dovecot-test 17436
Trying 'dovecot-test'...
* OK [CAPABILITY IMAP4rev1 LOGIN-REFERRALS ID ENABLE IDLE SASL-IR LITERAL+ 
STARTTLS AUTH=PLAIN AUTH=GSSAPI] Dovecot ready.
. CAPABILITY
* CAPABILITY IMAP4rev1 LOGIN-REFERRALS ID ENABLE IDLE SASL-IR LITERAL+ STARTTLS 
AUTH=PLAIN AUTH=GSSAPI
. OK Pre-login capabilities listed, post-login capabilities have more.
. AUTHENTICATE GSSAPI
+ 
YEcGBisGAQUFAqA9MDugDTALBgkqhkiG9xIBAgKjKjAooCYbJG5vdF9kZWZpbmVkX2luX1JGQzQxNzhAcGxlYXNlX2lnbm9yZQ==
YIIDAAYJKoZIhvcSAQICAQBuggLvMIIC66ADAgEFoQMCAQ6iBwMFACAAAACjggIDYYIB/zCCAfugAwIBBaENGwtFWEFNUExFLkNPTaIfMB2gAwIBA6EWMBQbBGltYXAbDGRvdmVjb3QtdGVzdKOCAcIwggG+oAMCARKhAwIBAqKCAbAEggGsj4jD3VOwvfNdLxjc2hqxFsBYyCvjdOCX0R1So6ANZEYnEWddqZwMCuz7BxXv4z+cXaL6g6iGlVkU4RxQyJQHDFUQC8JroTlyMQ+XsIM4zuwn5N4/xRsgKa+SisK92UNMYyl9hVIPKvu/A54cU0zYTdDjYfDGnkurG2RgXDrKIzMpU2LtpoBEtwl3F1H+rzKFJAqe96e39C85GjK1D4s8/TOm3IcHJ5eofeHxI2GeUodysi+DlurRQTSnsUkGa1LXSgkY+4QdlMf+4goNRG5xNdZ8OA2CLY97TPAFqIeej1Amvb9uQBIKvWfbTjDdItBWOhuvAetlNfqnxlcCbnjbCmFTOIbVsHhNW8W1JIElL28mGydbMPimi9brc250E+ImO0Bxp3gMn5oXGV0tUJl5Y8W1lHlEUU7vKK0V7khUob0b3P3lCGQVJyWZEGNodgpr5zkTbR2M8orP4eI9SYoYp2UB0Ag+JkeYSNoQrKZNxSoKBYLVPGzwwGNPBKl7T0CdXlDAOhfZS/FSxdoy8LGRhuTdv7ghQAvstOllibSbjN3wos8ZC8wH2I5LFkekgc4wgcugAwIBEqKBwwSBwMCJkwg3LL7QqlEOunOjvQzpXmA/LMbdtEDyW9b0EQNFL9KFkNuRKDC3V8SFkmG1KlEEHFp2GQNij6AN89xvmEGvhj3tqC280awJs8ve3Bbr7GHRJoFO/sikSRsol1HD/K3sC9OMDufEEItsWf94uu8SmEBpB2OBOzedtfw+PRpoWyYUJYEfAL9T4w0KmBD26KVcehzIv8e3vOl52aT3x9Ovjnw8RfFkZa
 +t/iGhMpYpf8ApWExZDWBZ6uzVJxcAPg==
. NO [AUTHENTICATIONFAILED] Authentication failed.
gsasl: server error

Successful authentication (mutt) dovecot debug log:

Apr 30 13:32:30 auth: Debug: Loading modules from directory: 
/usr/lib/dovecot/modules/auth
Apr 30 13:32:30 auth: Debug: Loading modules from directory: 
/usr/lib/dovecot/modules/auth
Apr 30 13:32:30 auth: Debug: Module loaded: 
/usr/lib/dovecot/modules/auth/libmech_gssapi.so
Apr 30 13:32:30 auth: Debug: Read auth token secret from 
/home/noahm/dovecot-root/b/auth-token-secret.dat
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: Server 
accepted connection (fd=18)
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: auth 
client connected (pid=6788)
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: client 
in: AUTH   1       GSSAPI  protocol=imap   final-resp-ok        
session=4aLx8v4z8JPAqAHa        lip=172.18.0.205        rip=192.168.1.218       
lport=17436     rport=37872 
resp=YIIDAAYJKoZIhvcSAQICAQBuggLvMIIC66ADAgEFoQMCAQ6iBwMFACAAAACjggIDYYIB/zCCAfugAwIBBaENGwtFWEFNUExFLkNPTaIfMB2gAwIBA6EWMBQbBGltYXAbDGRvdmVjb3QtdGVzdKOCAcIwggG+oAMCARKhAwIBAqKCAbAEggGsj4jD3VOwvfNdLxjc2hqxFsBYyCvjdOCX0R1So6ANZEYnEWddqZwMCuz7BxXv4z+cXaL6g6iGlVkU4RxQyJQHDFUQC8JroTlyMQ+XsIM4zuwn5N4/xRsgKa+SisK92UNMYyl9hVIPKvu/A54cU0zYTdDjYfDGnkurG2RgXDrKIzMpU2LtpoBEtwl3F1H+rzKFJAqe96e39C85GjK1D4s8/TOm3IcHJ5eofeHxI2GeUodysi+DlurRQTSnsUkGa1LXSgkY+4QdlMf+4goNRG5xNdZ8OA2CLY97TPAFqIeej1Amvb9uQBIKvWfbTjDdItBWOhuvAetlNfqnxlcCbnjbCmFTOIbVsHhNW8W1JIElL28mGydbMPimi9brc250E+ImO0Bxp3gMn5oXGV0tUJl5Y8W1lHlEUU7vKK0V7khUob0b3P3lCGQVJyWZEGNodgpr5zkTbR2M8orP4eI9SYoYp2UB0Ag+JkeYSNoQrKZNxSoKBYLVPGzwwGNPBKl7T0CdXlDAOhfZS/FSxdoy8LGRhuTdv7ghQAvstOllibSbjN3wos8ZC8wH
 
2I5LFkekgc4wgcugAwIBEqKBwwSBwHCqBBzSB3g1k9BBC5M8XG5NpM35pvpLMHWjw0HIXloN2XjibgczTBt6l+q4DuWo6OWCuf5U+g+BrQ17y52AnCwUk/l722toAEhxwEKA/f3K+7i/lXBzjfCxGTmD2TTO6NUVZUM6TTa6CvwKgGwzGZLh/kQ90VnyzaOyTErL5oiNtl8ZKfguMt38yV8THESf8ZGjxUCKUUa1n3UNClhVk/0Kl88qGD1h11it0yFoNNK5/tbqI5e+sdi+pK4VHsvjPw==
 (previous base64 data may contain sensitive data)
Apr 30 13:32:30 auth(?,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
gssapi: Using all keytab entries
Apr 30 13:32:30 
auth(no...@example.com,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
gssapi: security context state completed.
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: client 
passdb out: CONT   1       
YIGZBgkqhkiG9xIBAgICAG+BiTCBhqADAgEFoQMCAQ+iejB4oAMCARKicQRvsiRFdcazky9GL2l//v2J+U606pbiLSCahGZ2wUxpp05eo9kGAl7j/UQfkzmlOWW7aMfMzPrJTveYBZiDpcfyeTt/wJfAHiEk5A24KYKTIt2ialxe6YOvrmz1e4B+mULZAghrfq5ftdUkQfh0CP/W
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: client 
in: CONT   1        (previous base64 data may contain sensitive data)
Apr 30 13:32:30 
auth(no...@example.com,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
gssapi: Negotiated security layer
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: client 
passdb out: CONT   1       BQQF/wAMAAAAAAAAFUr00gH/////HIlwJEVFPtqhtCU=
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: client 
in: CONT   1       BQQE/wAMAAAAAAAAIfpD4AH///9ub2FobalxyQ7OjgY973Gakw== 
(previous base64 data may contain sensitive data)
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
static: Performing passdb lookup
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
static: lookup
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
static: Finished passdb lookup
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
Credentials: 70656e63696c
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
Auth request finished
Apr 30 13:32:30 auth: Debug: conn unix:login (pid=6788,uid=1000) [1]: client 
passdb out: OK     1       user=noahm      original_user=no...@example.com
Apr 30 13:32:30 auth: Debug: conn unix:/home/noahm/dovecot-root/b/auth-master 
(pid=6790,uid=0): Server accepted connection (fd=19)
Apr 30 13:32:30 auth: Debug: master in: REQUEST 4221435905      6788    1       
6b8a10b34adc8ace171603fc8d378730        session_pid=6790     request_auth_token
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
static: Performing userdb lookup
Apr 30 13:32:30 auth(noahm,192.168.1.218,sasl:gssapi)<4aLx8v4z8JPAqAHa>: Debug: 
static: Finished userdb lookup
Apr 30 13:32:30 auth: Debug: master userdb out: USER    4221435905      noahm   
uid=4711        gid=4711        home=/home/noahm/dovecot-root        
auth_mech=GSSAPI        auth_token=705494201f3425a0145e2f7af1edca82fee2ee17     
auth_user=no...@example.com

The corresponding client-side logs generated by mutt are:

[2025-04-30 13:32:30] Connecting to dovecot-test...
[2025-04-30 13:32:30] Connected to dovecot-test:17436 on fd=4
[2025-04-30 13:32:30] 4< * OK [CAPABILITY IMAP4rev1 LOGIN-REFERRALS ID ENABLE 
IDLE SASL-IR LITERAL+ STARTTLS AUTH=PLAIN AUTH=GSSAPI] Dovecot ready.
[2025-04-30 13:32:30] imap_authenticate: Trying method gssapi
[2025-04-30 13:32:30] imap_auth_gsasl: using mech GSSAPI
[2025-04-30 13:32:30] Authenticating (GSSAPI)...
[2025-04-30 13:32:30] 4> a0000 AUTHENTICATE GSSAPI 
YIIDAAYJKoZIhvcSAQICAQBuggLvMIIC66ADAgEFoQMCAQ6iBwMFACAAAACjggIDYYIB/zCCAfugAwIBBaENGwtFWEFNUExFLkNPTaIfMB2gAwIBA6EWMBQbBGltYXAbDGRvdmVjb3QtdGVzdKOCAcIwggG+oAMCARKhAwIBAqKCAbAEggGsj4jD3VOwvfNdLxjc2hqxFsBYyCvjdOCX0R1So6ANZEYnEWddqZwMCuz7BxXv4z+cXaL6g6iGlVkU4RxQyJQHDFUQC8JroTlyMQ+XsIM4zuwn5N4/xRsgKa+SisK92UNMYyl9hVIPKvu/A54cU0zYTdDjYfDGnkurG2RgXDrKIzMpU2LtpoBEtwl3F1H+rzKFJAqe96e39C85GjK1D4s8/TOm3IcHJ5eofeHxI2GeUodysi+DlurRQTSnsUkGa1LXSgkY+4QdlMf+4goNRG5xNdZ8OA2CLY97TPAFqIeej1Amvb9uQBIKvWfbTjDdItBWOhuvAetlNfqnxlcCbnjbCmFTOIbVsHhNW8W1JIElL28mGydbMPimi9brc250E+ImO0Bxp3gMn5oXGV0tUJl5Y8W1lHlEUU7vKK0V7khUob0b3P3lCGQVJyWZEGNodgpr5zkTbR2M8orP4eI9SYoYp2UB0Ag+JkeYSNoQrKZNxSoKBYLVPGzwwGNPBKl7T0CdXlDAOhfZS/FSxdoy8LGRhuTdv7ghQAvstOllibSbjN3wos8ZC8wH2I5LFkekgc4wgcugAwIBEqKBwwSBwHCqBBzSB3g1k9BBC5M8XG5NpM35pvpLMHWjw0HIXloN2XjibgczTBt6l+q4DuWo6OWCuf5U+g+BrQ17y52AnCwUk/l722toAEhxwEKA/f3K+7i/lXBzjfCxGTmD2TTO6NUVZUM6TTa6CvwKgGwzGZLh/kQ90VnyzaOyTErL5oiNtl8
 
ZKfguMt38yV8THESf8ZGjxUCKUUa1n3UNClhVk/0Kl88qGD1h11it0yFoNNK5/tbqI5e+sdi+pK4VHsvjPw==
[2025-04-30 13:32:30] 4< + 
YIGZBgkqhkiG9xIBAgICAG+BiTCBhqADAgEFoQMCAQ+iejB4oAMCARKicQRvsiRFdcazky9GL2l//v2J+U606pbiLSCahGZ2wUxpp05eo9kGAl7j/UQfkzmlOWW7aMfMzPrJTveYBZiDpcfyeTt/wJfAHiEk5A24KYKTIt2ialxe6YOvrmz1e4B+mULZAghrfq5ftdUkQfh0CP/W
[2025-04-30 13:32:30] 4> 
[2025-04-30 13:32:30] 4< + BQQF/wAMAAAAAAAAFUr00gH/////HIlwJEVFPtqhtCU=
[2025-04-30 13:32:30] 4> BQQE/wAMAAAAAAAAIfpD4AH///9ub2FobalxyQ7OjgY973Gakw==
[2025-04-30 13:32:30] 4< a0000 OK [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS 
ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS 
THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN 
NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT 
SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE REPLACE SNIPPET=FUZZY 
PREVIEW=FUZZY PREVIEW SPECIAL-USE STATUS=SIZE SAVEDATE COMPRESS=DEFLATE 
INPROGRESS NOTIFY LITERAL+] Logged in


_______________________________________________
dovecot mailing list -- dovecot@dovecot.org
To unsubscribe send an email to dovecot-le...@dovecot.org

Reply via email to