[Freeipa-users] Errors when trying IPA,Dovecot GSSAPI.

Wed Mar 6 15:00:04 UTC 2013

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 03/06/2013 02:46 PM, M.R Niranjan wrote:
> 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

There is a caveat to that article. Not sure if you remember where we got
up to with that Niranjan, but basically authentication kept failing for
ipa users if the user's mail spool was not already present.

Just keep that in mind if you manage to get that far.

Dale

>
> _______________________________________________
> Freeipa-users mailing list
> Freeipa-users at redhat.com
> https://www.redhat.com/mailman/listinfo/freeipa-users

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.13 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBAgAGBQJRN1nzAAoJEAJsWS61tB+qoksP/j4XVd7eFfBxOWqTX8Ti9edL
s1S+AxXgy1DB9AGjzwTy50w4ItUe9Z5JmS3VjrMWb+Cslcpq83CsOrRLpWKaLQrL
3h9t4E6rY5OalKXw0QUoo1GVuTcYfgRsDawqTzzdBWrkol0Gx6AcWhwwUViyKcMg
XP4N/wshnv1YCzqvXcqYAC0Tq/qc6H0mQM4NbAQzdSXCuDVxi7zcZ57/dARodlO5
UaDetP7Ku3Xfv8nBHBpmBEmbYmA3t861v4fvCvmQB4Nnn8t0BDswkS5vZ5Kv057S
D7faVM3Y3La8W5w0t1PAIYl94aOpE45mgUTMtYynZTYX5+uOSW7R1niGnGRJt4IG
ii4GLnyK0WIRzvo+adnUnLxNmJtPo1TEJHGjZ7HZZE2BkiMbcZQFV4mGmDFhJQ15
yFCYggPZVhAhYnBTjwA7lC/vMCUHfVeqm0Cw2Yg3OfpXcPfvKofNazscyRzcicg6
iINqdEtU3O0IRc80S3yfi8kKBQh9YKEfsysUZ6l+Ti7pEqgkuiyYLLuFoBzZgSpd
cI8EU1+uYwipS2lBe2Hu87JSh/qxw2TstIx/CqvjtrtRfFnEllEi0q+58+0L7JW3
ALkSuyujkZOSd8ygp2AdXdkLNTjsqKz3IOXtJWcLCrOZ7GFbAREIzeWKEuJoMc/w
WAlcQ0t0r8o+OMdl53Iz
=G9EX
-----END PGP SIGNATURE-----

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20130306/8a61bd54/attachment.htm>