[Date Prev][Date Next] [Chronological] [Thread] [Top]

(ITS#4187) slapd crash



Full_Name: Kevin Spicer
Version: 2.3.11
OS: Solaris 9
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (213.152.53.60)


I've seen periodic crashes of slapd when a user attempts to bind, this is not
happening often (about once or twice a fortnight) but when it happens it crashes
all 5 of of my slapd's (I have Solaris set to failover to use different servers
in the event of a failure).  In each case the last line in the log is the bind
request from the same user.  

Since last time this happened I switched my 'spare' server to loglevel 257, the
log output related to this event is shown at the end of this ITS (theres only 38
lines, if you need more logs I can provide these

I'm running 2.3.11 with DB 4.2.52.  I'm using back-bdb with the ppolicy and glue
overlays.  I have 5 databases glued together- each server is a master for one
and a replica for the others, although user accounts are only held in one of the
databases (the superior one).

I've kept a copy of the database files in case theres any useful diagnostics
you'd like me to run against them.

#### openldap log level 257 #####
Nov 20 18:20:57 barint slapd[3928]: [ID 848112 local4.debug] conn=2759 fd=47
ACCEPT from IP=172.25.69.20:45706 (IP=0.0.0.0:636)
Nov 20 18:20:57 barint slapd[3928]: [ID 611214 local4.debug] connection_get(47):
got connid=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 138202 local4.debug]
connection_read(47): checking for input on id=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 611214 local4.debug] connection_get(47):
got connid=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 138202 local4.debug]
connection_read(47): checking for input on id=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 418971 local4.debug]
connection_read(47): unable to get TLS client DN, error=49 id=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 105384 local4.debug] conn=2759 fd=47 TLS
established tls_ssf=168 ssf=168
Nov 20 18:20:57 barint slapd[3928]: [ID 611214 local4.debug] connection_get(47):
got connid=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 138202 local4.debug]
connection_read(47): checking for input on id=2759
Nov 20 18:20:57 barint slapd[3928]: [ID 812316 local4.debug] ber_get_next on fd
47 failed errno=11 (Resource temporarily unavailable)
Nov 20 18:20:57 barint slapd[3928]: [ID 948228 local4.debug] do_bind
Nov 20 18:20:57 barint slapd[3928]: [ID 198467 local4.debug] >>> dnPrettyNormal:
<uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local>
Nov 20 18:20:57 barint slapd[3928]: [ID 147344 local4.debug] <<< dnPrettyNormal:
<uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local>,
<uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local>
Nov 20 18:20:57 barint slapd[3928]: [ID 286280 local4.debug] do_bind: version=3
dn="uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local" method=128
Nov 20 18:20:57 barint slapd[3928]: [ID 215403 local4.debug] conn=2759 op=0 BIND
dn="uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local" method=128
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 603319 local4.debug] =>
bdb_dn2id("uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 697587 local4.debug] <= bdb_dn2id: got
id=0x000001f2
Nov 20 18:20:57 barint slapd[3928]: [ID 548982 local4.debug] entry_decode:
"uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local"
Nov 20 18:20:57 barint slapd[3928]: [ID 184541 local4.debug] <=
entry_decode(uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local)
Nov 20 18:20:57 barint slapd[3928]: [ID 960388 local4.debug] bdb_entry_get:
rc=0
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("cn=interview,ou=policy,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 603319 local4.debug] =>
bdb_dn2id("cn=interview,ou=policy,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 697587 local4.debug] <= bdb_dn2id: got
id=0x0000002a
Nov 20 18:20:57 barint slapd[3928]: [ID 548982 local4.debug] entry_decode:
"cn=interview,ou=policy,ou=uk,ou=cati,dc=emea,dc=group,dc=local"
Nov 20 18:20:57 barint slapd[3928]: [ID 184541 local4.debug] <=
entry_decode(cn=interview,ou=policy,ou=uk,ou=cati,dc=emea,dc=group,dc=local)
Nov 20 18:20:57 barint slapd[3928]: [ID 960388 local4.debug] bdb_entry_get:
rc=0
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 131099 local4.debug] send_ldap_result:
conn=2759 op=0 p=3
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 960388 local4.debug] bdb_entry_get:
rc=0
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 960388 local4.debug] bdb_entry_get:
rc=0
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("cn=interview,ou=policy,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 960388 local4.debug] bdb_entry_get:
rc=0
Nov 20 18:20:57 barint slapd[3928]: [ID 449132 local4.debug]
bdb_dn2entry("uid=war136,ou=people,ou=uk,ou=cati,dc=emea,dc=group,dc=local")
Nov 20 18:20:57 barint slapd[3928]: [ID 689477 local4.debug]
bdb_modify_internal: 0x000001f2:
uid=war136,ou=People,ou=uk,ou=cati,dc=emea,dc=group,dc=local