[Date Prev][Date Next] [Chronological] [Thread] [Top]
(ITS#3634) Slapd sometimes crashes after starting the same search action three times

To: openldap-its@OpenLDAP.org
Subject: (ITS#3634) Slapd sometimes crashes after starting the same search action three times
From: gerritvandenhul@lycos.nl
Date: Wed, 6 Apr 2005 09:00:04 GMT
Full_Name: Gerrit van den Hul
Version: 2.2.24
OS: Linux RedHat 4.0
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (145.72.98.1)


Hi, 

I have a problem with RedHat 4.0 and openldap 2.2.24/DB 4.2.

Slapd sometimes crashes after starting the same search action three times, at
the same time.
Slapd is started just before these search actions.

When I remove the regex lines from the access control list, I can't reproduce
the error.
I can't reproduce the error on a single processor system either (one XEON
processor; hypertreading disabled).

I have reproduced the error also with RedHat 3.0 and with openldap 2.2.13 and
with DB 4.3.

Perhaps this is a problem with acl parsing on a multi-processor system?

Greetings,

Gerrit van den Hul (email: gerritvandenhul@lycos.nl)




System: HP Proliant with two XEON processsors (four processors for O.S.)
O.S.: RedHat 4.0 ES

Openldap configuration (stripped):

loglevel           5
sizelimit           50000
timelimit           3600
sockbuf_max_incoming_auth      8000000
idletimeout         0
schemacheck         on
defaultsearchbase   "o=org,c=nl"
allow               bind_v2

database      bdb
checkpoint    250 15
suffix        "o=org,c=NL"
directory     /usr/local/openldap/openldapDB
index          objectClass      eq
index          cn               eq,sub

access to dn.regex="orgcode=(.*),ou=lb,o=org,c=nl" attr="data"
        by dn.regex="cn=updater,orgcode=$1,ou=lb,o=org,c=nl" write

access to *
        by self write
        by * read
      


DB configuration:

set_cachesize   0       500000000       0



Logfile:

Apr  6 10:01:43 localhost slapd[2978]: backend_startup: starting "o=org,c=NL" 
Apr  6 10:01:43 localhost slapd[2978]: bdb_db_open: o=org,c=NL 
Apr  6 10:01:43 localhost slapd[2978]: bdb_db_open:
dbenv_open(/usr/local/openldap/openldapDB) 
Apr  6 10:01:43 localhost slapd[2978]: slapd starting 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(10) 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(10): got connid=0 
Apr  6 10:01:44 localhost slapd[2978]: connection_read(10): checking for input
on id=0 
Apr  6 10:01:44 localhost slapd[2978]: ber_get_next on fd 10 failed errno=11
(Resource temporarily unavailable) 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(11) 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(11): got connid=1 
Apr  6 10:01:44 localhost slapd[2978]: connection_read(11): checking for input
on id=1 
Apr  6 10:01:44 localhost slapd[2978]: ber_get_next on fd 11 failed errno=11
(Resource temporarily unavailable) 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(12) 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(12): got connid=2 
Apr  6 10:01:44 localhost slapd[2978]: connection_read(12): checking for input
on id=2 
Apr  6 10:01:44 localhost slapd[2978]: ber_get_next on fd 12 failed errno=11
(Resource temporarily unavailable) 
Apr  6 10:01:44 localhost slapd[2978]: do_bind 
Apr  6 10:01:44 localhost slapd[2978]: >>> dnPrettyNormal: <> 
Apr  6 10:01:44 localhost slapd[2978]: <<< dnPrettyNormal: <>, <> 
Apr  6 10:01:44 localhost slapd[2978]: do_bind: version=2 dn="" method=128 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_result: conn=0 op=0 p=2 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_result: err=0 matched=""
text="" 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_response: msgid=1 tag=97 err=0

Apr  6 10:01:44 localhost slapd[2978]: do_bind: v2 anonymous bind 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(10) 
Apr  6 10:01:44 localhost slapd[2978]: do_bind 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(10): got connid=0 
Apr  6 10:01:44 localhost slapd[2978]: >>> dnPrettyNormal: <> 
Apr  6 10:01:44 localhost slapd[2978]: connection_read(10): checking for input
on id=0 
Apr  6 10:01:44 localhost slapd[2978]: <<< dnPrettyNormal: <>, <> 
Apr  6 10:01:44 localhost slapd[2978]: ber_get_next on fd 10 failed errno=11
(Resource temporarily unavailable) 
Apr  6 10:01:44 localhost slapd[2978]: do_bind 
Apr  6 10:01:44 localhost slapd[2978]: do_bind: version=2 dn="" method=128 
Apr  6 10:01:44 localhost slapd[2978]: >>> dnPrettyNormal: <> 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_result: conn=1 op=0 p=2 
Apr  6 10:01:44 localhost slapd[2978]: <<< dnPrettyNormal: <>, <> 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_result: err=0 matched=""
text="" 
Apr  6 10:01:44 localhost slapd[2978]: do_bind: version=2 dn="" method=128 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_response: msgid=1 tag=97 err=0

Apr  6 10:01:44 localhost slapd[2978]: send_ldap_result: conn=2 op=0 p=2 
Apr  6 10:01:44 localhost slapd[2978]: do_bind: v2 anonymous bind 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(11) 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_result: err=0 matched=""
text="" 
Apr  6 10:01:44 localhost slapd[2978]: do_search 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(11): got connid=1 
Apr  6 10:01:44 localhost slapd[2978]: send_ldap_response: msgid=1 tag=97 err=0

Apr  6 10:01:44 localhost slapd[2978]: >>> dnPrettyNormal: <orgCode=3466, ou=LB,
o=org, c=NL> 
Apr  6 10:01:44 localhost slapd[2978]: connection_read(11): checking for input
on id=1 
Apr  6 10:01:44 localhost slapd[2978]: do_bind: v2 anonymous bind 
Apr  6 10:01:44 localhost slapd[2978]: <<< dnPrettyNormal:
<orgCode=3466,ou=LB,o=org,c=NL>, <orgCode=3466,ou=lb,o=org,c=nl> 
Apr  6 10:01:44 localhost slapd[2978]: ber_get_next on fd 11 failed errno=11
(Resource temporarily unavailable) 
Apr  6 10:01:44 localhost slapd[2978]: do_search 
Apr  6 10:01:44 localhost slapd[2978]: SRCH "orgCode=3466, ou=LB, o=org, c=NL" 1
0
Apr  6 10:01:44 localhost slapd[2978]: connection_get(12) 
Apr  6 10:01:44 localhost slapd[2978]: >>> dnPrettyNormal: <orgCode=3466, ou=LB,
o=org, c=NL> 
Apr  6 10:01:44 localhost slapd[2978]:     0 1000 0 
Apr  6 10:01:44 localhost slapd[2978]: connection_get(12): got connid=2 
Apr  6 10:01:44 localhost slapd[2978]: <<< dnPrettyNormal:
<orgCode=3466,ou=LB,o=org,c=NL>, <orgCode=3466,ou=lb,o=org,c=nl> 
Apr  6 10:01:44 localhost slapd[2978]:     filter:
(&(&(activeEntry=0)(objectClass=distList)(!(listOwner=*)))(!(modifyTimestamp<=20050311140316Z)))

Apr  6 10:01:44 localhost slapd[2978]: connection_read(12): checking for input
on id=2 
Apr  6 10:01:44 localhost slapd[2978]: SRCH "orgCode=3466, ou=LB, o=org, c=NL" 1
0
Apr  6 10:01:44 localhost slapd[2978]:     attrs:
Apr  6 10:01:44 localhost slapd[2978]: ber_get_next on fd 12 failed errno=11
(Resource temporarily unavailable) 
Apr  6 10:01:44 localhost slapd[2978]: do_search 
Apr  6 10:01:44 localhost slapd[2978]:     0 1000 0 
Apr  6 10:01:44 localhost slapd[2978]:  orgID
Apr  6 10:01:44 localhost slapd[2978]: >>> dnPrettyNormal: <orgCode=3466, ou=LB,
o=org, c=NL> 
Apr  6 10:01:44 localhost slapd[2978]:     filter:
(&(&(activeEntry=0)(objectClass=distList)(!(listOwner=*)))(!(modifyTimestamp<=20050311140316Z)))

Apr  6 10:01:44 localhost slapd[2978]:  
Apr  6 10:01:44 localhost slapd[2978]: <<< dnPrettyNormal:
<orgCode=3466,ou=LB,o=org,c=NL>, <orgCode=3466,ou=lb,o=org,c=nl> 
Apr  6 10:01:44 localhost slapd[2978]:     attrs:
Apr  6 10:01:44 localhost slapd[2978]: ==> limits_get: conn=0 op=1
dn="[anonymous]" 
Apr  6 10:01:44 localhost slapd[2978]: SRCH "orgCode=3466, ou=LB, o=org, c=NL" 1
0
Apr  6 10:01:44 localhost slapd[2978]:  orgID
Apr  6 10:01:44 localhost slapd[2978]: => bdb_search 
Apr  6 10:01:44 localhost slapd[2978]:     0 1000 0 
Apr  6 10:01:44 localhost slapd[2978]:  
Apr  6 10:01:44 localhost slapd[2978]:
bdb_dn2entry("orgCode=3466,ou=lb,o=org,c=nl") 
Apr  6 10:01:44 localhost slapd[2978]:     filter:
(&(&(activeEntry=0)(objectClass=distList)(!(listOwner=*)))(!(modifyTimestamp<=20050311140316Z)))

Apr  6 10:01:44 localhost slapd[2978]: ==> limits_get: conn=1 op=1
dn="[anonymous]" 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id( "o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]:     attrs:
Apr  6 10:01:44 localhost slapd[2978]: => bdb_search 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2id: got id=0x00000001 
Apr  6 10:01:44 localhost slapd[2978]:  orgID
Apr  6 10:01:44 localhost slapd[2978]:
bdb_dn2entry("orgCode=3466,ou=lb,o=org,c=nl") 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id( "ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]:  
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id( "ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2id: got id=0x00000002 
Apr  6 10:01:44 localhost slapd[2978]: ==> limits_get: conn=2 op=1
dn="[anonymous]" 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2id: got id=0x00000002 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id(
"orgCode=3466,ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_search 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id(
"orgCode=3466,ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2id: got id=0x000001f4 
Apr  6 10:01:44 localhost slapd[2978]:
bdb_dn2entry("orgCode=3466,ou=lb,o=org,c=nl") 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2id: got id=0x000001f4 
Apr  6 10:01:44 localhost slapd[2978]: entry_decode:
"orgCode=3466,ou=LB,o=org,c=NL" 
Apr  6 10:01:44 localhost slapd[2978]: <=
entry_decode(orgCode=3466,ou=LB,o=org,c=NL) 
Apr  6 10:01:44 localhost slapd[2978]: search_candidates:
base="orgCode=3466,ou=lb,o=org,c=nl" (0x000001f4) scope=1 
Apr  6 10:01:44 localhost last message repeated 2 times
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2idl(
"orgCode=3466,ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost last message repeated 2 times
Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key:
%orgCode=3466,ou=lb,o=org,c=nl 
Apr  6 10:01:44 localhost last message repeated 2 times
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2idl: id=703 first=501
last=284838 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (objectClass)

Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2idl: id=703 first=501
last=284838 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (objectClass)

Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2idl: id=703 first=501
last=284838 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (objectClass)

Apr  6 10:01:44 localhost slapd[2978]: => key_read 
Apr  6 10:01:44 localhost slapd[2978]: => key_read 
Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key: [b49d1940] 
Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key: [b49d1940] 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_index_read: failed (-30990) 
Apr  6 10:01:44 localhost slapd[2978]: => key_read 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_index_read: failed (-30990) 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: id=0,
first=0, last=0 
Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key: [b49d1940] 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: id=0,
first=0, last=0 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (activeEntry)

Apr  6 10:01:44 localhost slapd[2978]: <= bdb_index_read: failed (-30990) 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (activeEntry)

Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: (activeEntry)
index_param failed (18) 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: id=0,
first=0, last=0 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: (activeEntry)
index_param failed (18) 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (activeEntry)

Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (objectClass)

Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (objectClass)

Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: (activeEntry)
index_param failed (18) 
Apr  6 10:01:44 localhost slapd[2978]: => key_read 
Apr  6 10:01:44 localhost slapd[2978]: => key_read 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_equality_candidates (objectClass)

Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key: [db024410] 
Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key: [db024410] 
Apr  6 10:01:44 localhost slapd[2978]: => key_read 
Apr  6 10:01:44 localhost slapd[2978]: bdb_idl_fetch_key: [db024410] 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_index_read 15993 candidates 
Apr  6 10:01:44 localhost last message repeated 2 times
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_equality_candidates: id=15993,
first=8, last=286893 
Apr  6 10:01:44 localhost last message repeated 2 times
Apr  6 10:01:44 localhost slapd[2978]: bdb_search_candidates: id=56 first=2704
last=247344 
Apr  6 10:01:44 localhost slapd[2978]: bdb_search_candidates: id=56 first=2704
last=247344 
Apr  6 10:01:44 localhost slapd[2978]: entry_decode:
"orgID=3000280130,orgCode=3466,ou=LB,o=org,c=NL" 
Apr  6 10:01:44 localhost slapd[2978]: bdb_search_candidates: id=56 first=2704
last=247344 
Apr  6 10:01:44 localhost slapd[2978]: entry_decode:
"orgID=3000280130,orgCode=3466,ou=LB,o=org,c=NL" 
Apr  6 10:01:44 localhost slapd[2978]: <=
entry_decode(orgID=3000280130,orgCode=3466,ou=LB,o=org,c=NL) 
Apr  6 10:01:44 localhost slapd[2978]: entry_decode:
"orgID=3000280130,orgCode=3466,ou=LB,o=org,c=NL" 
Apr  6 10:01:44 localhost slapd[2978]: <=
entry_decode(orgID=3000280130,orgCode=3466,ou=LB,o=org,c=NL) 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id(
"orgID=3000280130,orgCode=3466,ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id(
"orgID=3000280130,orgCode=3466,ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]: <=
entry_decode(orgID=3000280130,orgCode=3466,ou=LB,o=org,c=NL) 
Apr  6 10:01:44 localhost slapd[2978]: => bdb_dn2id(
"orgID=3000280130,orgCode=3466,ou=lb,o=org,c=nl" ) 
Apr  6 10:01:44 localhost slapd[2978]: <= bdb_dn2id: got id=0x00000a90 


Stack trace:

#0  0x008cf19e in build_trtable () from /lib/tls/libc.so.6
#1  0x008d6234 in re_search_internal () from /lib/tls/libc.so.6
#2  0x008d7912 in regexec@@GLIBC_2.3.4 () from /lib/tls/libc.so.6
#3  0x0806f2e8 in access_allowed (op=0x8a46258, e=0x8fe01578, desc=0x8a463e8,
val=0x917fa268, access=ACL_SEARCH,
    state=0x0) at acl.c:489
#4  0x0806cea1 in test_ava_filter (op=0x8a46258, e=0x8fe01578, ava=0x917fa264,
type=163) at filterentry.c:396
#5  0x0806d54d in test_filter (op=0x8a46258, e=0x8fe01578, f=0x917fa284) at
filterentry.c:130
#6  0x0806d30d in test_filter (op=0x8a46258, e=0x8fe01578, f=0x917fa2e4) at
filterentry.c:542
#7  0x0806d30d in test_filter (op=0x8a46258, e=0x8fe01578, f=0x917fa33c) at
filterentry.c:542
#8  0x0809e1e0 in bdb_do_search (op=0x8a46258, rs=0x91cfb240, sop=0x8a46258,
ps_e=0x0, ps_type=0)
    at search.c:1132
#9  0x0809e62b in bdb_search (op=0x8a35248, rs=0x91cfb240) at search.c:384
#10 0x0805a01d in do_search (op=0x8a46258, rs=0x91cfb240) at search.c:412
#11 0x080595f0 in connection_operation (ctx=0x91cfb2c0, arg_v=0x8a46258) at
connection.c:1079
#12 0x080ba217 in ldap_int_thread_pool_wrapper (xpool=0x89f2390) at tpool.c:467
#13 0x009993ae in start_thread () from /lib/tls/libpthread.so.0
#14 0x008f2aee in clone () from /lib/tls/libc.so.6
Prev by Date: (ITS#3635) smbk5pwd breaks sambaLMPassword hashes
Next by Date: (ITS#3636) more flexible file: URLs in LDIFs
Index(es):
- Chronological
- Thread