[Freeipa-users] Errors when trying IPA,Dovecot GSSAPI.
M.R Niranjan
mniranja at redhat.com
Wed Mar 6 14:46:21 UTC 2013
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
On 03/06/2013 08:03 PM, Johan Petersson wrote:
> Hi,
> I hope someone here can shed some light on what is wrong in my test
> environment.
> The error seem to be that Dovecot on mail server wants to access mail
> folder in my home directory on the NFS Server but can't get credentials
> for it. rpc.gssd on Mail Server try either to open a cachefile in /tmp
> that is corrupt or expired or if no cache file exists it just do error
> downcall.
> No try to update the key or create a new one.
> Should not forwardable tickets update the cache or generate a new one?
> The permission denied error in maillog i believe is because of no valid
> kerberos credentials.
>
> IPAserver
> NFS Server for Home Directory through autofs, IPA Client with
> nfs/share.test.net
> Mail server IPA Client with imap/mail.test.net,smtp/mail.test.net
>
> Clients pc's that are also IPA clients
>
> Everything is Red Hat 6.4 server and Client with default settings for
> IPA server and client.
>
> When trying to get mail i get ticket not accepted but i do get a imap
> ticket that i can see with klist.
>
> Ticket cache: FILE:/tmp/krb5cc_1644800003_UsqtSh
> Default principal: johan at TEST.NET
>
> Valid starting Expires Service principal
> 03/06/13 14:34:28 03/07/13 14:34:28 krbtgt/TEST.NET at TEST.NET
> 03/06/13 14:40:41 03/07/13 14:34:28 imap/mail.test.net at TEST.NET
> 03/06/13 14:44:43 03/07/13 14:34:28 host/share.test.net at TEST.NET
>
> Hopefully relevant logs:
>
> Mail Server /var/log/messages with rpc.gssapi -vvv:
>
> Mar 6 14:43:21 mail rpc.gssd[1143]: handling gssd upcall
> (/var/lib/nfs/rpc_pipefs/nfs/clnt12)
> Mar 6 14:43:21 mail rpc.gssd[1143]: handle_gssd_upcall: 'mech=krb5
> uid=1644800003 enctypes=18,17,16,23,3,1,2 '
> Mar 6 14:43:21 mail rpc.gssd[1143]: handling krb5 upcall
> (/var/lib/nfs/rpc_pipefs/nfs/clnt12)
> Mar 6 14:43:21 mail rpc.gssd[1143]: process_krb5_upcall: service is
> '<null>'
> Mar 6 14:43:21 mail rpc.gssd[1143]: getting credentials for client with
> uid 1644800003 for server share.test.net
> Mar 6 14:43:21 mail rpc.gssd[1143]: CC file
> '/tmp/krb5cc_machine_TEST.NET' being considered, with preferred realm
> 'TEST.NET'
> Mar 6 14:43:21 mail rpc.gssd[1143]: CC file
> '/tmp/krb5cc_machine_TEST.NET' owned by 0, not 1644800003
> Mar 6 14:43:21 mail rpc.gssd[1143]: CC file
> '/tmp/krb5cc_1644800001_MOFHds' being considered, with preferred realm
> 'TEST.NET'
> Mar 6 14:43:21 mail rpc.gssd[1143]: CC file
> '/tmp/krb5cc_1644800001_MOFHds' owned by 0, not 1644800003
> Mar 6 14:43:21 mail rpc.gssd[1143]: CC file '/tmp/krb5cc_0' being
> considered, with preferred realm 'TEST.NET'
> Mar 6 14:43:21 mail rpc.gssd[1143]: CC file '/tmp/krb5cc_0' owned by 0,
> not 1644800003
> Mar 6 14:43:21 mail rpc.gssd[1143]: WARNING: Failed to create krb5
> context for user with uid 1644800003 for server share.test.net
> Mar 6 14:43:21 mail rpc.gssd[1143]: doing error downcall
>
> Mail Server /var/log/maillog:
>
> Mar 06 14:43:11 master: Info: Dovecot v2.0.9 starting up (core dumps
> disabled)
> Mar 06 14:43:21 auth: Debug: Loading modules from directory:
> /usr/lib64/dovecot/auth
> Mar 06 14:43:21 auth: Debug: Module loaded:
> /usr/lib64/dovecot/auth/libauthdb_ldap.so
> Mar 06 14:43:21 auth: Debug: Module loaded:
> /usr/lib64/dovecot/auth/libdriver_sqlite.so
> Mar 06 14:43:21 auth: Debug: Module loaded:
> /usr/lib64/dovecot/auth/libmech_gssapi.so
> Mar 06 14:43:21 auth: Debug: auth client connected (pid=2183)
> Mar 06 14:43:21 auth: Debug: client in: AUTH 1 GSSAPI
> service=imap secured lip=192.168.0.33 rip=192.168.0.202
> lport=143 rport=36424
> Mar 06 14:43:21 auth: Debug: gssapi(?,192.168.0.202): Using all keytab
> entries
> Mar 06 14:43:21 auth: Debug: client out: CONT 1
> Mar 06 14:43:21 auth: Debug: client in: CONT<hidden>
> Mar 06 14:43:21 auth: Debug: gssapi(johan at TEST.NET,192.168.0.202):
> security context state completed.
> Mar 06 14:43:21 auth: Debug: client out: CONT 1
> YIGZBgkqhkiG9xIBAgICAG+BiTCBhqADAgEFoQMCAQ+iejB4oAMCARKicQRv1MwL+M8NJprfWznLmhNSKz2ONwOwvw+2nJkIlLZiRLgIfQECmsAnkj6v54ukCkFNkcl0eCKTuHX9/8CTSpBQZL0RpeHHqfqMDDVRtKuiVaK7DzFOf/RC2ZTKmRD4l54p4PF5KA39L3VTNbkKhsIN
> Mar 06 14:43:21 auth: Debug: client in: CONT<hidden>
> Mar 06 14:43:21 auth: Debug: gssapi(johan at TEST.NET,192.168.0.202):
> Negotiated security layer
> Mar 06 14:43:21 auth: Debug: client out: CONT 1
> BQQF/wAMAAAAAAAAN4/a0gH///+o8Mw0PdRlusfHcCo=
> Mar 06 14:43:21 auth: Debug: client in: CONT<hidden>
> Mar 06 14:43:21 auth: Debug: client out: OK 1 user=johan
> Mar 06 14:43:21 auth: Debug: master in: REQUEST 1818361857 2183
> 1 2f9e416bebaaac9a0a3f266165753c1b
> Mar 06 14:43:21 auth: Debug: passwd(johan,192.168.0.202): lookup
> Mar 06 14:43:21 auth: Debug: master out: USER 1818361857 johan
> system_groups_user=johan uid=1644800003 gid=1644800003
> home=/nethome/johan
> Mar 06 14:43:21 imap-login: Info: Login: user=<johan>, method=GSSAPI,
> rip=192.168.0.202, lip=192.168.0.33, mpid=2186, TLS
> Mar 06 14:43:21 imap(johan): Error: chdir(/nethome/johan/) failed:
> Permission denied (euid=1644800003(johan) egid=1644800003(johan) missing
> +x perm: /nethome/johan, euid is not dir owner)
> Mar 06 14:43:21 imap(johan): Error: chdir(/nethome/johan) failed:
> Permission denied
> Mar 06 14:43:21 imap(johan): Error: user johan: Initialization failed:
> Initializing mail storage from mail_location setting failed:
> stat(/nethome/johan/mail) failed: Permission denied
> (euid=1644800003(johan) egid=1644800003(johan) missing +x perm:
> /nethome/johan, euid is not dir owner)
> Mar 06 14:43:21 imap(johan): Error: Invalid user settings. Refer to
> server log for more information.
>
> NFS Server /var/log/messages with rpc.svcgssd -vvv:
>
> Mar 6 14:43:21 share rpc.svcgssd[17422]: handling null request
> Mar 6 14:43:21 share rpc.svcgssd[17422]: svcgssd_limit_krb5_enctypes:
> Calling gss_set_allowable_enctypes with 7 enctypes from the kernel
> Mar 6 14:43:21 share rpc.svcgssd[17422]: sname = nfs/mail.test.net at TEST.NET
> Mar 6 14:43:21 share rpc.svcgssd[17422]: DEBUG: serialize_krb5_ctx:
> lucid version!
> Mar 6 14:43:21 share rpc.svcgssd[17422]: prepare_krb5_rfc4121_buffer:
> protocol 1
> Mar 6 14:43:21 share rpc.svcgssd[17422]: prepare_krb5_rfc4121_buffer:
> serializing key with enctype 18 and size 32
> Mar 6 14:43:21 share rpc.svcgssd[17422]: doing downcall
> Mar 6 14:43:21 share rpc.svcgssd[17422]: mech: krb5, hndl len: 4, ctx
> len 52, timeout: 1362657132 (79731 from now), clnt: nfs at mail.test.net,
> uid: -1, gid: -1, num aux grps: 0:
> Mar 6 14:43:21 share rpc.svcgssd[17422]: sending null reply
> Mar 6 14:43:21 share rpc.svcgssd[17422]: writing message: \x
> \x6082026406092a864886f71201020201006e8202533082024fa003020105a10302010ea20703050020000000a382015d6182015930820155a003020105a10a1b08544553542e4e4554a220301ea003020103a11730151b036e66731b0e73686172652e746573742e6e6574a382011e3082011aa003020112a103020101a282010c048201080bd88fab1779cae6f283c843e375c2771728abafc384c52f50cc7b2af86583170f495fd96ad3665acb035e08fdac19c820c8ed16fa1120409d165b7eec74e418c11f3d24601c6ad2ee752185f20b4c9667a52dd8e11485e2aef2d5f7fd3ae6991d097e303287e5627f83dc514bca1932262dfa0df4836d55541a6dbce88cc88678cb037acdeada894dc4f3c0dbeaf7f157c9d57e6193ed3ca917f467b17291b4661742f6755a73c8c2b6b9d2b23334ee1cc3b108ee3d825db5edd042c7f9441afe76422f69c400620160fe415e28cdbe9637ca20062cad2999a453c4c4e4e694577bb7f861db6071759a4a0692ce0988fe9c6bdae423f04d22c8f5090d0f76ce235db4ceb9fe13fca481d83081d5a003020112a281cd0481ca1eb49a3eb4c68ce63349590168de47cd5af0bdcaa8a21434f3cbba3ec41a4469bae62d4dd65d037d6c02fcb0a24ff9679a22ab7ffd48857ea7b72f12ab3776c8d28b
> 27a985a0fa53bfc162da8fda7e8ca49a2e57093f2af0bc4d2a4148420aa1bacb8f7bc4313650060ccae01426ff752405aab2f52ed332f0ac5e670e0013acf9acef23e0e1e5beb85b497d506526aed62a0718377d7e360ce9d5ddf812d02839daa6ee62887e0370a63a49f0345f2eb0d4f9f069c983ed0c63cec039e97378d5abe4eeb214c2e735af
> 1362577461 0 0 \xbc000000
> \x60819906092a864886f71201020202006f8189308186a003020105a10302010fa27a3078a003020112a271046f598391477156abf0dce0a5d58927fc329174a95f47e0dbfb6ab9e77937ba24047c50beafed6bff70e4d133c6304bfb8b47e48b3c17b87ff5a3f44095ab138804a821c155e80410d0f8ec1e663416e935b50c1a90b030d828d7d6c9d2199a46193a04fb32dbd88f18984d5913a3bc60
> Mar 6 14:43:21 share rpc.svcgssd[17422]: finished handling null request
> Mar 6 14:43:21 share rpc.svcgssd[17422]: entering poll
>
> IPA Server /var/log/dirsrv/slapd-TEST-NET/access:
>
> [06/Mar/2013:14:43:21 +0100] conn=1273 fd=70 slot=70 connection from
> 192.168.0.33 to 192.168.0.30
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=0 BIND dn="" method=sasl
> version=3 mech=GSSAPI
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=0 RESULT err=14 tag=97
> nentries=0 etime=0, SASL bind in progress
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=1 BIND dn="" method=sasl
> version=3 mech=GSSAPI
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=1 RESULT err=14 tag=97
> nentries=0 etime=0, SASL bind in progress
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=2 BIND dn="" method=sasl
> version=3 mech=GSSAPI
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=2 RESULT err=0 tag=97
> nentries=0 etime=0
> dn="fqdn=mail.test.net,cn=computers,cn=accounts,dc=test,dc=net"
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=3 SRCH
> base="automountmapname=auto_nethome,cn=default,cn=automount,dc=test,dc=net"
> scope=2
> filter="(&(objectClass=automount)(|(automountKey=johan)(automountKey=/)(automountKey=\2a)))"
> attrs="automountKey automountInformation"
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=3 RESULT err=0 tag=101
> nentries=1 etime=0
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=4 UNBIND
> [06/Mar/2013:14:43:21 +0100] conn=1273 op=4 fd=70 closed - U1
> [06/Mar/2013:14:43:21 +0100] conn=1270 op=16 SRCH
> base="cn=accounts,dc=test,dc=net" scope=2
> filter="(&(uid=nfs/mail.test.net)(objectClass=posixAccount))"
> attrs="objectClass uid userPassword uidNumber gidNumber gecos
> homeDirectory loginShell krbPrincipalName cn memberOf nsUniqueId
> modifyTimestamp entryusn shadowLastChange shadowMin shadowMax
> shadowWarning shadowInactive shadowExpire shadowFlag krbLastPwdChange
> krbPasswordExpiration pwdattribute authorizedService accountexpires
> useraccountcontrol nsAccountLock host logindisabled loginexpirationtime
> loginallowedtimemap ipaSshPubKey"
> [06/Mar/2013:14:43:21 +0100] conn=1270 op=16 RESULT err=0 tag=101
> nentries=0 etime=0
>
> Regards,
> Johan.
>
>
> _______________________________________________
> Freeipa-users mailing list
> Freeipa-users at redhat.com
> https://www.redhat.com/mailman/listinfo/freeipa-users
>
Can you check if the below article helps:
http://www.freeipa.org/page/Dovecot_IMAPS_Integration_with_FreeIPA_using_Single_Sign_On
- --
Regards
M.R.Niranjan
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.13 (GNU/Linux)
Comment: Using GnuPG with undefined - http://www.enigmail.net/
iEYEARECAAYFAlE3Vr0ACgkQLu3FX2BHx8cFBACfdCG8KmmLhvnURf+ZYlwzbJVg
fxMAn3RpGJ+x9qfI8T7Wd6iq5fVrDckM
=e4L3
-----END PGP SIGNATURE-----
More information about the Freeipa-users
mailing list