Viewing Software Bugs/5199
Full headers

Major security issue: yes  no

Notes:
fixed?
Notification:

Date: Wed, 24 Oct 2007 12:31:59 GMT
From: david@schmitt.edv-bus.at
To: openldap-its@OpenLDAP.org
Subject: slapd sometimes hangs with back-sql

Full_Name: David Schmitt
Version: 2.3.38
OS: Debian etch
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (193.170.138.34)


Hi!

I have OSX clients authenticating via slapd against my postgres database. Once
every fortnight slapd stops responding to requests. I got this backtrace out of
it:

0x00002b28372e20f5 in pthread_join () from /lib/libpthread.so.0
(gdb) bt full
#0  0x00002b28372e20f5 in pthread_join () from /lib/libpthread.so.0
No symbol table info available.
#1  0x00000000004230d2 in slapd_daemon ()
    at /root/tmp/openldap2.3-2.3.38/servers/slapd/daemon.c:2579
        listener_tid = 1082132832
        rc = 0
#2  0x000000000041665f in main (argc=5, argv=0x7fff748e4288)
    at /root/tmp/openldap2.3-2.3.38/servers/slapd/main.c:859
        save_errno = <value optimized out>
        fp = (FILE *) 0x6a4f70
        i = <value optimized out>
        no_detach = 0
        rc = 1
        urls = <value optimized out>
        username = 0x605030 "gidNumber"
        groupname = 0x605010 "\226{P7(+"
        sandbox = 0x0
        syslogUser = 160
        configfile = <value optimized out>
        configdir = <value optimized out>
        serverName = <value optimized out>
        scp = <value optimized out>
        scp_entry = <value optimized out>
        debug_unknowns = (char **) 0x0
        syslog_unknowns = (char **) 0x0
        l = <value optimized out>
        slapd_pid_file_unlink = 1
        slapd_args_file_unlink = 1
        __PRETTY_FUNCTION__ = "main"
(gdb)

When testing with ldapsearch, the client connects, but doesn't receive any
data.

This is running on a 2.6.21-2-vserver-amd64 kernel, within a vserver container.

Followup 1

Date: Wed, 24 Oct 2007 15:14:08 +0200
From: Pierangelo Masarati <ando@sys-net.it>
To: openldap-its@openldap.org, david@schmitt.edv-bus.at
Subject: ITS#5199

The stack backtrace you provide is useless, as it refers to the main
thread.  Please run "thread apply all bt full".

p.



Ing. Pierangelo Masarati
OpenLDAP Core Team

SysNet s.r.l.
via Dossi, 8 - 27100 Pavia - ITALIA
http://www.sys-net.it
---------------------------------------
Office:  +39 02 23998309
Mobile:  +39 333 4963172
Email:   pierangelo.masarati@sys-net.it
---------------------------------------

Followup 2

From: David Schmitt <david@schmitt.edv-bus.at>
To: openldap-its@openldap.org
Subject: Re: ITS#5199
Date: Thu, 25 Oct 2007 09:39:02 +0200

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Wednesday 24 October 2007, you wrote:
> The stack backtrace you provide is useless, as it refers to the main
> thread.  Please run "thread apply all bt full".


Hmpf. Thanks for your answer, I will try to get a better trace upon the next 
hang.


Regards, David


- -- 
The primary freedom of open source is not the freedom from cost, but the free-
dom to shape software to do what you want. This freedom is /never/ exercised
without cost, but is available /at all/ only by accepting the very different
costs associated with open source, costs not in money, but in time and effort.
- -- http://www.schierer.org/~luke/log/20070710-1129/on-forks-and-forking
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.6 (GNU/Linux)

iD8DBQFHIEgZ/Pp1N6Uzh0URAjTPAJ4oiB8IlYjeDKxIGDKHDFCtQEKr2QCgnECE
x5GwRPbtZ4Cl5bMy0NlOsTc=
=nnG/
-----END PGP SIGNATURE-----

Followup 3

