[Date Prev][Date Next] [Chronological] [Thread] [Top]
Re: Kerberos, GSSAPI Miscellaneous failure

To: "Donald Norwood" <dnorwood@portalias.net>
Subject: Re: Kerberos, GSSAPI Miscellaneous failure
From: "Nicholas Clark" <nclark1@gmu.edu>
Date: Sun, 18 Sep 2005 14:27:35 -0400 (EDT)
Cc: sujiannming@gmail.com, openldap-software@OpenLDAP.org
Importance: Normal
In-reply-to: <3454.70.108.197.104.1127062919.squirrel@70.108.197.104>
References: <f88b8080dc9e.432b26e8@gmu.edu> <561dc3260509161959194df71@mail.gmail.com> <1857.70.108.197.104.1126966022.squirrel@70.108.197.104> <432CAF88.6090606@portalias.net> <3454.70.108.197.104.1127062919.squirrel@70.108.197.104>
User-agent: SquirrelMail/1.5.0
I was pulling all the debug info from the logs and hadn't tried running
slapd in debug mode. I just ran slapd as root in debug mode and suddenly
it worked! This must be some sort of permission problem.. although the
ldap.keytab file is owned by user/group ldap and set to 0640. Are there
other permissions that need to be set elsewhere? I must be missing
something.


