[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 13:01:59 -0400 (EDT)
Cc: nclark1@gmu.edu, sujiannming@gmail.com, openldap-software@OpenLDAP.org
Importance: Normal
In-reply-to: <432CAF88.6090606@portalias.net>
References: <f88b8080dc9e.432b26e8@gmu.edu> <561dc3260509161959194df71@mail.gmail.com> <1857.70.108.197.104.1126966022.squirrel@70.108.197.104> <432CAF88.6090606@portalias.net>
User-agent: SquirrelMail/1.5.0
"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
>>>
>>>
>>>
>>
>>
>>
>>
>>
>
>
Follow-Ups:
- Re: Kerberos, GSSAPI Miscellaneous failure
  - From: "Nicholas Clark" <nclark1@gmu.edu>
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>
Prev by Date: Re: Kerberos, GSSAPI Miscellaneous failure
Next by Date: Re: Kerberos, GSSAPI Miscellaneous failure
Index(es):
- Chronological
- Thread