From: David Schmitt <david@schmitt.edv-bus.at>
To: openldap-its@openldap.org
Subject: Re: (ITS#5199) slapd sometimes hangs with back-sql
Date: Wed, 31 Oct 2007 14:09:33 +0100

--Boundary-00=_O6HKHoQQJlEsW1J
Content-Type: text/plain;
  charset="utf-8"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

Hi! 

Please find attached the output of "thread apply all bt full".


Regards, David


-- 
The primary freedom of open source is not the freedom from cost, but the free-
dom to shape software to do what you want. This freedom is /never/ exercised
without cost, but is available /at all/ only by accepting the very different
costs associated with open source, costs not in money, but in time and effort.
-- http://www.schierer.org/~luke/log/20070710-1129/on-forks-and-forking

--Boundary-00=_O6HKHoQQJlEsW1J
Content-Type: application/octet-stream;
  name="bt_full"
Content-Transfer-Encoding: quoted-printable
Content-Disposition: attachment;
	filename="bt_full"


Thread 5 (Thread 1082132832 (LWP 10915)):
#0  0x00002b5a2fb75eeb in __lll_mutex_lock_wait () from /lib/libpthread.so.0
No symbol table info available.
#1  0x00000000407fc9c0 in ?? ()
No symbol table info available.
#2  0x00000000006088d0 in ?? ()
No symbol table info available.
#3  0x00002b5a2fb72d9f in pthread_mutex_lock () from /lib/libpthread.so.0
No symbol table info available.
#4  0x0000003000000030 in ?? ()
No symbol table info available.
#5  0x00000000407fc8a0 in ?? ()
No symbol table info available.
#6  0x00000000407fc7b0 in ?? ()
No symbol table info available.
#7  0x00002b5a2feba0e0 in __after_morecore_hook () from /lib/libc.so.6
No symbol table info available.
#8  0x00000000000001c9 in ?? ()
No symbol table info available.
#9  0x0000000000000002 in ?? ()
No symbol table info available.
#10 0x00000000004a12bd in lt_preloaded_symbols ()
No symbol table info available.
#11 0x0000000000000004 in ?? ()
No symbol table info available.
#12 0x00000000004a1b35 in __PRETTY_FUNCTION__.12118 ()
No symbol table info available.
#13 0x0000000000000005 in ?? ()
No symbol table info available.
#14 0x00000000007238f0 in ?? ()
No symbol table info available.
#15 0x0000000000646b60 in ?? ()
No symbol table info available.
#16 0x0000000000646a20 in ?? ()
No symbol table info available.
#17 0x00000000407fc860 in ?? ()
No symbol table info available.
#18 0x00000000005fdf90 in style_strings ()
No symbol table info available.
#19 0x0000000000603600 in aclbuf ()
No symbol table info available.
#20 0x0000000000000002 in ?? ()
No symbol table info available.
#21 0x00002b5a30a054bd in backsql_free_db_conn (op=3D0x407fc860) at /root/t=
mp/openldap2.3-2.3.38/servers/slapd/back-sql/sql-wrap.c:439
	bi =3D (backsql_info *) 0x689910
	tmp =3D {ldap_cid =3D 469, dbh =3D 0x0}
	conn =3D <value optimized out>
#22 0x00002b5a309f7047 in backsql_connection_destroy (bd=3D<value optimized=
 out>, c=3D0x0) at /root/tmp/openldap2.3-2.3.38/servers/slapd/back-sql/init=
=2Ec:590
	opbuf =3D {
  buffer =3D "=C0=C9\177@\000\000\000\000=D9T=A6/Z+\000\000=A0=C8\177@\000\=
000\000\000\235s=A6/Z+\000\000p\227h\000\000\000\000\000\003\000\000\000\00=
0\000\000\0005\033J\000\000\000\000\000\000\000\000\000Z+\000\000=FF=FF=FF=
=FFunknown", '\0' <repeats 93 times>,
"]vB\000\000\000\000\000p=CA\177@\000=
\000\000\000P", '\0' <repeats 175 times>, "=D5\001", '\0' <repeats 174
time=
s>, "=D5\001\000\000\000\000\000\000=C0xf1Z+", '\0' <repeats 185
times>, ia=
lign =3D 1082116544, lalign =3D 1082116544,=20
  falign =3D 3.99668884, dalign =3D 5.3463660918685768e-315, palign =3D 0x4=
07fc9c0 ""}
	op =3D (Operation *) 0x689a50
