Re: [nssldap] Looking for support on nss_ldap issue

[nssldap [at] evilbrain.com]

On Tue, 17 Nov 2009, Douglas E. Engert wrote:
> I don't have a CentOS system but we ran into issues with lost connections
> and TLS. This sounds a lot like:
>
> BUG #392: call do_close() if ldap_result() or ldap_parse_result()
>          fails (before returning NSS_UNAVAIL)
>
> and not having a timelimit set.
>
> Fixes for these are in nss_ldap-265 announced on 11/6/2009
>
> You may want to try using this newer version, if only to see if it fixes
> your problem even if CentOS does not have this version yet.
>
> Since this looks like issues with timeouts
> You may also want to set:
>
> idle_timelimit 20
> timelimit 30
>
> Good luck.

Thanks!  I have attached a document.

I downloaded the source for that version that you describe and built it 
into packages for my CentOS machines.  I tried it out, but I still 
encounter the timeout related failure.  I added the following lines to 
ldap.conf but to no avail:

bind_timelimit          5
idle_timelimit 5
timelimit 5

My LDAP servers are local and are not stressed, so I figured a low timeout 
would be acceptable.

The server that I hit with SIGSTOP that is detailed in the debug output 
was ldap1.management.example.com .

Any additional help would be appreciated, thanks again!

