michael@stroeder.com wrote:
Full_Name: Michael Ströder Version: 2.4.25 OS: openSUSE Linux 11.4 URL: Submission from: (NULL) (84.128.243.158)
Currently I observe something like below in my syslog.
The syslog output you included doesn't show anything unusual. Did you have an actual bug to report?
This is a simple python-ldap (linked against OpenLDAP libs 2.4.25) script doing LDAPI connect and unbind. I occasionally experience hangs when doing unbind also to other LDAP servers.
Your syslog output doesn't show any problem. Your debug output also doesn't show any problem.
The debug output shows that a read attempt was queued up for a socket that was closed. This is a normal occurrence when an LDAP client closes its connection immediately after sending its last request (Unbind here) and slapd doesn't have enough CPU resources to process the read attempt immediately. By the time slapd gets to this event in its queue, the connection is gone.
If you're reporting a hang with OpenLDAP, you should have said that explicitly. If not, then I see no bug here and this ITS will be closed.
---------------------- debug log ---------------------- [..private search results snipped..] <= send_search_entry: conn 1000 exit. send_ldap_result: conn=1000 op=0 p=3 send_ldap_result: err=0 matched="" text="" send_ldap_response: msgid=1 tag=101 err=0 ber_flush2: 14 bytes to sd 18 0000: 30 0c 02 01 01 65 07 0a 01 00 04 00 04 00 0....e........ ldap_write: want=14, written=14 0000: 30 0c 02 01 01 65 07 0a 01 00 04 00 04 00 0....e........ conn=1000 op=0 SEARCH RESULT tag=101 err=0 nentries=72 text= daemon: activity on 1 descriptor daemon: activity on: 18r daemon: read active on 18 daemon: epoll: listen=7 active_threads=0 tvp=zero daemon: epoll: listen=8 active_threads=0 tvp=zero daemon: epoll: listen=9 active_threads=0 tvp=zero daemon: activity on 1 descriptor daemon: activity on: daemon: read active on 18 daemon: epoll: listen=7 active_threads=0 tvp=zero daemon: epoll: listen=8 active_threads=0 tvp=zero daemon: epoll: listen=9 active_threads=0 tvp=zero daemon: activity on 1 descriptor daemon: activity on: daemon: read active on 18 daemon: epoll: listen=7 active_threads=0 tvp=zero daemon: epoll: listen=8 active_threads=0 tvp=zero daemon: epoll: listen=9 active_threads=0 tvp=zero connection_get(18) connection_get(18): got connid=1000 connection_read(18): checking for input on id=1000 ber_get_next ldap_read: want=8, got=7 0000: 30 05 02 01 02 42 00 0....B. ber_get_next: tag 0x30 len 5 contents: ber_dump: buf=0xe9d5a0 ptr=0xe9d5a0 end=0xe9d5a5 len=5 0000: 02 01 02 42 00 ...B. op tag 0x42, time 1304096292 ber_get_next ldap_read: want=8, got=0
ber_get_next on fd 18 failed errno=0 (Success) connection_read(18): input error=-2 id=1000, closing. connection_closing: readying conn=1000 sd=18 for close connection_close: deferring conn=1000 sd=18 conn=1000 op=1 do_unbind conn=1000 op=1 UNBIND connection_resched: attempting closing conn=1000 sd=18 connection_close: conn=1000 sd=18 =>ldap_back_conn_destroy: fetching conn 1000 daemon: removing 18 conn=1000 fd=18 closed connection_get(18) connection_get(18): connection not used connection_read(18): no connection! connection_read(18) error connection_get(18) connection_get(18): connection not used connection_read(18): no connection! connection_read(18) error daemon: activity on 1 descriptor daemon: activity on: daemon: epoll: listen=7 active_threads=0 tvp=zero daemon: epoll: listen=8 active_threads=0 tvp=zero daemon: epoll: listen=9 active_threads=0 tvp=zero