bdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found

[jay alvarez <ldapb0y@yahoo.com>]

Hi Den,
  I still can't figure out what's the cause of the
problem. I don't think it's a permission issue since I
am running slapd under the root account, as well as
ldapadd. Anymore idea?

--- dennis@utiba.com wrote:

> Hi,
> 
> every time this method screwed up for me it was
> permissions on the
> directory. You might like to check them.
> 
> dennis
> > Hi,
> >   I was playing with ldapadd and ldapadelete to
> add
> > and remove entries in my directory, but as soon as
> my
> > test entries began to grow, I decided to just "rm
> -rf"
> > the whole /usr/local/openldap/var/openldap-data.
> Next,
> > I will kill the slapd process, then create another
> > openldap-data directory again and then rerun the
> > slapd. For quite some time, this technique worked
> for
> > me. After launching the slapd, it begins creating
> db
> > files in openldap-data directory. Then I could
> just do
> > the ldapadd -f my.ldif again and all entries will
> be
> > added to the database. But then one time I did
> this
> > technique again, I was surprise to findout that
> > ldapadd failed giving this error message:
> >
> > gaheris# ldapadd -f camlann.ldif
> > SASL/GSSAPI authentication started
> > SASL username: matato@CAMLANN.PREGI.NET
> > SASL SSF: 56
> > SASL installing layers
> > adding new entry "dc=camlann,dc=pregi,dc=net"
> > ldap_add: No such object (32)
> >
> > Looking at my /var/log/debug, I can see some error
> > messages like these:
> >
> > SASL [conn=2] Failure: Could not open db
> >
> >
> > ber_get_next on fd 12 failed errno=35 (Resource
> > temporarily unavailable)
> >
> > bdb_dn2id: get failed: DB_NOTFOUND: No matching
> > key/data pair found (-30989)
> >
> >
> > I tried fsck'ing the partition as I suspect it to
> have
> > a corrupted filesystem but it didn't do anything.
> >
> > I have attached here my debug.log. I hope it can
> help
> > you troubleshoot my problem.
> >
> > Thanks!
> >
> >
> >
> >
> >
> >
> >
> >
> >
> > __________________________________
> > Do you Yahoo!?
> > Make Yahoo! your home page
> > http://www.yahoo.com/r/hs
> > -----------------
> > Utiba Pty Ltd
> > This message has been scanned for viruses and
> > dangerous content by Utiba mail server and is
> > believed to be clean.
> >
> >
> 
> 
> 
> -----------------
> Utiba Pty Ltd 
> This message has been scanned for viruses and
> dangerous content by Utiba mail server and is 
> believed to be clean.
> 
> 

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com

Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: new connection on 11
Jun 17 15:12:28 gaheris slapd[702]: conn=1 fd=11 ACCEPT from IP=::1 59519 (IP=:: 389)
Jun 17 15:12:28 gaheris slapd[702]: daemon: added 11r
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]:  11r
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: read activity on 11
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11)
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11): got connid=1
Jun 17 15:12:28 gaheris slapd[702]: connection_read(11): checking for input on id=1
Jun 17 15:12:28 gaheris slapd[702]: ber_get_next on fd 11 failed errno=35 (Resource temporarily unavailable)
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: do_search
Jun 17 15:12:28 gaheris slapd[702]: >>> dnPrettyNormal: <>
Jun 17 15:12:28 gaheris slapd[702]: <<< dnPrettyNormal: <>, <>
Jun 17 15:12:28 gaheris slapd[702]: SRCH "" 0 0
Jun 17 15:12:28 gaheris slapd[702]:     0 0 0
Jun 17 15:12:28 gaheris slapd[702]: begin get_filter
Jun 17 15:12:28 gaheris slapd[702]: PRESENT
Jun 17 15:12:28 gaheris slapd[702]: end get_filter 0
Jun 17 15:12:28 gaheris slapd[702]:     filter: (objectClass=*)
Jun 17 15:12:28 gaheris slapd[702]:     attrs:
Jun 17 15:12:28 gaheris slapd[702]:  supportedSASLMechanisms
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=0 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=0 SRCH attr=supportedSASLMechanisms
Jun 17 15:12:28 gaheris slapd[702]: => test_filter
Jun 17 15:12:28 gaheris slapd[702]:     PRESENT
Jun 17 15:12:28 gaheris slapd[702]: => access_allowed: search access to "" "objectClass" requested
Jun 17 15:12:28 gaheris slapd[702]: => acl_get: [1] attr objectClass
Jun 17 15:12:28 gaheris slapd[702]: => acl_mask: access to entry "", attr "objectClass" requested
Jun 17 15:12:28 gaheris slapd[702]: => acl_mask: to all values by "", (=n) 
Jun 17 15:12:28 gaheris slapd[702]: <= check a_dn_pat: *
Jun 17 15:12:28 gaheris slapd[702]: <= acl_mask: [1] applying write(=wrscx) (stop)
Jun 17 15:12:28 gaheris slapd[702]: <= acl_mask: [1] mask: write(=wrscx)
Jun 17 15:12:28 gaheris slapd[702]: => access_allowed: search access granted by write(=wrscx)
Jun 17 15:12:28 gaheris slapd[702]: <= test_filter 6
Jun 17 15:12:28 gaheris slapd[702]: => send_search_entry: dn=""
Jun 17 15:12:28 gaheris slapd[702]: => access_allowed: read access to "" "entry" requested
Jun 17 15:12:28 gaheris slapd[702]: => acl_get: [1] attr entry
Jun 17 15:12:28 gaheris slapd[702]: => acl_mask: access to entry "", attr "entry" requested
Jun 17 15:12:28 gaheris slapd[702]: => acl_mask: to all values by "", (=n) 
Jun 17 15:12:28 gaheris slapd[702]: <= check a_dn_pat: *
Jun 17 15:12:28 gaheris slapd[702]: <= acl_mask: [1] applying write(=wrscx) (stop)
Jun 17 15:12:28 gaheris slapd[702]: <= acl_mask: [1] mask: write(=wrscx)
Jun 17 15:12:28 gaheris slapd[702]: => access_allowed: read access granted by write(=wrscx)
Jun 17 15:12:28 gaheris slapd[702]: => access_allowed: read access to "" "supportedSASLMechanisms" requested
Jun 17 15:12:28 gaheris slapd[702]: => acl_get: [1] attr supportedSASLMechanisms
Jun 17 15:12:28 gaheris slapd[702]: access_allowed: no res from state (supportedSASLMechanisms)
Jun 17 15:12:28 gaheris slapd[702]: => acl_mask: access to entry "", attr "supportedSASLMechanisms" requested
Jun 17 15:12:28 gaheris slapd[702]: => acl_mask: to value by "", (=n) 
Jun 17 15:12:28 gaheris slapd[702]: <= check a_dn_pat: *
Jun 17 15:12:28 gaheris slapd[702]: <= acl_mask: [1] applying write(=wrscx) (stop)
Jun 17 15:12:28 gaheris slapd[702]: <= acl_mask: [1] mask: write(=wrscx)
Jun 17 15:12:28 gaheris slapd[702]: => access_allowed: read access granted by write(=wrscx)
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=0 ENTRY dn=""
Jun 17 15:12:28 gaheris slapd[702]: <= send_search_entry
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_result: conn=1 op=0 p=3
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_result: err=0 matched="" text=""
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_response: msgid=1 tag=101 err=0
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]:  11r
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: read activity on 11
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11)
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11): got connid=1
Jun 17 15:12:28 gaheris slapd[702]: connection_read(11): checking for input on id=1
Jun 17 15:12:28 gaheris slapd[702]: ber_get_next on fd 11 failed errno=35 (Resource temporarily unavailable)
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: do_bind
Jun 17 15:12:28 gaheris slapd[702]: >>> dnPrettyNormal: <>
Jun 17 15:12:28 gaheris slapd[702]: <<< dnPrettyNormal: <>, <>
Jun 17 15:12:28 gaheris slapd[702]: do_sasl_bind: dn () mech GSSAPI
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=1 BIND dn="" method=163
Jun 17 15:12:28 gaheris slapd[702]: ==> sasl_bind: dn="" mech=GSSAPI datalen=575
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_sasl: err=14 len=110
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_response: msgid=2 tag=97 err=14
Jun 17 15:12:28 gaheris slapd[702]: <== slap_sasl_bind: rc=14
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]:  11r
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: read activity on 11
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11)
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11): got connid=1
Jun 17 15:12:28 gaheris slapd[702]: connection_read(11): checking for input on id=1
Jun 17 15:12:28 gaheris slapd[702]: ber_get_next on fd 11 failed errno=35 (Resource temporarily unavailable)
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: do_bind
Jun 17 15:12:28 gaheris slapd[702]: >>> dnPrettyNormal: <>
Jun 17 15:12:28 gaheris slapd[702]: <<< dnPrettyNormal: <>, <>
Jun 17 15:12:28 gaheris slapd[702]: do_sasl_bind: dn () mech GSSAPI
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=2 BIND dn="" method=163
Jun 17 15:12:28 gaheris slapd[702]: ==> sasl_bind: dn="" mech=<continuing> datalen=0
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_sasl: err=14 len=65
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_response: msgid=3 tag=97 err=14
Jun 17 15:12:28 gaheris slapd[702]: <== slap_sasl_bind: rc=14
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]:  11r
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: read activity on 11
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11)
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11): got connid=1
Jun 17 15:12:28 gaheris slapd[702]: connection_read(11): checking for input on id=1
Jun 17 15:12:28 gaheris slapd[702]: ber_get_next on fd 11 failed errno=35 (Resource temporarily unavailable)
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: do_bind
Jun 17 15:12:28 gaheris slapd[702]: >>> dnPrettyNormal: <>
Jun 17 15:12:28 gaheris slapd[702]: <<< dnPrettyNormal: <>, <>
Jun 17 15:12:28 gaheris slapd[702]: do_sasl_bind: dn () mech GSSAPI
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=3 BIND dn="" method=163
Jun 17 15:12:28 gaheris slapd[702]: ==> sasl_bind: dn="" mech=<continuing> datalen=65
Jun 17 15:12:28 gaheris slapd[702]: SASL Canonicalize [conn=1]: authcid="matato"
Jun 17 15:12:28 gaheris slapd[702]: slap_sasl_getdn: id=matato [len=6]
Jun 17 15:12:28 gaheris slapd[702]: slap_sasl_getdn: u:id converted to uid=matato,cn=GSSAPI,cn=auth
Jun 17 15:12:28 gaheris slapd[702]: >>> dnNormalize: <uid=matato,cn=GSSAPI,cn=auth>
Jun 17 15:12:28 gaheris slapd[702]: <<< dnNormalize: <uid=matato,cn=gssapi,cn=auth>
Jun 17 15:12:28 gaheris slapd[702]: ==>slap_sasl2dn: converting SASL name uid=matato,cn=gssapi,cn=auth to a DN
Jun 17 15:12:28 gaheris slapd[702]: slap_sasl_regexp: converting SASL name uid=matato,cn=gssapi,cn=auth
Jun 17 15:12:28 gaheris slapd[702]: <==slap_sasl2dn: Converted SASL name to <nothing>
Jun 17 15:12:28 gaheris slapd[702]: SASL Canonicalize [conn=1]: slapAuthcDN="uid=matato,cn=gssapi,cn=auth"
Jun 17 15:12:28 gaheris slapd[702]: SASL [conn=1] Failure: Could not open db
Jun 17 15:12:28 gaheris slapd[702]: SASL proxy authorize [conn=1]: authcid="matato" authzid="matato"
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=3 BIND authcid="matato"
Jun 17 15:12:28 gaheris slapd[702]: SASL Authorize [conn=1]:  proxy authorization allowed
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_sasl: err=0 len=-1
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_response: msgid=4 tag=97 err=0
Jun 17 15:12:28 gaheris slapd[702]: <== slap_sasl_bind: rc=0
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=3 BIND dn="uid=matato,cn=gssapi,cn=auth" mech=GSSAPI ssf=56
Jun 17 15:12:28 gaheris slapd[702]: do_bind: SASL/GSSAPI bind: dn="uid=matato,cn=gssapi,cn=auth" ssf=56
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]:  11r
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: read activity on 11
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11)
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11): got connid=1
Jun 17 15:12:28 gaheris slapd[702]: connection_read(11): checking for input on id=1
Jun 17 15:12:28 gaheris slapd[702]: ber_get_next on fd 11 failed errno=35 (Resource temporarily unavailable)
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: do_add
Jun 17 15:12:28 gaheris slapd[702]: >>> dnPrettyNormal: <dc=camlann,dc=pregi,dc=net>
Jun 17 15:12:28 gaheris slapd[702]: <<< dnPrettyNormal: <dc=camlann,dc=pregi,dc=net>, <dc=camlann,dc=pregi,dc=net>
Jun 17 15:12:28 gaheris slapd[702]: do_add: dn (dc=camlann,dc=pregi,dc=net)
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=4 ADD dn="dc=camlann,dc=pregi,dc=net"
Jun 17 15:12:28 gaheris slapd[702]: bdb_dn2entry("dc=camlann,dc=pregi,dc=net")
Jun 17 15:12:28 gaheris slapd[702]: => bdb_dn2id( "dc=camlann,dc=pregi,dc=net" )
Jun 17 15:12:28 gaheris slapd[702]: <= bdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30989)
Jun 17 15:12:28 gaheris slapd[702]: ==> bdb_add: dc=camlann,dc=pregi,dc=net
Jun 17 15:12:28 gaheris slapd[702]: oc_check_required entry (dc=camlann,dc=pregi,dc=net), objectClass "dcObject"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_required entry (dc=camlann,dc=pregi,dc=net), objectClass "organization"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "objectClass"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "o"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "dc"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "description"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "structuralObjectClass"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "entryUUID"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "creatorsName"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "createTimestamp"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "entryCSN"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "modifiersName"
Jun 17 15:12:28 gaheris slapd[702]: oc_check_allowed type "modifyTimestamp"
Jun 17 15:12:28 gaheris slapd[702]: bdb_dn2entry("dc=camlann,dc=pregi,dc=net")
Jun 17 15:12:28 gaheris slapd[702]: => bdb_dn2id( "dc=camlann,dc=pregi,dc=net" )
Jun 17 15:12:28 gaheris slapd[702]: <= bdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair found (-30989)
Jun 17 15:12:28 gaheris slapd[702]: bdb_add: suffix denied
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_result: conn=1 op=4 p=3
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_result: err=32 matched="" text=""
Jun 17 15:12:28 gaheris slapd[702]: send_ldap_response: msgid=5 tag=105 err=32
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=4 RESULT tag=105 err=32 text=
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 1 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on:
Jun 17 15:12:28 gaheris slapd[702]:  11r
Jun 17 15:12:28 gaheris slapd[702]: 
Jun 17 15:12:28 gaheris slapd[702]: daemon: read activity on 11
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11)
Jun 17 15:12:28 gaheris slapd[702]: connection_get(11): got connid=1
Jun 17 15:12:28 gaheris slapd[702]: connection_read(11): checking for input on id=1
Jun 17 15:12:28 gaheris slapd[702]: ber_get_next on fd 11 failed errno=35 (Resource temporarily unavailable)
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=1 tvp=zero
Jun 17 15:12:28 gaheris slapd[702]: do_unbind
Jun 17 15:12:28 gaheris slapd[702]: conn=1 op=5 UNBIND
Jun 17 15:12:28 gaheris slapd[702]: connection_closing: readying conn=1 sd=11 for close
Jun 17 15:12:28 gaheris slapd[702]: connection_resched: attempting closing conn=1 sd=11
Jun 17 15:12:28 gaheris slapd[702]: connection_close: conn=1 sd=11
Jun 17 15:12:28 gaheris slapd[702]: daemon: removing 11
Jun 17 15:12:28 gaheris slapd[702]: conn=1 fd=11 closed
Jun 17 15:12:28 gaheris slapd[702]: daemon: activity on 2 descriptors
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=6 active_threads=0 tvp=NULL
Jun 17 15:12:28 gaheris slapd[702]: daemon: select: listen=7 active_threads=0 tvp=NULL