GSSAPI authentication regression with 2.4.x
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/K3sC9OMDufEEItsWf94uu8SmEBpB2OBOzedtfw+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/FSxdoy8LGRhuTdv7ghQAvstOllibSbjN3wos8ZC8wH2I5LFkekgc4wgcugAwIBEqKBwwSBwHCqBBzSB3g1k9BBC5M8XG5NpM35pvpLMHWjw0HIXloN2XjibgczTBt6l+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(noahm@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(noahm@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=noahm@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=noahm@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/kQ90VnyzaOyTErL5oiNtl8ZKfguMt38yV8THESf8ZGjxUCKUUa1n3UNClhVk/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
GSSAPI is one of these pretty opaque protocols. Since it works with mutt, and does not work with gsasl, it could be some thing with gsasl.
I can only see one change in mech-gssapi, we use mech_gssapi_krb5_userok() always. Also we have added support for final response prosessing, which was missing in 2.3.21.1.
Aki
On 30/04/2025 18:28 EEST Noah Meyerhans via dovecot <dovecot@dovecot.org> wrote:
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+PRpoWyYUJYEfAL9T4w0KmBD26KVcehzIv8e3vOl52aT3x9Ovjnw8RfFk Za +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/FSxdoy8LGRhuTdv7ghQAvstOllibSbjN3wos8ZC8 wH 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(noahm@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(noahm@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=noahm@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=noahm@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/kQ90VnyzaOyTErL5oiNt l8 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-leave@dovecot.org
On Wed, Apr 30, 2025 at 08:30:16PM +0300, Aki Tuomi wrote:
GSSAPI is one of these pretty opaque protocols. Since it works with mutt, and does not work with gsasl, it could be some thing with gsasl.
It could, but the same gsasl version can authenticate against dovecot 2.3.31. I will attempt to repro the issue with other clients.
I can only see one change in mech-gssapi, we use mech_gssapi_krb5_userok() always. Also we have added support for final response prosessing, which was missing in 2.3.21.1.
I'm testing a build with the mech_gssapi_krb5_userok() change reverted, because I agree that it's the only change that appears relevant. Will post results when I have them.
noah
On Wed, Apr 30, 2025 at 08:30:16PM +0300, Aki Tuomi via dovecot wrote:
GSSAPI is one of these pretty opaque protocols. Since it works with mutt, and does not work with gsasl, it could be some thing with gsasl.
I can only see one change in mech-gssapi, we use mech_gssapi_krb5_userok() always. Also we have added support for final response prosessing, which was missing in 2.3.21.1.
I've traced the issue to commit 1486c30 ("auth: Add support for channel binding"). With this commit reverted (along with 848cceb25c2 ("auth: mech-scram - Implement SCRAM-SHA-1-PLUS and SCRAM-SHA-256-PLUS"), which depends on it but isn't related to gssapi handling) then authentication from gsasl is again possible.
I haven't looked deeply into exactly what in this commit is causing the regression yet.
https://github.com/dovecot/core/commit/1486c30e191 https://github.com/dovecot/core/commit/848cceb25c2
noah
Op 1-5-2025 om 21:36 schreef Noah Meyerhans via dovecot:
On Wed, Apr 30, 2025 at 08:30:16PM +0300, Aki Tuomi via dovecot wrote:
GSSAPI is one of these pretty opaque protocols. Since it works with mutt, and does not work with gsasl, it could be some thing with gsasl.
I can only see one change in mech-gssapi, we use mech_gssapi_krb5_userok() always. Also we have added support for final response prosessing, which was missing in 2.3.21.1.
I've traced the issue to commit 1486c30 ("auth: Add support for channel binding"). With this commit reverted (along with 848cceb25c2 ("auth: mech-scram - Implement SCRAM-SHA-1-PLUS and SCRAM-SHA-256-PLUS"), which depends on it but isn't related to gssapi handling) then authentication from gsasl is again possible.
I haven't looked deeply into exactly what in this commit is causing the regression yet.
https://github.com/dovecot/core/commit/1486c30e191 https://github.com/dovecot/core/commit/848cceb25c2
I am having some difficulty setting up an environment to test this right now, but I think this should fix it: diff --git a/src/auth/mech-gssapi.c b/src/auth/mech-gssapi.c index 57a2b125b2..4ff5716528 100644 --- a/src/auth/mech-gssapi.c +++ b/src/auth/mech-gssapi.c @@ -672,7 +672,7 @@ mech_gssapi_auth_initial(struct auth_request *request, if (data_size == 0) { /* The client should go first */ - auth_request_handler_reply_continue(request, NULL, 0); + auth_request_handler_reply_continue(request, uchar_empty_ptr, 0); } else { mech_gssapi_auth_continue(request, data, data_size); } Regards, Stephan.
noah
_______________________________________________ dovecot mailing list -- dovecot@dovecot.org To unsubscribe send an email to dovecot-leave@dovecot.org
On Fri, May 02, 2025 at 04:57:42AM +0200, Stephan Bosch wrote:
I am having some difficulty setting up an environment to test this right now, but I think this should fix it:
diff --git a/src/auth/mech-gssapi.c b/src/auth/mech-gssapi.c index 57a2b125b2..4ff5716528 100644 --- a/src/auth/mech-gssapi.c +++ b/src/auth/mech-gssapi.c @@ -672,7 +672,7 @@ mech_gssapi_auth_initial(struct auth_request *request,
if (data_size == 0) { /* The client should go first */ - auth_request_handler_reply_continue(request, NULL, 0); + auth_request_handler_reply_continue(request, uchar_empty_ptr, 0); } else { mech_gssapi_auth_continue(request, data, data_size); }
Thank you, this does seem to fix the issue. In case it helps, I've found the test script used by gsasl and libgssglue to be quite useful for testing this functionality. It sets up a minimal Kerberos realm, dovecot server, and GSSAPI IMAP client. A version that works with dovecot 2.4 is available at https://salsa.debian.org/noahm/libgssglue/-/blob/0504956891696208d412cceb912... noah
participants (5)
-
Aki Tuomi
-
Noah Meyerhans
-
Noah Meyerhans
-
Noah Meyerhans
-
Stephan Bosch