#23 0x000000000043219c in backend_connection_destroy (conn=3D0x2b5a316678c0=
) at /root/tmp/openldap2.3-2.3.38/servers/slapd/backend.c:770
	be =3D (BackendDB *) 0x689770
#24 0x0000000000427973 in connection_close (c=3D0x2b5a316678c0) at /root/tm=
p/openldap2.3-2.3.38/servers/slapd/connection.c:690
	sd =3D -1
	__PRETTY_FUNCTION__ =3D "connection_close"
#25 0x00000000004289c6 in connection_read (s=3D10) at /root/tmp/openldap2.3=
=2D2.3.38/servers/slapd/connection.c:1458
	err =3D <value optimized out>
	sd =3D 10
	rc =3D -2
	c =3D (Connection *) 0x2b5a316678c0
	__PRETTY_FUNCTION__ =3D "connection_read"
#26 0x00000000004254db in slapd_daemon_task (ptr=3D<value optimized out>)
a=
t /root/tmp/openldap2.3-2.3.38/servers/slapd/daemon.c:2468
	fd =3D 10
	l =3D <value optimized out>
	last_idle_check =3D 0
	ebadf =3D 0
#27 0x00002b5a2fb70f1a in start_thread () from /lib/libpthread.so.0
No symbol table info available.
#28 0x00002b5a2fd4a6c2 in clone () from /lib/libc.so.6
No symbol table info available.
#29 0x0000000000000000 in ?? ()
No symbol table info available.

Thread 4 (Thread 1090525536 (LWP 10930)):
#0  0x00002b5a2fb75eeb in __lll_mutex_lock_wait () from /lib/libpthread.so.0
No symbol table info available.
#1  0x0000000041000bd0 in ?? ()
No symbol table info available.
#2  0x0000000000000000 in ?? ()
No symbol table info available.

Thread 3 (Thread 1098918240 (LWP 26084)):
#0  0x00002b5a2fb73b3a in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpt=
hread.so.0
No symbol table info available.
#1  0x00002b5a2eb7

Followup 4

From: Hallvard B Furuseth <h.b.furuseth@usit.uio.no>
Date: Wed, 31 Oct 2007 15:09:17 +0100
To: david@schmitt.edv-bus.at
Cc: openldap-its@openldap.org
Subject: Re: (ITS#5199) slapd sometimes hangs with back-sql

It looks like thread 5 runs amok in sql_dbconn_mutex() while locking
sql_dbconn_mutex.  That mutex lacks an unlock operation in 2.3.38 where
slapd logs "backsql_open_db_conn(...): duplicate connection ID".  (Which
doesn't sound too good to me either, but then I don't know back-sql.)
If that's the problem, it was fixed in OpenLDAP 2.3.39 for ITS#5095.

-- 
Regards,
Hallvard

Followup 5

From: Hallvard B Furuseth <h.b.furuseth@usit.uio.no>
Date: Wed, 31 Oct 2007 18:11:38 +0100
To: david@schmitt.edv-bus.at
cc: openldap-its@openldap.org
Subject: Re: (ITS#5199) slapd sometimes hangs with back-sql

h.b.furuseth@usit.uio.no writes:
> It looks like thread 5 runs amok in sql_dbconn_mutex() while locking
> sql_dbconn_mutex.

Oops, cut&paste error.  I meant in backsql_free_db_conn().
Anyway, does your log contain that message some time before?

> "backsql_open_db_conn(...): duplicate connection ID".

The (...) is the (connection id).

-- 
Hallvard