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///9xheyHOAR4oKi3t3MJul 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