> --
>
> Douglas E. Engert  <DEEngert@anl.gov>
> Argonne National Laboratory
> 9700 South Cass Avenue
> Argonne, Illinois  60439
> (630) 252-5444
ldap_create
ldap_url_parse_ext(ldap://ldap1.management.example.com)
ldap_create
ldap_url_parse_ext(ldap://ldap1.management.example.com)
ldap_extended_operation
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP ldap1.management.example.com:389
ldap_new_socket: 7
ldap_prepare_socket: 7
ldap_connect_to_host: Trying 192.168.1.2:389
ldap_connect_timeout: fd: 7 tm: 5 async: 0
ldap_ndelay_on: 7
ldap_is_sock_ready: 7
ldap_ndelay_off: 7
ldap_open_defconn: successful
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush: 31 bytes to sd 7
ldap_result ld 0x55556e62adf0 msgid 1
ldap_chkResponseList ld 0x55556e62adf0 msgid 1 all 1
ldap_chkResponseList returns ld 0x55556e62adf0 NULL
wait4msg ld 0x55556e62adf0 msgid 1 (timeout 5000000 usec)
wait4msg continue ld 0x55556e62adf0 msgid 1 all 1
ldap_chkResponseList ld 0x55556e62adf0 msgid 1 all 1
ldap_chkResponseList returns ld 0x55556e62adf0 NULL
ldap_int_select
ldap_abandon 1
ldap_abandon_ext 1
do_abandon origid 1, msgid 1
ldap_msgdelete
ber_flush: 8 bytes to sd 7
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_free_request (origid 1, msgid 1)
ldap_err2string
ldap_unbind
ldap_free_connection 1 1
ldap_send_unbind
ber_flush: 7 bytes to sd 7
ldap_free_connection: actually freed
ldap_create
ldap_url_parse_ext(ldap://ldap2.management.example.com)
ldap_extended_operation
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP ldap2.management.example.com:389
ldap_new_socket: 7
ldap_prepare_socket: 7
ldap_connect_to_host: Trying 192.168.1.3:389
ldap_connect_timeout: fd: 7 tm: 5 async: 0
ldap_ndelay_on: 7
ldap_is_sock_ready: 7
ldap_ndelay_off: 7
ldap_open_defconn: successful
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush: 31 bytes to sd 7
ldap_result ld 0x55556e634240 msgid 1
ldap_chkResponseList ld 0x55556e634240 msgid 1 all 1
ldap_chkResponseList returns ld 0x55556e634240 NULL
wait4msg ld 0x55556e634240 msgid 1 (timeout 5000000 usec)
wait4msg continue ld 0x55556e634240 msgid 1 all 1
ldap_chkResponseList ld 0x55556e634240 msgid 1 all 1
ldap_chkResponseList returns ld 0x55556e634240 NULL
ldap_int_select
read1msg: ld 0x55556e634240 msgid 1 all 1
ber_get_next
ber_get_next: tag 0x30 len 12 contents:
read1msg: ld 0x55556e634240 msgid 1 message type extended-result
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x55556e634240 0 new referrals
read1msg:  mark request completed, ld 0x55556e634240 msgid 1
request done: ld 0x55556e634240 msgid 1
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
TLS trace: SSL_connect:before/connect initialization
TLS trace: SSL_connect:SSLv2/v3 write client hello A
TLS trace: SSL_connect:SSLv3 read server hello A
TLS certificate verification: depth: 1, err: 0, subject: /C=US/ST=New 
York/L=New York/O=Example/CN=example.com, issuer: /C=US/ST=New York/L=New 
York/O=Example/CN=example.com
TLS certificate verification: depth: 0, err: 0, subject: /C=US/ST=New 
York/O=Example/CN=ldap2.management.example.com, issuer: /C=US/ST=New York/L=New 
York/O=Example/CN=example.com
TLS trace: SSL_connect:SSLv3 read server certificate A
TLS trace: SSL_connect:SSLv3 read server done A
TLS trace: SSL_connect:SSLv3 write client key exchange A
TLS trace: SSL_connect:SSLv3 write change cipher spec A
TLS trace: SSL_connect:SSLv3 write finished A
TLS trace: SSL_connect:SSLv3 flush data
TLS trace: SSL_connect:SSLv3 read finished A
ldap_simple_bind
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({i) ber:
ber_flush: 14 bytes to sd 7
ldap_result ld 0x55556e634240 msgid 2
ldap_chkResponseList ld 0x55556e634240 msgid 2 all 0
ldap_chkResponseList returns ld 0x55556e634240 NULL
wait4msg ld 0x55556e634240 msgid 2 (timeout 5000000 usec)
wait4msg continue ld 0x55556e634240 msgid 2 all 0
ldap_chkResponseList ld 0x55556e634240 msgid 2 all 0
ldap_chkResponseList returns ld 0x55556e634240 NULL
ldap_int_select
read1msg: ld 0x55556e634240 msgid 2 all 0
ber_get_next
ber_get_next: tag 0x30 len 12 contents:
read1msg: ld 0x55556e634240 msgid 2 message type bind
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x55556e634240 0 new referrals
read1msg:  mark request completed, ld 0x55556e634240 msgid 2
request done: ld 0x55556e634240 msgid 2
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ldap_search
put_filter: "(&(objectClass=shadowAccount)(uid=mark))"
put_filter: AND
put_filter_list "(objectClass=shadowAccount)(uid=mark)"
put_filter: "(objectClass=shadowAccount)"
put_filter: simple
put_simple_filter: "objectClass=shadowAccount"
put_filter: "(uid=mark)"
put_filter: simple
put_simple_filter: "uid=mark"
ldap_send_initial_request
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush: 206 bytes to sd 7
ldap_result ld 0x55556e634240 msgid 3
ldap_chkResponseList ld 0x55556e634240 msgid 3 all 1
ldap_chkResponseList returns ld 0x55556e634240 NULL
wait4msg ld 0x55556e634240 msgid 3 (timeout 5000000 usec)
wait4msg continue ld 0x55556e634240 msgid 3 all 1
ldap_chkResponseList ld 0x55556e634240 msgid 3 all 1
ldap_chkResponseList returns ld 0x55556e634240 NULL
ldap_int_select
read1msg: ld 0x55556e634240 msgid 3 all 1
ber_get_next
ber_get_next: tag 0x30 len 79 contents:
read1msg: ld 0x55556e634240 msgid 3 message type search-entry
wait4msg ld 0x55556e634240 5 secs to go
wait4msg continue ld 0x55556e634240 msgid 3 all 1
ldap_chkResponseList ld 0x55556e634240 msgid 3 all 1
ldap_chkResponseList returns ld 0x55556e634240 NULL
ldap_int_select
read1msg: ld 0x55556e634240 msgid 3 all 1
ber_get_next
ber_get_next: tag 0x30 len 12 contents:
read1msg: ld 0x55556e634240 msgid 3 message type search-result
ber_scanf fmt ({eaa) ber:
ber_scanf fmt ({eaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg: ld 0x55556e634240 0 new referrals
read1msg:  mark request completed, ld 0x55556e634240 msgid 3
request done: ld 0x55556e634240 msgid 3
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 3, msgid 3)
ldap_free_connection 0 1
ldap_free_connection: refcnt 1
adding response ld 0x55556e634240 msgid 3 type 101:
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([v]) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt ([v]) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_get_values
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ldap_msgfree
ldap_create
ldap_extended_operation_s
ldap_extended_operation
ldap_send_initial_request
ldap_new_connection 1 1 0
ldap_int_open_connection
ldap_connect_to_host: TCP ldap1.management.example.com:389
ldap_new_socket: 10
ldap_prepare_socket: 10
ldap_connect_to_host: Trying 192.168.1.2:389
ldap_connect_timeout: fd: 10 tm: 5 async: 0
ldap_ndelay_on: 10
ldap_is_sock_ready: 10
ldap_ndelay_off: 10
ldap_open_defconn: successful
ldap_send_server_request
ber_scanf fmt ({it) ber:
ber_scanf fmt ({) ber:
ber_flush: 31 bytes to sd 10
ldap_result ld 0x55556e6dde40 msgid 1
ldap_chkResponseList ld 0x55556e6dde40 msgid 1 all 1
ldap_chkResponseList returns ld 0x55556e6dde40 NULL
wait4msg ld 0x55556e6dde40 msgid 1 (infinite timeout)
wait4msg continue ld 0x55556e6dde40 msgid 1 all 1
ldap_chkResponseList ld 0x55556e6dde40 msgid 1 all 1
ldap_chkResponseList returns ld 0x55556e6dde40 NULL
ldap_int_select