Cannot Authenticate user with Kerberos/GSSAPI
mark at ohprs.org
mark at ohprs.org
Wed Jul 12 22:57:00 EEST 2017
My last message probably contained too much information. This one is more succient.
I have a user, 'mark', who has been running a Thunderbird client on Windows to Dovecot server
with Kerberos/GSSAPI authentication for over a year. I created a new Tbird account on a new
Linux workstation for 'mark', also with Kerberos/GSSAPI and that worked just fine.
I have another user, 'dsmith', who has been running a Thunderbird client on Windows to Dovecot
server with Kerberos/GSSAPI authentication for over a year as well, no problems. I created a
new Tbird account on the same new Linux workstation as above for 'dsmith', also with
KerberosGSSAPI and that DID NOT WORK! I get the message in Thunderbird:
"The Kerberos/GSSAPI ticket was not accepted by the IMAP server ... please check that you
are logged into the Kerberos/GSSAPI realm."
I created/recreated the smith account numerous time with slightly different settings hoping
something will work, but I always get the same message.
Why? I need to figure this out ASAP.
Here is the dovecot log when user dsmith attempts to connect to dovecot from the Tbird client:
Jul 11 19:29:43 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Jul 11 19:29:43 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Jul 11 19:29:43 auth: Debug: Loading modules from directory: /usr/local/lib/dovecot/auth
Jul 11 19:29:43 auth: Debug: Read auth token secret from /usr/local/var/run/dovecot/auth-token-secret.dat
Jul 11 19:29:43 auth: Debug: auth client connected (pid=1578)
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv2/v3 read client hello A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client certificate A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read certificate verify A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [192.168.0.57]
Jul 11 19:29:46 imap-login: Debug: SSL alert: close notify [192.168.0.57]
Jul 11 19:29:46 imap-login: Info: Disconnected (no auth attempts in 3 secs): user=<>, rip=192.168.0.57, lip=192.168.0.2, TLS, session=<jR0sExNUTADAqAA5>
Jul 11 19:30:17 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Jul 11 19:30:17 imap-login: Debug: SSL: elliptic curve secp384r1 will be used for ECDH and ECDHE key exchanges
Jul 11 19:30:17 auth: Debug: auth client connected (pid=3148)
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x10, ret=1: before/accept initialization [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: before/accept initialization [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv2/v3 read client hello A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client hello A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server hello A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write certificate A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write key exchange A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write server done A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client certificate A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2002, ret=-1: SSLv3 read client key exchange A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read client key exchange A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read certificate verify A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 read finished A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write session ticket A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write change cipher spec A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 write finished A [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2001, ret=1: SSLv3 flush data [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x20, ret=1: SSL negotiation finished successfully [192.168.0.57]
Jul 11 19:30:17 imap-login: Debug: SSL: where=0x2002, ret=1: SSL negotiation finished successfully [192.168.0.57]
Jul 11 19:30:17 auth: Debug: client in: AUTH 1 GSSAPI service=imap secured session=iDUNFRNUUgDAqAA5 lip=192.168.0.2 rip=192.168.0.57 lport=143 rport=58962
Jul 11 19:30:17 auth: Debug: gssapi(?,192.168.0.57,<iDUNFRNUUgDAqAA5>): Using all keytab entries
Jul 11 19:30:17 auth: Debug: client passdb out: CONT 1
Jul 11 19:30:17 auth: Debug: client in: CONT 1 YIIE+ [deleted]
Jul 11 19:30:18 auth: Debug: gssapi(dsmith,192.168.0.57,<iDUNFRNUUgDAqAA5>): security context state completed.
Jul 11 19:30:18 auth: Debug: client passdb out: CONT 1 YIGVB [deleted]
Jul 11 19:30:18 auth: Debug: client in: CONT 1 (previous base64 data may contain sensitive data)
Jul 11 19:30:18 auth: Debug: gssapi(dsmith,192.168.0.57,<iDUNFRNUUgDAqAA5>): Negotiated security layer
Jul 11 19:30:18 auth: Debug: client passdb out: CONT 1 BQQF/wAMAAAAAAAAFxWx/AH///9xheyHOAR4oKi3t3M=
Jul 11 19:30:18 auth: Debug: client in: CONT 1 BQQE/wAMAAAAAAAANRcNbgEAAABkc21pdGjS3NSV6TWvt53rOLY= (previous base64 data may contain sensitive data)
Jul 11 19:30:18 auth-worker(3149): Debug: Loading modules from directory: /usr/local/lib/dovecot/auth
Jul 11 19:30:18 auth-worker(3149): Debug: shadow(dsmith,192.168.0.57): lookup
Jul 11 19:30:18 auth-worker(3149): Info: shadow(dsmith,192.168.0.57): unknown user
Jul 11 19:30:18 auth: Debug: shadow(dsmith,192.168.0.57,<iDUNFRNUUgDAqAA5>): Credentials:
Jul 11 19:30:18 auth: Debug: client passdb out: OK 1 user=dsmith original_user=dsmith at HPRS.LOCAL
Jul 11 19:30:18 auth: Debug: master in: REQUEST 432275457 3148 1 3f58f611e9a6450ad7291105a93bbe1f session_pid=3150 request_auth_token
Jul 11 19:30:18 auth-worker(3149): Debug: shadow(dsmith,192.168.0.57): lookup
Jul 11 19:30:18 auth-worker(3149): Debug: shadow(dsmith,192.168.0.57): username changed dsmith -> HPRS\dsmith
Jul 11 19:30:18 auth: Debug: master userdb out: USER 432275457 dsmith system_groups_user=HPRS\dsmithuid=3000036 gid=10000 home=/home/HPRS/dsmith auth_token=9ad7ad520ac8da70d07b3353b1c9c4e6ef394004 auth_user=dsmith at HPRS.LOCAL
Jul 11 19:30:18 imap-login: Info: Login: user=<dsmith>, method=GSSAPI, rip=192.168.0.57, lip=192.168.0.2, mpid=3150, TLS, session=<iDUNFRNUUgDAqAA5>
Thanks, Mark
More information about the dovecot
mailing list