[Date Prev][Date Next] [Chronological] [Thread] [Top]
Re: ITS#3304: AD hang

To: openldap-its@OpenLDAP.org
Subject: Re: ITS#3304: AD hang
From: mwt@cems.umn.edu
Date: Mon, 1 Nov 2004 18:03:32 GMT
Kurt,

It is hanging without the -C, enabling the -C option causes the search 
to finish sucessfully, here is the ldapsearch command I used (passwords 
have been starred)

ldapsearch -H ldaps://phoenix.cems.umn.edu -x -d 1 -b 
"dc=cems,dc=umn,dc=edu" -s "sub" -D "cn=nssldap,ou=Users,ou=IT 
Office,dc=cems,dc=umn,dc=edu" -w '********' "cn=mwt"

here's the debug output (without -C)

ldap_create
ldap_url_parse_ext(ldaps://phoenix.cems.umn.edu)
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP phoenix.cems.umn.edu:636
ldap_new_socket: 3
ldap_prepare_socket: 3
ldap_connect_to_host: Trying 134.84.165.42:636
ldap_connect_timeout: fd: 3 tm: -1 async: 0
ldap_ndelay_on: 3
ldap_is_sock_ready: 3
ldap_ndelay_off: 3
ldap_int_sasl_open: host=phoenix.cems.umn.edu
TLS certificate verification: depth: 0, err: 66, subject: C=, ST=, L=, 
O=, OU=, CN=phoenix.cems.umn.edu/Email=, issuer: C=, ST=MN, 
L=Minneapolis, O=University of Minnesota, OU=CEMS, 
CN=phoenix/Email=cems_sys@cems.umn.edu
TLS certificate verification: Error, Unknown error
ldap_open_defconn: successful
ldap_send_server_request
ber_flush: 83 bytes to sd 3
ldap_result msgid 1
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 1
wait4msg continue, msgid 1, all 1
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:01:12 2004

** Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 1, all 1
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type bind msgid 1, original id 1
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 1
request 1 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ldap_search_ext
put_filter: "cn=mwt"
put_filter: default
put_simple_filter: "cn=mwt"
ldap_send_initial_request
ldap_send_server_request
ber_flush: 58 bytes to sd 3
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:01:12 2004

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 2108 contents:
ldap_read: message type search-entry msgid 2, original id 2
ldap_get_dn
ber_scanf fmt ({a) ber:
ldap_dn2ufn
ldap_dn_normalize
=> ldap_bv2dn(CN=mwt,OU=Users,OU=IT Office,DC=cems,DC=umn,DC=edu,0)
<= ldap_bv2dn(CN=mwt,OU=Users,OU=IT Office,DC=cems,DC=umn,DC=edu,0)=0
=> ldap_dn2bv(64)
<= ldap_dn2bv(mwt, Users, IT Office, cems.umn.edu,64)=0
ber_scanf fmt ({xx) ber:
ldap_first_attribute
ber_scanf fmt ({xl{) ber:
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt (x}{a) ber:
<truncated...it does that for a while....>
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ldap_msgfree
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:01:12 2004

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 69 contents:
ldap_read: message type search-reference msgid 2, original id 2
ber_scanf fmt ({v) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:01:12 2004

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type search-result msgid 2, original id 2
ber_scanf fmt ({iaa) ber:
read1msg:  0 new referrals
read1msg:  mark request completed, id = 2
request 2 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_int_select

and right there is where it hangs. Here below is the debug output with 
-C on the above ldapsearch command:

ldap_create
ldap_url_parse_ext(ldaps://phoenix.cems.umn.edu)
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP phoenix.cems.umn.edu:636
ldap_new_socket: 3
ldap_prepare_socket: 3
ldap_connect_to_host: Trying 134.84.165.42:636
ldap_connect_timeout: fd: 3 tm: -1 async: 0
ldap_ndelay_on: 3
ldap_is_sock_ready: 3
ldap_ndelay_off: 3
ldap_int_sasl_open: host=phoenix.cems.umn.edu
TLS certificate verification: depth: 0, err: 66, subject: C=, ST=, L=, 
O=, OU=, CN=phoenix.cems.umn.edu/Email=, issuer: C=, ST=MN, 
L=Minneapolis, O=University of Minnesota, OU=CEMS, 
CN=phoenix/Email=cems_sys@cems.umn.edu
TLS certificate verification: Error, Unknown error
ldap_open_defconn: successful
ldap_send_server_request
ber_flush: 83 bytes to sd 3
ldap_result msgid 1
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 1
wait4msg continue, msgid 1, all 1
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 1, all 1
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type bind msgid 1, original id 1
ber_scanf fmt ({iaa) ber:
ber_scanf fmt ({iaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg:  0 new referrals
read1msg:  mark request completed, id = 1
request 1 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ldap_search_ext
put_filter: "cn=mwt"
put_filter: default
put_simple_filter: "cn=mwt"
ldap_send_initial_request
ldap_send_server_request
ber_flush: 58 bytes to sd 3
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 2108 contents:
ldap_read: message type search-entry msgid 2, original id 2
ldap_get_dn
ber_scanf fmt ({a) ber:
ldap_dn2ufn
ldap_dn_normalize
=> ldap_bv2dn(CN=mwt,OU=Users,OU=IT Office,DC=cems,DC=umn,DC=edu,0)
<= ldap_bv2dn(CN=mwt,OU=Users,OU=IT Office,DC=cems,DC=umn,DC=edu,0)=0
=> ldap_dn2bv(64)
<= ldap_dn2bv(mwt, Users, IT Office, cems.umn.edu,64)=0
ber_scanf fmt ({xx) ber:
ldap_first_attribute
ber_scanf fmt ({xl{) ber:
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
ldap_get_values_len
ber_scanf fmt ({x{{a) ber:
ber_scanf fmt (x}{a) ber:
ber_scanf fmt ([V]) ber:
ldap_next_attribute
ber_scanf fmt ({ax}) ber:
<truncated>
ldap_next_attribute
ldap_msgfree
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 0, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 69 contents:
ldap_read: message type search-reference msgid 2, original id 2
ber_scanf fmt ({v}) ber:
ldap_chase_v3referrals
ldap_url_parse_ext(ldap://cems.umn.edu/CN=Configuration,DC=cems,DC=umn,DC=edu)
re_encode_request: new msgid 3, new dn 
<CN=Configuration,DC=cems,DC=umn,DC=edu>
ber_scanf fmt ({it) ber:
ber_scanf fmt ({ae) ber:
ldap_chase_v3referral: msgid 2, url 
"ldap://cems.umn.edu/CN=Configuration,DC=cems,DC=umn,DC=edu";
ldap_send_server_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP cems.umn.edu:389
ldap_new_socket: 5
ldap_prepare_socket: 5
ldap_connect_to_host: Trying 134.84.165.42:389
ldap_connect_timeout: fd: 5 tm: -1 async: 0
ldap_ndelay_on: 5
ldap_is_sock_ready: 5
ldap_ndelay_off: 5
ldap_int_sasl_open: host=phoenix.cems.umn.edu
anonymous rebind via ldap_bind_s
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ber_flush: 14 bytes to sd 5
ldap_result msgid 4
ldap_chkResponseList for msgid=4, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 4
wait4msg continue, msgid 4, all 1
** Connections:
* host: cems.umn.edu  port: 0
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:05:26 2004
  rebind in progress
    queue is empty

* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 4,  origid 4, status InProgress
   outstanding referrals 0, parent count 0
 * msgid 2,  origid 2, status InProgress
   outstanding referrals 1, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=4, all=1
ldap_chkResponseList returns NULL
read1msg: msgid 4, all 1
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type search-result msgid 2, original id 2
ber_scanf fmt ({iaa) ber:
ber_scanf fmt ({iaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg:  0 new referrals
read1msg:  mark request completed, id = 2
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_int_select
read1msg: msgid 4, all 1
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type bind msgid 4, original id 4
ber_scanf fmt ({iaa) ber:
ber_scanf fmt ({iaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg:  0 new referrals
read1msg:  mark request completed, id = 4
request 4 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 4, msgid 4)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_msgfree
ber_flush: 75 bytes to sd 5
read1msg:  1 new referrals
wait4msg continue, msgid -1, all 0
** Connections:
* host: cems.umn.edu  port: 0
  refcnt: 1  status: Connected
  last used: Mon Nov  1 12:05:26 2004
 
* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 1  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 3,  origid 2, status InProgress
   outstanding referrals 0, parent count 1
 * msgid 2,  origid 2, status Request Completed
   outstanding referrals 1, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 79 contents:
ldap_read: message type search-reference msgid 3, original id 2
ber_scanf fmt ({v}) ber:
ldap_chase_v3referrals
ldap_url_parse_ext(ldap://cems.umn.edu/CN=Schema,CN=Configuration,DC=cems,DC=umn,DC=edu)
re_encode_request: new msgid 5, new dn 
<CN=Schema,CN=Configuration,DC=cems,DC=umn,DC=edu>
ber_scanf fmt ({it) ber:
ber_scanf fmt ({ae) ber:
ldap_chase_v3referral: msgid 3, url 
"ldap://cems.umn.edu/CN=Schema,CN=Configuration,DC=cems,DC=umn,DC=edu";
ldap_send_server_request
ber_flush: 85 bytes to sd 5
read1msg:  search ref chased, mark request chasing refs, id = 3
read1msg:  1 new referrals
wait4msg continue, msgid -1, all 0
** Connections:
* host: cems.umn.edu  port: 0
  refcnt: 2  status: Connected
  last used: Mon Nov  1 12:05:26 2004

* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 1  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 5,  origid 2, status InProgress
   outstanding referrals 0, parent count 1
 * msgid 3,  origid 2, status ChasingRefs
   outstanding referrals 0, parent count 1
 * msgid 2,  origid 2, status Request Completed
   outstanding referrals 2, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type search-result msgid 3, original id 2
ber_scanf fmt ({iaa) ber:
ber_scanf fmt ({iaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg:  0 new referrals
read1msg:  mark request completed, id = 3
merged parent (id 2) error info:  result errno 0, error <>, matched <>
ldap_free_connection
ldap_free_connection: refcnt 1
wait4msg continue, msgid -1, all 0
** Connections:
* host: cems.umn.edu  port: 0
  refcnt: 1  status: Connected
  last used: Mon Nov  1 12:05:26 2004

* host: phoenix.cems.umn.edu  port: 636  (default)
  refcnt: 1  status: Connected
  last used: Mon Nov  1 12:05:26 2004

** Outstanding Requests:
 * msgid 5,  origid 2, status InProgress
   outstanding referrals 0, parent count 1
 * msgid 3,  origid 2, status Request Completed
   outstanding referrals 0, parent count 1
 * msgid 2,  origid 2, status Request Completed
   outstanding referrals 1, parent count 0
** Response Queue:
   Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ber_get_next
ber_get_next: tag 0x30 len 16 contents:
ldap_read: message type search-result msgid 5, original id 2
ber_scanf fmt ({iaa) ber:
ber_scanf fmt ({iaa}) ber:
new result:  res_errno: 0, res_error: <>, res_matched: <>
read1msg:  0 new referrals
read1msg:  mark request completed, id = 5
merged parent (id 2) error info:  result errno 0, error <>, matched <>
request 2 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_request (origid 2, msgid 5)
ldap_free_request (origid 2, msgid 3)
ldap_free_connection
ldap_send_unbind
ber_flush: 7 bytes to sd 5
ldap_free_connection: actually freed
ldap_parse_result
ber_scanf fmt ({iaa) ber:
ber_scanf fmt (}) ber:
ldap_err2string
ldap_unbind
ldap_free_connection
ldap_send_unbind
ber_flush: 7 bytes to sd 3
ldap_free_connection: actually freed
# extended LDIF
#
# LDAPv3
# base <dc=cems,dc=umn,dc=edu> with scope sub
# filter: cn=mwt
# requesting: ALL

<truncated actual search results, but it did return the correct information>

# search result
search: 2
result: 0 Success

# numResponses: 2
# numEntries: 1




Let me know if you need anymore.

--Mike


>Is ldapsearch(1) hanging with or without -C?
>
>At 11:35 AM 10/28/2004, Mike Thomas wrote:
>  
>
>>Hello,
>>
>>I've never hacked around the OpenLDAP sources before, so forgive me if I've applied an uneducated fix, but after reading the diff between openldap 2.1.28 (working) and 2.1.29 (unworking) I went through and found the problem that was causing the referral hanging problem.
>>
>>This is with OpenLDAP 2.1.30
>>
>>Here's the segment of code (lines 805-807)
>>
>>                  if ( lc != NULL ) {
>>                              ldap_free_connection( ld, lc, 0, 1 );
>>                              *lcp = NULL;
>>                      }
>>
>>removing (or commenting out) the *lcp = NULL;  statement on line 807 resolves this problem. The searches now chase referrals correctly
>>and the search terminates instead of hangs. Like I said before, I'm fairly uneducated when it comes to the OpenLDAP code, I do not know if this fix introduces and other problems, but I thought since there was no progess (or stalled progress) on this bug, I'd investigate this myself.
>>
>>--Mike
>>
>>    
>>
>
>
>  
>
Prev by Date: Re: SyncREPL Behaves Inconsistently (ITS#3262)
Next by Date: Quick practical observation re DBD default configuration
Index(es):
- Chronological
- Thread