DB_NOTFOUND: No matching key/data pair found

[jay alvarez <ldapb0y@yahoo.com>]

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

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