>
> "SASL/GSSAPI authentication started
> ldap_sasl_interactive_bind_s: Internal (implementation specific) error
> (80)
>         additional info: SASL(-1): generic failure: GSSAPI Error:
> Miscellaneous failure (Resource temporarily unavailable)"
>
>
> See logs below from trying to run an ldapsearch. I am authenticated via
> kerberos and klist shows the following after running the search:
>
> -bash-3.00$ klist
> Ticket cache: FILE:/tmp/krb5cc_11000_MGvei4
> Default principal: dummyuser@NETLAB.GMU.EDU
>
> Valid starting     Expires            Service principal
> 09/18/05 12:55:10  09/18/05 22:55:10  krbtgt/NETLAB.GMU.EDU@NETLAB.GMU.EDU
>         renew until 09/18/05 12:55:10
> 09/18/05 12:56:10  09/18/05 22:55:10
> ldap/ldap.netlab.gmu.edu@NETLAB.GMU.EDU
>         renew until 09/18/05 12:55:10
>
>
> Kerberos 4 ticket cache: /tmp/tkt11000
> klist: You have no tickets cached
>
>
> Sep 18 12:57:07 socrates slapd[17192]: daemon: activity on 1 descriptors
> Sep 18 12:57:07 socrates slapd[17192]: daemon: new connection on 19
> Sep 18 12:57:07 socrates slapd[17192]: daemon: added 19r
> Sep 18 12:57:07 socrates slapd[17192]: daemon: activity on:
> Sep 18 12:57:07 socrates slapd[17192]:
> Sep 18 12:57:07 socrates slapd[17192]: daemon: select: listen=6
> active_threads=1 tvp=zero
> Sep 18 12:57:07 socrates slapd[17192]: daemon: select: listen=7
> active_threads=1 tvp=zero
> Sep 18 12:57:07 socrates slapd[17192]: daemon: select: listen=8
> active_threads=1 tvp=zero
> Sep 18 12:57:07 socrates slapd[17192]: daemon: select: listen=9
> active_threads=1 tvp=zero
> Sep 18 12:57:07 socrates slapd[17192]: daemon: activity on 1 descriptors
> Sep 18 12:57:07 socrates slapd[17192]: daemon: activity on:
> Sep 18 12:57:07 socrates slapd[17192]:  19r
> Sep 18 12:57:07 socrates slapd[17192]:
> Sep 18 12:57:07 socrates slapd[17192]: daemon: read activity on 19
> Sep 18 12:57:07 socrates slapd[17192]: connection_get(19)
> Sep 18 12:57:07 socrates slapd[17192]: connection_get(19): got connid=7
> Sep 18 12:57:07 socrates slapd[17192]: connection_read(19): checking for
> input on id=7
> Sep 18 12:57:07 socrates slapd[17192]: ber_get_next on fd 19 failed
> errno=11 (Resource temporarily unavailable)
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=6
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=7
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=8
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=9
> active_threads=1 tvp=zero
> Sep 18 12:57:07 socrates slapd[17192]: do_search
> Sep 18 12:57:08 socrates slapd[17192]: >>> dnPrettyNormal: <>
> Sep 18 12:57:08 socrates slapd[17192]: <<< dnPrettyNormal: <>, <>
> Sep 18 12:57:08 socrates slapd[17192]: SRCH "" 0 0
> Sep 18 12:57:08 socrates slapd[17192]:     0 0 0
> Sep 18 12:57:08 socrates slapd[17192]: begin get_filter
> Sep 18 12:57:08 socrates slapd[17192]: PRESENT
> Sep 18 12:57:08 socrates slapd[17192]: end get_filter 0
> Sep 18 12:57:08 socrates slapd[17192]:     filter: (objectClass=*)
> Sep 18 12:57:08 socrates slapd[17192]:     attrs:
> Sep 18 12:57:08 socrates slapd[17192]:  supportedSASLMechanisms
> Sep 18 12:57:08 socrates slapd[17192]:
> Sep 18 12:57:08 socrates slapd[17192]: => test_filter
> Sep 18 12:57:08 socrates slapd[17192]:     PRESENT
> Sep 18 12:57:08 socrates slapd[17192]: => access_allowed: search access to
> "" "objectClass" requested
> Sep 18 12:57:08 socrates slapd[17192]: => acl_get: [3] attr objectClass
> Sep 18 12:57:08 socrates slapd[17192]: => acl_mask: access to entry "",
> attr "objectClass" requested
> Sep 18 12:57:08 socrates slapd[17192]: => acl_mask: to all values by "",
> (=n)
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => string_expand: pattern:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => string_expand: expanded:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => regex_matches: string:
> Sep 18 12:57:08 socrates slapd[17192]: => regex_matches: rc: 1 no matches
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat:
> uid=root,ou=people,dc=netlab,dc=gmu,dc=edu
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat: *
> Sep 18 12:57:08 socrates slapd[17192]: <= acl_mask: [3] applying
> read(=rscx) (stop)
> Sep 18 12:57:08 socrates slapd[17192]: <= acl_mask: [3] mask: read(=rscx)
> Sep 18 12:57:08 socrates slapd[17192]: => access_allowed: search access
> granted by read(=rscx)
> Sep 18 12:57:08 socrates slapd[17192]: <= test_filter 6
> Sep 18 12:57:08 socrates slapd[17192]: => send_search_entry: dn=""
> Sep 18 12:57:08 socrates slapd[17192]: => access_allowed: read access to
> "" "entry" requested
> Sep 18 12:57:08 socrates slapd[17192]: => acl_get: [3] attr entry
> Sep 18 12:57:08 socrates slapd[17192]: => acl_mask: access to entry "",
> attr "entry" requested
> Sep 18 12:57:08 socrates slapd[17192]: => acl_mask: to all values by "",
> (=n)
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => string_expand: pattern:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => string_expand: expanded:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => regex_matches: string:
> Sep 18 12:57:08 socrates slapd[17192]: => regex_matches: rc: 1 no matches
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat:
> uid=root,ou=people,dc=netlab,dc=gmu,dc=edu
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat: *
> Sep 18 12:57:08 socrates slapd[17192]: <= acl_mask: [3] applying
> read(=rscx) (stop)
> Sep 18 12:57:08 socrates slapd[17192]: <= acl_mask: [3] mask: read(=rscx)
> Sep 18 12:57:08 socrates slapd[17192]: => access_allowed: read access
> granted by read(=rscx)
> Sep 18 12:57:08 socrates slapd[17192]: => access_allowed: read access to
> "" "supportedSASLMechanisms" requested
> Sep 18 12:57:08 socrates slapd[17192]: => acl_get: [3] attr
> supportedSASLMechanisms
> Sep 18 12:57:08 socrates slapd[17192]: access_allowed: no res from state
> (supportedSASLMechanisms)
> Sep 18 12:57:08 socrates slapd[17192]: => acl_mask: access to entry "",
> attr "supportedSASLMechanisms" requested
> Sep 18 12:57:08 socrates slapd[17192]: => acl_mask: to value by "", (=n)
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => string_expand: pattern:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => string_expand: expanded:
> uid=.*/admin,cn=GSSAPI,cn=auth
> Sep 18 12:57:08 socrates slapd[17192]: => regex_matches: string:
> Sep 18 12:57:08 socrates slapd[17192]: => regex_matches: rc: 1 no matches
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat:
> uid=root,ou=people,dc=netlab,dc=gmu,dc=edu
> Sep 18 12:57:08 socrates slapd[17192]: <= check a_dn_pat: *
> Sep 18 12:57:08 socrates slapd[17192]: <= acl_mask: [3] applying
> read(=rscx) (stop)
> Sep 18 12:57:08 socrates slapd[17192]: <= acl_mask: [3] mask: read(=rscx)
> Sep 18 12:57:08 socrates slapd[17192]: => access_allowed: read access
> granted by read(=rscx)
> Sep 18 12:57:08 socrates slapd[17192]: <= send_search_entry
> Sep 18 12:57:08 socrates slapd[17192]: send_ldap_result: conn=7 op=0 p=3
> Sep 18 12:57:08 socrates slapd[17192]: send_ldap_result: err=0 matched=""
> text=""
> Sep 18 12:57:08 socrates slapd[17192]: send_ldap_response: msgid=1 tag=101
> err=0
> Sep 18 12:57:08 socrates slapd[17192]: daemon: activity on 1 descriptors
> Sep 18 12:57:08 socrates slapd[17192]: daemon: activity on:
> Sep 18 12:57:08 socrates slapd[17192]:  19r
> Sep 18 12:57:08 socrates slapd[17192]:
> Sep 18 12:57:08 socrates slapd[17192]: daemon: read activity on 19
> Sep 18 12:57:08 socrates slapd[17192]: connection_get(19)
> Sep 18 12:57:08 socrates slapd[17192]: connection_get(19): got connid=7
> Sep 18 12:57:08 socrates slapd[17192]: connection_read(19): checking for
> input on id=7
> Sep 18 12:57:08 socrates slapd[17192]: ber_get_next on fd 19 failed
> errno=11 (Resource temporarily unavailable)
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=6
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=7
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=8
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: daemon: select: listen=9
> active_threads=1 tvp=zero
> Sep 18 12:57:08 socrates slapd[17192]: do_bind
> Sep 18 12:57:08 socrates slapd[17192]: >>> dnPrettyNormal: <>
> Sep 18 12:57:08 socrates slapd[17192]: <<< dnPrettyNormal: <>, <>
> Sep 18 12:57:08 socrates slapd[17192]: do_sasl_bind: dn () mech GSSAPI
> Sep 18 12:57:08 socrates slapd[17192]: ==> sasl_bind: dn="" mech=GSSAPI
> datalen=566
> Sep 18 12:57:08 socrates slapd[17192]: SASL [conn=7] Failure: GSSAPI
> Error: Miscellaneous failure (Resource temporarily unavailable)
> Sep 18 12:57:08 socrates slapd[17192]: send_ldap_result: conn=7 op=1 p=3
> Sep 18 12:57:08 socrates slapd[17192]: send_ldap_result: err=80 matched=""
> text="SASL(-1): generic failure: GSSAPI Error: Miscellaneous failure
> (Resource temporarily unavailable)"
> Sep 18 12:57:08 socrates slapd[17192]: send_ldap_response: msgid=2 tag=97
> err=80
> Sep 18 12:57:08 socrates slapd[17192]: <== slap_sasl_bind: rc=80
> Sep 18 12:57:08 socrates slapd[17192]: daemon: activity on 1 descriptors
> Sep 18 12:57:08 socrates slapd[17192]: daemon: activity on:
> Sep 18 12:57:09 socrates slapd[17192]:  19r
> Sep 18 12:57:09 socrates slapd[17192]:
> Sep 18 12:57:09 socrates slapd[17192]: daemon: read activity on 19
> Sep 18 12:57:09 socrates slapd[17192]: connection_get(19)
> Sep 18 12:57:09 socrates slapd[17192]: connection_get(19): got connid=7
> Sep 18 12:57:09 socrates slapd[17192]: connection_read(19): checking for
> input on id=7
> Sep 18 12:57:09 socrates slapd[17192]: ber_get_next on fd 19 failed
> errno=0 (Success)
> Sep 18 12:57:09 socrates slapd[17192]: connection_read(19): input error=-2
> id=7, closing.
> Sep 18 12:57:09 socrates slapd[17192]: connection_closing: readying conn=7
> sd=19 for close
> Sep 18 12:57:09 socrates slapd[17192]: connection_close: conn=7 sd=19
> Sep 18 12:57:09 socrates slapd[17192]: daemon: removing 19
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=6
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=7
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=8
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=9
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: activity on 1 descriptors
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=6
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=7
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=8
> active_threads=1 tvp=zero
> Sep 18 12:57:09 socrates slapd[17192]: daemon: select: listen=9
> active_threads=1 tvp=zero
>
>
>> I just went through a hellish installation on a RH system and I remember
>> hitting that same point,.but not where I hit that point. Could you post
>> the full slapd debug output?
>>
>> Nicholas Clark wrote:
>>
>>>It does:
>>>
>>>#
>>># LDAPv3
>>># base <> with scope base
>>># filter: (objectclass=*)
>>># requesting: supportedSASLMechanisms
>>>#
>>>
>>>#
>>>dn:
>>>supportedSASLMechanisms: GSSAPI
>>>supportedSASLMechanisms: DIGEST-MD5
>>>supportedSASLMechanisms: CRAM-MD5
>>>
>>># search result
>>>
>>># numResponses: 2
>>># numEntries: 1
>>>
>>>
>>>- Nick
>>>
>>>
>>>
>>>>On 9/16/05, nclark1@gmu.edu <nclark1@gmu.edu> wrote:
>>>>
>>>>
>>>>>Trying to get openldap working with MIT Kerberos authentication but
>>>>> keep
>>>>>getting the following error when connecting:
>>>>>
>>>>>SASL/GSSAPI authentication started
>>>>>ldap_sasl_interactive_bind_s: Internal (implementation specific) error
>>>>>(80)
>>>>>        additional info: SASL(-1): generic failure: GSSAPI Error:
>>>>>Miscellaneous failure (Resource temporarily unavailable)
>>>>>
>>>>>
>>>>>
>>>>Make sure:
>>>>
>>>>  ldapsearch -x -L -s "base" -b "" supportedSASLMechanisms
>>>>
>>>>returns:
>>>>
>>>>  supportedSASLMechanisms: GSSAPI
>>>>
>>>>--
>>>>Jiann-Ming Su
>>>>"I have to decide between two equally frightening options.
>>>> If I wanted to do that, I'd vote." --Duckman
>>>>
>>>>
>>>>
>>>
>>>
>>>
>>>
>>>
>>
>>
>
References:
- Kerberos, GSSAPI Miscellaneous failure
  - From: nclark1@gmu.edu
- Re: Kerberos, GSSAPI Miscellaneous failure
  - From: Jiann-Ming Su <sujiannming@gmail.com>
- Re: Kerberos, GSSAPI Miscellaneous failure
  - From: "Nicholas Clark" <nclark1@gmu.edu>
- Re: Kerberos, GSSAPI Miscellaneous failure
  - From: Donald Norwood <dnorwood@portalias.net>
- Re: Kerberos, GSSAPI Miscellaneous failure
  - From: "Nicholas Clark" <nclark1@gmu.edu>
Prev by Date: Re: Kerberos, GSSAPI Miscellaneous failure
Next by Date: back-sql wrong SQL construction
Index(es):
- Chronological
- Thread