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

ldap search hangs forever



I'm using openldap-2.4.18 as a client to bind and asynchronously search an active directory server.

I have a domain, example.com, that has two domain controllers: one.example.com, and two.example.com.

The ip of one.example.com is 12.34.56.1
The ip of two.example.com is 12.34.56.2

The reverse mapping of 12.34.56.1 is one.example.com
The reverse mapping of 12.34.56.2 doesn't exist

-----

/ nslookup one.example.com
Server:    12.34.56.99
Address 1: 12.34.56.99 dns1.example.com

Name:      one.example.com
Address 1: 12.34.56.1 one.example.com



/ nslookup two.example.com
Server:    12.34.56.99
Address 1: 12.34.56.99 dns1.example.com

Name:      two.example.com
Address 1: 12.34.56.2



/ nslookup example.com
Server:    12.34.56.99
Address 1: 12.34.56.99 dns1.example.com

Name:      example.com
Address 1: 12.34.56.2
Address 2: 12.34.56.1 one.example.com



/ nslookup 12.34.56.2
Server:    12.34.56.99
Address 1: 12.34.56.99 dns1.example.com

Name:      12.34.56.2
Address 1: 12.34.56.2



/ nslookup 12.34.56.1
Server:    12.34.56.99
Address 1: 12.34.56.99 dns1.example.com

Name:      12.34.56.1
Address 1: 12.34.56.1 one.example.com

/

-----

I have given openldap a "rebind proc" to use when chasing the referrals.

I do a sasl gssapi bind to one.example.com, which succeeds.

I do a search, which returns three referrals:
  DomainDnsZones.example.com
  ForestDnsZones.example.com
  example.com

openldap looks up these three names and gets 12.34.56.2, which doesn't reverse map to anything.

Then I get error messages for each referral:

May 27 16:26:18 xyz: GSSAPI Error:  Miscellaneous failure (see text) (Server (krbtgt/23.56.2@EXAMPLE.COM) unknown)
May 27 16:26:18 xyz: GSSAPI Error:  Miscellaneous failure (see text) (Server (krbtgt/23.56.2@EXAMPLE.COM) unknown)
May 27 16:26:18 xyz: GSSAPI Error:  Miscellaneous failure (see text) (Server (krbtgt/23.56.2@EXAMPLE.COM) unknown)

Then openldap hangs forever; I never get a LDAP_RES_SEARCH_RESULT.

-----

If I modify my DNS server to return 12.34.56.1 first instead of 12.34.56.2, then everything works perfectly.
If I don't chase referrals, then everything works perfectly minus chasing referrals of course.
If I use "normal" binding instead of sasl gssapi, then everything works perfectly.
If I use openldap's syncronous search instead of asyncronously polling with ldap_result, then the call times out and returns.

I half-expected openldap to not be able to bind to the referrals, but still fail quickly and return.
I don't understand why the ldap search never finishes. (I never get a LDAP_RES_SEARCH_RESULT)
I did get a LDAP_RES_SEARCH_REFERENCE and a LDAP_NO_RESULTS_RETURNED, but those dont signify the search has finished, right?

I've attached the ldap debugging. You'll see at the end the repeated calls to ldap_result with timeouts of 10 seconds.
I don't know how to read them exactly, but the status seems to be "RequestCompleted" ?

-----

17:20:50.530 ldap_result ld 0x10097060 msgid 5
17:20:50.530 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:50.530 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:50.530 ** ld 0x10097060 Connections:
17:20:50.530 * host: one.example.com  port: 389  (default)
17:20:50.530   refcnt: 1  status: Connected
17:20:50.530   last used: Wed May 26 17:19:59 2010

17:20:50.530
17:20:50.530 ** ld 0x10097060 Outstanding Requests:
17:20:50.530  * msgid 5,  origid 5, status RequestCompleted
17:20:50.530    outstanding referrals 0, parent count 0
17:20:50.530   ld 0x10097060 request count 1 (abandoned 0)
17:20:50.530 ** ld 0x10097060 Response Queue:
17:20:50.530    Empty
17:20:50.530   ld 0x10097060 response count 0
17:20:50.530 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:50.530 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:50.530 ldap_int_select

-----

I got the latest 2.4.22 release and grabbed the majority of the changes, but the hang remains.

You can see the full debugging information in the attached txt file.

I'm asking if the forever hang could be a bug in openldap, or perhaps I'm doing something wrong?

Thanks,
 - Jeremiah


17:19:58.876 ldap_create
17:19:58.876 ldap_url_parse_ext(ldap://one.example.com:389/??base)
17:19:58.881 ldap_err2string
17:19:58.881 ldap_err2string
17:19:59.415 ldap_pvt_sasl_getmech
17:19:59.415 ldap_search
17:19:59.415 put_filter: "(objectclass=*)"
17:19:59.416 put_filter: simple
17:19:59.416 put_simple_filter: "objectclass=*"
17:19:59.416 ldap_send_initial_request
17:19:59.416 ldap_new_connection 1 1 0
17:19:59.416 ldap_int_open_connection
17:19:59.416 ldap_connect_to_host: TCP one.example.com:389
17:19:59.421 ldap_new_socket: 7
17:19:59.421 ldap_prepare_socket: 7
17:19:59.421 ldap_connect_to_host: Trying 12.34.56.1:389
17:19:59.421 ldap_pvt_connect: fd: 7 tm: 30 async: 0
17:19:59.421 ldap_ndelay_on: 7
17:19:59.422 ldap_int_poll: fd: 7 tm: 30
17:19:59.422 ldap_is_sock_ready: 7
17:19:59.422 ldap_ndelay_off: 7
17:19:59.422 ldap_pvt_connect: 0
17:19:59.422 ldap_open_defconn: successful
17:19:59.422 ldap_send_server_request
17:19:59.423 ldap_result ld 0x10097060 msgid 1
17:19:59.423 wait4msg ld 0x10097060 msgid 1 (infinite timeout)
17:19:59.423 wait4msg continue ld 0x10097060 msgid 1 all 1
17:19:59.423 ** ld 0x10097060 Connections:
17:19:59.423 * host: one.example.com  port: 389  (default)
17:19:59.423   refcnt: 2  status: Connected
17:19:59.423   last used: Wed May 26 17:19:59 2010

17:19:59.423 
17:19:59.423 ** ld 0x10097060 Outstanding Requests:
17:19:59.423  * msgid 1,  origid 1, status InProgress
17:19:59.423    outstanding referrals 0, parent count 0
17:19:59.423   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.423 ** ld 0x10097060 Response Queue:
17:19:59.423    Empty
17:19:59.424   ld 0x10097060 response count 0
17:19:59.424 ldap_chkResponseList ld 0x10097060 msgid 1 all 1
17:19:59.424 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.424 ldap_int_select
17:19:59.424 read1msg: ld 0x10097060 msgid 1 all 1
17:19:59.424 read1msg: ld 0x10097060 msgid 1 message type search-entry
17:19:59.424 wait4msg continue ld 0x10097060 msgid 1 all 1
17:19:59.424 ** ld 0x10097060 Connections:
17:19:59.424 * host: one.example.com  port: 389  (default)
17:19:59.424   refcnt: 2  status: Connected
17:19:59.424   last used: Wed May 26 17:19:59 2010

17:19:59.424 
17:19:59.424 ** ld 0x10097060 Outstanding Requests:
17:19:59.424  * msgid 1,  origid 1, status InProgress
17:19:59.424    outstanding referrals 0, parent count 0
17:19:59.424   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.424 ** ld 0x10097060 Response Queue:
17:19:59.424  * msgid 1,  type 100
17:19:59.424   ld 0x10097060 response count 1
17:19:59.424 ldap_chkResponseList ld 0x10097060 msgid 1 all 1
17:19:59.424 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.425 ldap_int_select
17:19:59.425 read1msg: ld 0x10097060 msgid 1 all 1
17:19:59.425 read1msg: ld 0x10097060 msgid 1 message type search-result
17:19:59.425 read1msg: ld 0x10097060 0 new referrals
17:19:59.425 read1msg:  mark request completed, ld 0x10097060 msgid 1
17:19:59.425 request done: ld 0x10097060 msgid 1
17:19:59.425 res_errno: 0, res_error: <>, res_matched: <>
17:19:59.425 ldap_free_request (origid 1, msgid 1)
17:19:59.425 adding response ld 0x10097060 msgid 1 type 101:
17:19:59.425 ldap_parse_result
17:19:59.425 ldap_get_values
17:19:59.425 ldap_msgfree
17:19:59.425 ldap_sasl_interactive_bind_s: server supports: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:19:59.425 ldap_int_sasl_bind: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:19:59.464 ldap_int_sasl_open: host=one.example.com
17:19:59.535 ldap_sasl_bind_s
17:19:59.535 ldap_sasl_bind
17:19:59.535 ldap_send_initial_request
17:19:59.535 ldap_send_server_request
17:19:59.535 ldap_result ld 0x10097060 msgid 2
17:19:59.535 wait4msg ld 0x10097060 msgid 2 (infinite timeout)
17:19:59.536 wait4msg continue ld 0x10097060 msgid 2 all 1
17:19:59.536 ** ld 0x10097060 Connections:
17:19:59.536 * host: one.example.com  port: 389  (default)
17:19:59.536   refcnt: 2  status: Connected
17:19:59.536   last used: Wed May 26 17:19:59 2010

17:19:59.536 
17:19:59.536 ** ld 0x10097060 Outstanding Requests:
17:19:59.536  * msgid 2,  origid 2, status InProgress
17:19:59.536    outstanding referrals 0, parent count 0
17:19:59.536   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.536 ** ld 0x10097060 Response Queue:
17:19:59.536    Empty
17:19:59.536   ld 0x10097060 response count 0
17:19:59.536 ldap_chkResponseList ld 0x10097060 msgid 2 all 1
17:19:59.536 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.536 ldap_int_select
17:19:59.537 read1msg: ld 0x10097060 msgid 2 all 1
17:19:59.537 read1msg: ld 0x10097060 msgid 2 message type bind
17:19:59.537 read1msg: ld 0x10097060 0 new referrals
17:19:59.537 read1msg:  mark request completed, ld 0x10097060 msgid 2
17:19:59.538 request done: ld 0x10097060 msgid 2
17:19:59.538 res_errno: 14, res_error: <>, res_matched: <>
17:19:59.538 ldap_free_request (origid 2, msgid 2)
17:19:59.538 ldap_parse_sasl_bind_result
17:19:59.538 ldap_parse_result
17:19:59.538 ldap_msgfree
17:19:59.539 sasl_client_step: 1
17:19:59.539 ldap_sasl_bind_s
17:19:59.539 ldap_sasl_bind
17:19:59.539 ldap_send_initial_request
17:19:59.539 ldap_send_server_request
17:19:59.539 ldap_result ld 0x10097060 msgid 3
17:19:59.539 wait4msg ld 0x10097060 msgid 3 (infinite timeout)
17:19:59.539 wait4msg continue ld 0x10097060 msgid 3 all 1
17:19:59.539 ** ld 0x10097060 Connections:
17:19:59.539 * host: one.example.com  port: 389  (default)
17:19:59.539   refcnt: 2  status: Connected
17:19:59.539   last used: Wed May 26 17:19:59 2010

17:19:59.539 
17:19:59.539 ** ld 0x10097060 Outstanding Requests:
17:19:59.539  * msgid 3,  origid 3, status InProgress
17:19:59.539    outstanding referrals 0, parent count 0
17:19:59.540   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.540 ** ld 0x10097060 Response Queue:
17:19:59.540    Empty
17:19:59.540   ld 0x10097060 response count 0
17:19:59.540 ldap_chkResponseList ld 0x10097060 msgid 3 all 1
17:19:59.540 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.540 ldap_int_select
17:19:59.540 read1msg: ld 0x10097060 msgid 3 all 1
17:19:59.540 read1msg: ld 0x10097060 msgid 3 message type bind
17:19:59.540 read1msg: ld 0x10097060 0 new referrals
17:19:59.540 read1msg:  mark request completed, ld 0x10097060 msgid 3
17:19:59.540 request done: ld 0x10097060 msgid 3
17:19:59.540 res_errno: 14, res_error: <>, res_matched: <>
17:19:59.540 ldap_free_request (origid 3, msgid 3)
17:19:59.540 ldap_parse_sasl_bind_result
17:19:59.540 ldap_parse_result
17:19:59.540 ldap_msgfree
17:19:59.546 sasl_client_step: 0
17:19:59.546 ldap_sasl_bind_s
17:19:59.546 ldap_sasl_bind
17:19:59.546 ldap_send_initial_request
17:19:59.546 ldap_send_server_request
17:19:59.547 ldap_result ld 0x10097060 msgid 4
17:19:59.547 wait4msg ld 0x10097060 msgid 4 (infinite timeout)
17:19:59.547 wait4msg continue ld 0x10097060 msgid 4 all 1
17:19:59.547 ** ld 0x10097060 Connections:
17:19:59.547 * host: one.example.com  port: 389  (default)
17:19:59.547   refcnt: 2  status: Connected
17:19:59.547   last used: Wed May 26 17:19:59 2010

17:19:59.547 
17:19:59.547 ** ld 0x10097060 Outstanding Requests:
17:19:59.547  * msgid 4,  origid 4, status InProgress
17:19:59.547    outstanding referrals 0, parent count 0
17:19:59.547   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.547 ** ld 0x10097060 Response Queue:
17:19:59.547    Empty
17:19:59.547   ld 0x10097060 response count 0
17:19:59.547 ldap_chkResponseList ld 0x10097060 msgid 4 all 1
17:19:59.547 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.547 ldap_int_select
17:19:59.547 read1msg: ld 0x10097060 msgid 4 all 1
17:19:59.548 read1msg: ld 0x10097060 msgid 4 message type bind
17:19:59.548 read1msg: ld 0x10097060 0 new referrals
17:19:59.548 read1msg:  mark request completed, ld 0x10097060 msgid 4
17:19:59.548 request done: ld 0x10097060 msgid 4
17:19:59.548 res_errno: 0, res_error: <>, res_matched: <>
17:19:59.548 ldap_free_request (origid 4, msgid 4)
17:19:59.548 ldap_parse_sasl_bind_result
17:19:59.548 ldap_parse_result
17:19:59.548 ldap_msgfree
17:19:59.548 ldap_int_sasl_bind: ignoring  bogus empty data provided with SASL outcome message.
17:19:59.548 ldap_pvt_sasl_generic_install
17:19:59.548 ldap_err2string
17:19:59.548 ldap_err2string
17:19:59.549 ldap_search_ext
17:19:59.549 put_filter: "(objectclass=*)"
17:19:59.549 put_filter: simple
17:19:59.549 put_simple_filter: "objectclass=*"
17:19:59.549 ldap_send_initial_request
17:19:59.549 ldap_send_server_request
17:19:59.550 ldap_result ld 0x10097060 msgid 5
17:19:59.550 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:19:59.550 wait4msg continue ld 0x10097060 msgid 5 all 2
17:19:59.550 ** ld 0x10097060 Connections:
17:19:59.550 * host: one.example.com  port: 389  (default)
17:19:59.550   refcnt: 2  status: Connected
17:19:59.550   last used: Wed May 26 17:19:59 2010

17:19:59.550 
17:19:59.550 ** ld 0x10097060 Outstanding Requests:
17:19:59.550  * msgid 5,  origid 5, status InProgress
17:19:59.550    outstanding referrals 0, parent count 0
17:19:59.550   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.550 ** ld 0x10097060 Response Queue:
17:19:59.550    Empty
17:19:59.550   ld 0x10097060 response count 0
17:19:59.551 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:19:59.551 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.551 ldap_int_select
17:19:59.551 read1msg: ld 0x10097060 msgid 5 all 2
17:19:59.551 read1msg: ld 0x10097060 msgid 5 message type search-entry
17:19:59.551 read1msg: ld 0x10097060 msgid 5 message type search-result
17:19:59.551 read1msg: ld 0x10097060 0 new referrals
17:19:59.551 read1msg:  mark request completed, ld 0x10097060 msgid 5
17:19:59.551 request done: ld 0x10097060 msgid 5
17:19:59.551 res_errno: 0, res_error: <>, res_matched: <>
17:19:59.551 ldap_free_request (origid 5, msgid 5)
17:19:59.551 adding response ld 0x10097060 msgid 5 type 101:
17:19:59.551 ldap_parse_result
17:19:59.552 ldap_get_dn
17:19:59.552 ldap_first_attribute
17:19:59.552 ldap_get_values_len
17:19:59.552 ldap_next_attribute
17:19:59.552 ldap_msgfree
17:19:59.553 ldap_err2string
17:19:59.553 ldap_err2string
17:19:59.553 ldap_err2string
17:19:59.553 ldap_err2string
17:19:59.553 ldap_free_connection 1 1
17:19:59.553 ldap_send_unbind
17:19:59.554 ldap_free_connection: actually freed
17:19:59.555 ldap_err2string
17:19:59.555 ldap_err2string
17:19:59.555 ldap_create
17:19:59.555 ldap_url_parse_ext(ldap://one.example.com:389/??sub)
17:19:59.560 ldap_err2string
17:19:59.560 ldap_err2string
17:19:59.940 ldap_pvt_sasl_getmech
17:19:59.940 ldap_search
17:19:59.940 put_filter: "(objectclass=*)"
17:19:59.940 put_filter: simple
17:19:59.940 put_simple_filter: "objectclass=*"
17:19:59.940 ldap_send_initial_request
17:19:59.941 ldap_new_connection 1 1 0
17:19:59.941 ldap_int_open_connection
17:19:59.941 ldap_connect_to_host: TCP one.example.com:389
17:19:59.947 ldap_new_socket: 7
17:19:59.948 ldap_prepare_socket: 7
17:19:59.948 ldap_connect_to_host: Trying 12.34.56.1:389
17:19:59.948 ldap_pvt_connect: fd: 7 tm: 30 async: 0
17:19:59.948 ldap_ndelay_on: 7
17:19:59.948 ldap_int_poll: fd: 7 tm: 30
17:19:59.948 ldap_is_sock_ready: 7
17:19:59.949 ldap_ndelay_off: 7
17:19:59.949 ldap_pvt_connect: 0
17:19:59.949 ldap_open_defconn: successful
17:19:59.949 ldap_send_server_request
17:19:59.949 ldap_result ld 0x10097060 msgid 1
17:19:59.949 wait4msg ld 0x10097060 msgid 1 (infinite timeout)
17:19:59.949 wait4msg continue ld 0x10097060 msgid 1 all 1
17:19:59.949 ** ld 0x10097060 Connections:
17:19:59.949 * host: one.example.com  port: 389  (default)
17:19:59.949   refcnt: 2  status: Connected
17:19:59.949   last used: Wed May 26 17:19:59 2010

17:19:59.949 
17:19:59.949 ** ld 0x10097060 Outstanding Requests:
17:19:59.949  * msgid 1,  origid 1, status InProgress
17:19:59.949    outstanding referrals 0, parent count 0
17:19:59.949   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.949 ** ld 0x10097060 Response Queue:
17:19:59.949    Empty
17:19:59.949   ld 0x10097060 response count 0
17:19:59.950 ldap_chkResponseList ld 0x10097060 msgid 1 all 1
17:19:59.950 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.950 ldap_int_select
17:19:59.950 read1msg: ld 0x10097060 msgid 1 all 1
17:19:59.950 read1msg: ld 0x10097060 msgid 1 message type search-entry
17:19:59.950 wait4msg continue ld 0x10097060 msgid 1 all 1
17:19:59.950 ** ld 0x10097060 Connections:
17:19:59.950 * host: one.example.com  port: 389  (default)
17:19:59.950   refcnt: 2  status: Connected
17:19:59.950   last used: Wed May 26 17:19:59 2010

17:19:59.950 
17:19:59.950 ** ld 0x10097060 Outstanding Requests:
17:19:59.950  * msgid 1,  origid 1, status InProgress
17:19:59.950    outstanding referrals 0, parent count 0
17:19:59.950   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.950 ** ld 0x10097060 Response Queue:
17:19:59.950  * msgid 1,  type 100
17:19:59.950   ld 0x10097060 response count 1
17:19:59.950 ldap_chkResponseList ld 0x10097060 msgid 1 all 1
17:19:59.950 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.950 ldap_int_select
17:19:59.950 read1msg: ld 0x10097060 msgid 1 all 1
17:19:59.950 read1msg: ld 0x10097060 msgid 1 message type search-result
17:19:59.951 read1msg: ld 0x10097060 0 new referrals
17:19:59.951 read1msg:  mark request completed, ld 0x10097060 msgid 1
17:19:59.951 request done: ld 0x10097060 msgid 1
17:19:59.951 res_errno: 0, res_error: <>, res_matched: <>
17:19:59.951 ldap_free_request (origid 1, msgid 1)
17:19:59.951 adding response ld 0x10097060 msgid 1 type 101:
17:19:59.951 ldap_parse_result
17:19:59.951 ldap_get_values
17:19:59.951 ldap_msgfree
17:19:59.951 ldap_sasl_interactive_bind_s: server supports: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:19:59.951 ldap_int_sasl_bind: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:19:59.951 ldap_int_sasl_open: host=one.example.com
17:19:59.971 ldap_sasl_bind_s
17:19:59.972 ldap_sasl_bind
17:19:59.972 ldap_send_initial_request
17:19:59.972 ldap_send_server_request
17:19:59.972 ldap_result ld 0x10097060 msgid 2
17:19:59.972 wait4msg ld 0x10097060 msgid 2 (infinite timeout)
17:19:59.972 wait4msg continue ld 0x10097060 msgid 2 all 1
17:19:59.972 ** ld 0x10097060 Connections:
17:19:59.972 * host: one.example.com  port: 389  (default)
17:19:59.972   refcnt: 2  status: Connected
17:19:59.972   last used: Wed May 26 17:19:59 2010

17:19:59.972 
17:19:59.972 ** ld 0x10097060 Outstanding Requests:
17:19:59.972  * msgid 2,  origid 2, status InProgress
17:19:59.972    outstanding referrals 0, parent count 0
17:19:59.972   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.972 ** ld 0x10097060 Response Queue:
17:19:59.972    Empty
17:19:59.972   ld 0x10097060 response count 0
17:19:59.972 ldap_chkResponseList ld 0x10097060 msgid 2 all 1
17:19:59.972 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.973 ldap_int_select
17:19:59.974 read1msg: ld 0x10097060 msgid 2 all 1
17:19:59.974 read1msg: ld 0x10097060 msgid 2 message type bind
17:19:59.974 read1msg: ld 0x10097060 0 new referrals
17:19:59.974 read1msg:  mark request completed, ld 0x10097060 msgid 2
17:19:59.974 request done: ld 0x10097060 msgid 2
17:19:59.974 res_errno: 14, res_error: <>, res_matched: <>
17:19:59.974 ldap_free_request (origid 2, msgid 2)
17:19:59.974 ldap_parse_sasl_bind_result
17:19:59.974 ldap_parse_result
17:19:59.974 ldap_msgfree
17:19:59.974 sasl_client_step: 1
17:19:59.974 ldap_sasl_bind_s
17:19:59.974 ldap_sasl_bind
17:19:59.974 ldap_send_initial_request
17:19:59.974 ldap_send_server_request
17:19:59.975 ldap_result ld 0x10097060 msgid 3
17:19:59.975 wait4msg ld 0x10097060 msgid 3 (infinite timeout)
17:19:59.975 wait4msg continue ld 0x10097060 msgid 3 all 1
17:19:59.975 ** ld 0x10097060 Connections:
17:19:59.975 * host: one.example.com  port: 389  (default)
17:19:59.975   refcnt: 2  status: Connected
17:19:59.975   last used: Wed May 26 17:19:59 2010

17:19:59.975 
17:19:59.975 ** ld 0x10097060 Outstanding Requests:
17:19:59.975  * msgid 3,  origid 3, status InProgress
17:19:59.975    outstanding referrals 0, parent count 0
17:19:59.975   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.975 ** ld 0x10097060 Response Queue:
17:19:59.975    Empty
17:19:59.975   ld 0x10097060 response count 0
17:19:59.975 ldap_chkResponseList ld 0x10097060 msgid 3 all 1
17:19:59.975 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.975 ldap_int_select
17:19:59.975 read1msg: ld 0x10097060 msgid 3 all 1
17:19:59.975 read1msg: ld 0x10097060 msgid 3 message type bind
17:19:59.975 read1msg: ld 0x10097060 0 new referrals
17:19:59.975 read1msg:  mark request completed, ld 0x10097060 msgid 3
17:19:59.976 request done: ld 0x10097060 msgid 3
17:19:59.976 res_errno: 14, res_error: <>, res_matched: <>
17:19:59.976 ldap_free_request (origid 3, msgid 3)
17:19:59.976 ldap_parse_sasl_bind_result
17:19:59.976 ldap_parse_result
17:19:59.976 ldap_msgfree
17:19:59.976 sasl_client_step: 0
17:19:59.976 ldap_sasl_bind_s
17:19:59.976 ldap_sasl_bind
17:19:59.976 ldap_send_initial_request
17:19:59.976 ldap_send_server_request
17:19:59.976 ldap_result ld 0x10097060 msgid 4
17:19:59.976 wait4msg ld 0x10097060 msgid 4 (infinite timeout)
17:19:59.977 wait4msg continue ld 0x10097060 msgid 4 all 1
17:19:59.977 ** ld 0x10097060 Connections:
17:19:59.977 * host: one.example.com  port: 389  (default)
17:19:59.977   refcnt: 2  status: Connected
17:19:59.977   last used: Wed May 26 17:19:59 2010

17:19:59.977 
17:19:59.977 ** ld 0x10097060 Outstanding Requests:
17:19:59.977  * msgid 4,  origid 4, status InProgress
17:19:59.977    outstanding referrals 0, parent count 0
17:19:59.977   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.977 ** ld 0x10097060 Response Queue:
17:19:59.977    Empty
17:19:59.977   ld 0x10097060 response count 0
17:19:59.977 ldap_chkResponseList ld 0x10097060 msgid 4 all 1
17:19:59.977 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.977 ldap_int_select
17:19:59.977 read1msg: ld 0x10097060 msgid 4 all 1
17:19:59.977 read1msg: ld 0x10097060 msgid 4 message type bind
17:19:59.977 read1msg: ld 0x10097060 0 new referrals
17:19:59.977 read1msg:  mark request completed, ld 0x10097060 msgid 4
17:19:59.977 request done: ld 0x10097060 msgid 4
17:19:59.977 res_errno: 0, res_error: <>, res_matched: <>
17:19:59.977 ldap_free_request (origid 4, msgid 4)
17:19:59.978 ldap_parse_sasl_bind_result
17:19:59.978 ldap_parse_result
17:19:59.978 ldap_msgfree
17:19:59.978 ldap_int_sasl_bind: ignoring  bogus empty data provided with SASL outcome message.
17:19:59.978 ldap_pvt_sasl_generic_install
17:19:59.978 ldap_err2string
17:19:59.978 ldap_err2string
17:19:59.979 ldap_search_ext
17:19:59.980 put_filter: "(|(&(objectclass=person)(cn=johndoe)))"
17:19:59.980 put_filter: OR
17:19:59.980 put_filter_list "(&(objectclass=person)(cn=johndoe))"
17:19:59.980 put_filter: "(&(objectclass=person)(cn=johndoe))"
17:19:59.980 put_filter: AND
17:19:59.980 put_filter_list "(objectclass=person)(cn=johndoe)"
17:19:59.980 put_filter: "(objectclass=person)"
17:19:59.980 put_filter: simple
17:19:59.980 put_simple_filter: "objectclass=person"
17:19:59.980 put_filter: "(cn=johndoe)"
17:19:59.980 put_filter: simple
17:19:59.980 put_simple_filter: "cn=johndoe"
17:19:59.980 ldap_send_initial_request
17:19:59.980 ldap_send_server_request
17:19:59.980 ldap_result ld 0x10097060 msgid 5
17:19:59.980 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:19:59.980 wait4msg continue ld 0x10097060 msgid 5 all 2
17:19:59.981 ** ld 0x10097060 Connections:
17:19:59.981 * host: one.example.com  port: 389  (default)
17:19:59.981   refcnt: 2  status: Connected
17:19:59.981   last used: Wed May 26 17:19:59 2010

17:19:59.981 
17:19:59.981 ** ld 0x10097060 Outstanding Requests:
17:19:59.981  * msgid 5,  origid 5, status InProgress
17:19:59.981    outstanding referrals 0, parent count 0
17:19:59.981   ld 0x10097060 request count 1 (abandoned 0)
17:19:59.981 ** ld 0x10097060 Response Queue:
17:19:59.981    Empty
17:19:59.981   ld 0x10097060 response count 0
17:19:59.981 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:19:59.981 ldap_chkResponseList returns ld 0x10097060 NULL
17:19:59.981 ldap_int_select
17:20:00.007 read1msg: ld 0x10097060 msgid 5 all 2
17:20:00.007 read1msg: ld 0x10097060 msgid 5 message type search-reference
17:20:00.007 ldap_chase_v3referrals
17:20:00.007 ldap_url_parse_ext(ldap://ForestDnsZones.example.com/DC=ForestDnsZones,DC=example,DC=com)
17:20:00.007 re_encode_request: new msgid 6, new dn <DC=ForestDnsZones,DC=example,DC=com>
17:20:00.007 ldap_chase_v3referral: msgid 5, url "ldap://ForestDnsZones.example.com/DC=ForestDnsZones,DC=example,DC=com";
17:20:00.007 ldap_send_server_request
17:20:00.007 ldap_new_connection 0 1 1
17:20:00.007 ldap_int_open_connection
17:20:00.008 ldap_connect_to_host: TCP ForestDnsZones.example.com:389
17:20:00.050 ldap_new_socket: 6
17:20:00.050 ldap_prepare_socket: 6
17:20:00.050 ldap_connect_to_host: Trying 12.34.56.2:389
17:20:00.050 ldap_pvt_connect: fd: 6 tm: 30 async: 0
17:20:00.050 ldap_ndelay_on: 6
17:20:00.050 ldap_int_poll: fd: 6 tm: 30
17:20:00.051 ldap_is_sock_ready: 6
17:20:00.051 ldap_ndelay_off: 6
17:20:00.051 ldap_pvt_connect: 0
17:20:00.051 Call application rebind_proc
17:20:00.051 ldap_pvt_sasl_getmech
17:20:00.051 ldap_search
17:20:00.051 put_filter: "(objectclass=*)"
17:20:00.051 put_filter: simple
17:20:00.051 put_simple_filter: "objectclass=*"
17:20:00.051 ldap_send_initial_request
17:20:00.051 ldap_send_server_request
17:20:00.051 ldap_result ld 0x10097060 msgid 7
17:20:00.051 wait4msg ld 0x10097060 msgid 7 (infinite timeout)
17:20:00.051 wait4msg continue ld 0x10097060 msgid 7 all 1
17:20:00.052 ** ld 0x10097060 Connections:
17:20:00.052 * host: ForestDnsZones.example.com  port: 0
17:20:00.052   refcnt: 2  status: Connected
17:20:00.052   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.052     queue is empty
17:20:00.052 
17:20:00.052 * host: one.example.com  port: 389  (default)
17:20:00.052   refcnt: 3  status: Connected
17:20:00.052   last used: Wed May 26 17:19:59 2010

17:20:00.052 
17:20:00.052 ** ld 0x10097060 Outstanding Requests:
17:20:00.052  * msgid 7,  origid 7, status InProgress
17:20:00.052    outstanding referrals 0, parent count 0
17:20:00.052  * msgid 5,  origid 5, status InProgress
17:20:00.052    outstanding referrals 1, parent count 0
17:20:00.052   ld 0x10097060 request count 2 (abandoned 0)
17:20:00.052 ** ld 0x10097060 Response Queue:
17:20:00.052    Empty
17:20:00.052   ld 0x10097060 response count 0
17:20:00.052 ldap_chkResponseList ld 0x10097060 msgid 7 all 1
17:20:00.052 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.052 read1msg: ld 0x10097060 msgid 7 all 1
17:20:00.053 read1msg: ld 0x10097060 msgid 5 message type search-reference
17:20:00.053 ldap_chase_v3referrals
17:20:00.053 ldap_url_parse_ext(ldap://DomainDnsZones.example.com/DC=DomainDnsZones,DC=example,DC=com)
17:20:00.053 re_encode_request: new msgid 8, new dn <DC=DomainDnsZones,DC=example,DC=com>
17:20:00.053 ldap_chase_v3referral: msgid 5, url "ldap://DomainDnsZones.example.com/DC=DomainDnsZones,DC=example,DC=com";
17:20:00.053 ldap_send_server_request
17:20:00.053 ldap_new_connection 0 1 1
17:20:00.053 ldap_int_open_connection
17:20:00.053 ldap_connect_to_host: TCP DomainDnsZones.example.com:389
17:20:00.131 ldap_new_socket: 8
17:20:00.131 ldap_prepare_socket: 8
17:20:00.131 ldap_connect_to_host: Trying 12.34.56.2:389
17:20:00.131 ldap_pvt_connect: fd: 8 tm: 30 async: 0
17:20:00.131 ldap_ndelay_on: 8
17:20:00.131 ldap_int_poll: fd: 8 tm: 30
17:20:00.132 ldap_is_sock_ready: 8
17:20:00.132 ldap_ndelay_off: 8
17:20:00.132 ldap_pvt_connect: 0
17:20:00.132 Call application rebind_proc
17:20:00.132 ldap_pvt_sasl_getmech
17:20:00.132 ldap_search
17:20:00.132 put_filter: "(objectclass=*)"
17:20:00.132 put_filter: simple
17:20:00.132 put_simple_filter: "objectclass=*"
17:20:00.132 ldap_send_initial_request
17:20:00.132 ldap_send_server_request
17:20:00.132 ldap_result ld 0x10097060 msgid 9
17:20:00.133 wait4msg ld 0x10097060 msgid 9 (infinite timeout)
17:20:00.133 wait4msg continue ld 0x10097060 msgid 9 all 1
17:20:00.133 ** ld 0x10097060 Connections:
17:20:00.133 * host: DomainDnsZones.example.com  port: 0
17:20:00.133   refcnt: 2  status: Connected
17:20:00.133   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.133     queue is empty
17:20:00.133 
17:20:00.133 * host: ForestDnsZones.example.com  port: 0
17:20:00.133   refcnt: 2  status: Connected
17:20:00.133   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.133     queue is empty
17:20:00.133 
17:20:00.133 * host: one.example.com  port: 389  (default)
17:20:00.133   refcnt: 4  status: Connected
17:20:00.133   last used: Wed May 26 17:19:59 2010

17:20:00.133 
17:20:00.133 ** ld 0x10097060 Outstanding Requests:
17:20:00.133  * msgid 9,  origid 9, status InProgress
17:20:00.133    outstanding referrals 0, parent count 0
17:20:00.133  * msgid 7,  origid 7, status InProgress
17:20:00.133    outstanding referrals 0, parent count 0
17:20:00.134  * msgid 5,  origid 5, status InProgress
17:20:00.134    outstanding referrals 2, parent count 0
17:20:00.134   ld 0x10097060 request count 3 (abandoned 0)
17:20:00.134 ** ld 0x10097060 Response Queue:
17:20:00.134    Empty
17:20:00.134   ld 0x10097060 response count 0
17:20:00.134 ldap_chkResponseList ld 0x10097060 msgid 9 all 1
17:20:00.134 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.134 read1msg: ld 0x10097060 msgid 9 all 1
17:20:00.134 read1msg: ld 0x10097060 msgid 5 message type search-reference
17:20:00.134 ldap_chase_v3referrals
17:20:00.134 ldap_url_parse_ext(ldap://example.com/CN=Configuration,DC=example,DC=com)
17:20:00.134 re_encode_request: new msgid 10, new dn <CN=Configuration,DC=example,DC=com>
17:20:00.134 ldap_chase_v3referral: msgid 5, url "ldap://example.com/CN=Configuration,DC=example,DC=com";
17:20:00.134 ldap_send_server_request
17:20:00.134 ldap_new_connection 0 1 1
17:20:00.134 ldap_int_open_connection
17:20:00.134 ldap_connect_to_host: TCP example.com:389
17:20:00.141 ldap_new_socket: 9
17:20:00.141 ldap_prepare_socket: 9
17:20:00.141 ldap_connect_to_host: Trying 12.34.56.2:389
17:20:00.141 ldap_pvt_connect: fd: 9 tm: 30 async: 0
17:20:00.141 ldap_ndelay_on: 9
17:20:00.141 ldap_int_poll: fd: 9 tm: 30
17:20:00.141 ldap_is_sock_ready: 9
17:20:00.142 ldap_ndelay_off: 9
17:20:00.142 ldap_pvt_connect: 0
17:20:00.142 Call application rebind_proc
17:20:00.142 ldap_pvt_sasl_getmech
17:20:00.142 ldap_search
17:20:00.142 put_filter: "(objectclass=*)"
17:20:00.142 put_filter: simple
17:20:00.142 put_simple_filter: "objectclass=*"
17:20:00.142 ldap_send_initial_request
17:20:00.142 ldap_send_server_request
17:20:00.142 ldap_result ld 0x10097060 msgid 11
17:20:00.142 wait4msg ld 0x10097060 msgid 11 (infinite timeout)
17:20:00.142 wait4msg continue ld 0x10097060 msgid 11 all 1
17:20:00.142 ** ld 0x10097060 Connections:
17:20:00.142 * host: example.com  port: 0
17:20:00.142   refcnt: 2  status: Connected
17:20:00.142   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.142     queue is empty
17:20:00.143 
17:20:00.143 * host: DomainDnsZones.example.com  port: 0
17:20:00.143   refcnt: 2  status: Connected
17:20:00.143   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.143     queue is empty
17:20:00.143 
17:20:00.143 * host: ForestDnsZones.example.com  port: 0
17:20:00.143   refcnt: 2  status: Connected
17:20:00.143   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.143     queue is empty
17:20:00.143 
17:20:00.143 * host: one.example.com  port: 389  (default)
17:20:00.143   refcnt: 5  status: Connected
17:20:00.143   last used: Wed May 26 17:19:59 2010

17:20:00.143 
17:20:00.143 ** ld 0x10097060 Outstanding Requests:
17:20:00.143  * msgid 11,  origid 11, status InProgress
17:20:00.143    outstanding referrals 0, parent count 0
17:20:00.143  * msgid 9,  origid 9, status InProgress
17:20:00.143    outstanding referrals 0, parent count 0
17:20:00.143  * msgid 7,  origid 7, status InProgress
17:20:00.143    outstanding referrals 0, parent count 0
17:20:00.144  * msgid 5,  origid 5, status InProgress
17:20:00.144    outstanding referrals 3, parent count 0
17:20:00.144   ld 0x10097060 request count 4 (abandoned 0)
17:20:00.144 ** ld 0x10097060 Response Queue:
17:20:00.144    Empty
17:20:00.144   ld 0x10097060 response count 0
17:20:00.144 ldap_chkResponseList ld 0x10097060 msgid 11 all 1
17:20:00.144 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.144 read1msg: ld 0x10097060 msgid 11 all 1
17:20:00.144 read1msg: ld 0x10097060 msgid 5 message type search-result
17:20:00.144 read1msg: ld 0x10097060 0 new referrals
17:20:00.144 read1msg:  mark request completed, ld 0x10097060 msgid 5
17:20:00.144 wait4msg continue ld 0x10097060 msgid 11 all 1
17:20:00.144 ** ld 0x10097060 Connections:
17:20:00.144 * host: example.com  port: 0
17:20:00.144   refcnt: 2  status: Connected
17:20:00.144   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.144     queue is empty
17:20:00.144 
17:20:00.144 * host: DomainDnsZones.example.com  port: 0
17:20:00.144   refcnt: 2  status: Connected
17:20:00.144   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.144     queue is empty
17:20:00.145 
17:20:00.145 * host: ForestDnsZones.example.com  port: 0
17:20:00.145   refcnt: 2  status: Connected
17:20:00.145   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.145     queue is empty
17:20:00.145 
17:20:00.145 * host: one.example.com  port: 389  (default)
17:20:00.145   refcnt: 4  status: Connected
17:20:00.145   last used: Wed May 26 17:19:59 2010

17:20:00.145 
17:20:00.145 ** ld 0x10097060 Outstanding Requests:
17:20:00.145  * msgid 11,  origid 11, status InProgress
17:20:00.145    outstanding referrals 0, parent count 0
17:20:00.145  * msgid 9,  origid 9, status InProgress
17:20:00.145    outstanding referrals 0, parent count 0
17:20:00.145  * msgid 7,  origid 7, status InProgress
17:20:00.145    outstanding referrals 0, parent count 0
17:20:00.145  * msgid 5,  origid 5, status RequestCompleted
17:20:00.145    outstanding referrals 3, parent count 0
17:20:00.145   ld 0x10097060 request count 4 (abandoned 0)
17:20:00.145 ** ld 0x10097060 Response Queue:
17:20:00.145    Empty
17:20:00.145   ld 0x10097060 response count 0
17:20:00.145 ldap_chkResponseList ld 0x10097060 msgid 11 all 1
17:20:00.145 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.145 ldap_int_select
17:20:00.146 read1msg: ld 0x10097060 msgid 11 all 1
17:20:00.146 read1msg: ld 0x10097060 msgid 11 message type search-entry
17:20:00.146 read1msg: ld 0x10097060 msgid 11 all 1
17:20:00.146 read1msg: ld 0x10097060 msgid 9 message type search-entry
17:20:00.146 read1msg: ld 0x10097060 msgid 11 all 1
17:20:00.146 read1msg: ld 0x10097060 msgid 7 message type search-entry
17:20:00.146 wait4msg continue ld 0x10097060 msgid 11 all 1
17:20:00.146 ** ld 0x10097060 Connections:
17:20:00.146 * host: example.com  port: 0
17:20:00.146   refcnt: 2  status: Connected
17:20:00.146   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.146     queue is empty
17:20:00.146 
17:20:00.146 * host: DomainDnsZones.example.com  port: 0
17:20:00.146   refcnt: 2  status: Connected
17:20:00.146   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.146     queue is empty
17:20:00.146 
17:20:00.146 * host: ForestDnsZones.example.com  port: 0
17:20:00.146   refcnt: 2  status: Connected
17:20:00.146   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.146     queue is empty
17:20:00.147 
17:20:00.147 * host: one.example.com  port: 389  (default)
17:20:00.147   refcnt: 4  status: Connected
17:20:00.147   last used: Wed May 26 17:19:59 2010

17:20:00.147 
17:20:00.147 ** ld 0x10097060 Outstanding Requests:
17:20:00.147  * msgid 11,  origid 11, status InProgress
17:20:00.147    outstanding referrals 0, parent count 0
17:20:00.147  * msgid 9,  origid 9, status InProgress
17:20:00.147    outstanding referrals 0, parent count 0
17:20:00.147  * msgid 7,  origid 7, status InProgress
17:20:00.147    outstanding referrals 0, parent count 0
17:20:00.147  * msgid 5,  origid 5, status RequestCompleted
17:20:00.147    outstanding referrals 3, parent count 0
17:20:00.147   ld 0x10097060 request count 4 (abandoned 0)
17:20:00.147 ** ld 0x10097060 Response Queue:
17:20:00.147  * msgid 7,  type 100
17:20:00.147  * msgid 9,  type 100
17:20:00.147  * msgid 11,  type 100
17:20:00.147   ld 0x10097060 response count 3
17:20:00.147 ldap_chkResponseList ld 0x10097060 msgid 11 all 1
17:20:00.147 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.147 ldap_int_select
17:20:00.147 read1msg: ld 0x10097060 msgid 11 all 1
17:20:00.147 read1msg: ld 0x10097060 msgid 11 message type search-result
17:20:00.148 read1msg: ld 0x10097060 0 new referrals
17:20:00.148 read1msg:  mark request completed, ld 0x10097060 msgid 11
17:20:00.148 request done: ld 0x10097060 msgid 11
17:20:00.148 res_errno: 0, res_error: <>, res_matched: <>
17:20:00.148 ldap_free_request (origid 11, msgid 11)
17:20:00.148 adding response ld 0x10097060 msgid 11 type 101:
17:20:00.148 ldap_parse_result
17:20:00.148 ldap_get_values
17:20:00.148 ldap_msgfree
17:20:00.148 ldap_sasl_interactive_bind_s: server supports: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:20:00.148 ldap_int_sasl_bind: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:20:00.149 ldap_int_sasl_open: host=12.34.56.2
17:20:00.159 ldap_free_connection 1 0
17:20:00.159 ldap_free_connection: actually freed
17:20:00.159 ldap_err2string
17:20:00.159 Unable to chase referral "ldap://example.com/CN=Configuration,DC=example,DC=com"; (-2: Local error)
17:20:00.160 wait4msg continue ld 0x10097060 msgid 9 all 1
17:20:00.160 ** ld 0x10097060 Connections:
17:20:00.160 * host: DomainDnsZones.example.com  port: 0
17:20:00.160   refcnt: 2  status: Connected
17:20:00.160   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.160     queue is empty
17:20:00.160 
17:20:00.160 * host: ForestDnsZones.example.com  port: 0
17:20:00.160   refcnt: 2  status: Connected
17:20:00.160   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.160     queue is empty
17:20:00.160 
17:20:00.160 * host: one.example.com  port: 389  (default)
17:20:00.160   refcnt: 3  status: Connected
17:20:00.160   last used: Wed May 26 17:19:59 2010

17:20:00.160 
17:20:00.160 ** ld 0x10097060 Outstanding Requests:
17:20:00.160  * msgid 9,  origid 9, status InProgress
17:20:00.160    outstanding referrals 0, parent count 0
17:20:00.160  * msgid 7,  origid 7, status InProgress
17:20:00.160    outstanding referrals 0, parent count 0
17:20:00.161  * msgid 5,  origid 5, status RequestCompleted
17:20:00.161    outstanding referrals 2, parent count 0
17:20:00.161   ld 0x10097060 request count 3 (abandoned 0)
17:20:00.161 ** ld 0x10097060 Response Queue:
17:20:00.161  * msgid 5,  type 115
17:20:00.161  * msgid 7,  type 100
17:20:00.161  * msgid 9,  type 100
17:20:00.161   ld 0x10097060 response count 3
17:20:00.161 ldap_chkResponseList ld 0x10097060 msgid 9 all 1
17:20:00.161 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.161 ldap_int_select
17:20:00.161 read1msg: ld 0x10097060 msgid 9 all 1
17:20:00.161 read1msg: ld 0x10097060 msgid 9 message type search-result
17:20:00.161 read1msg: ld 0x10097060 0 new referrals
17:20:00.161 read1msg:  mark request completed, ld 0x10097060 msgid 9
17:20:00.161 request done: ld 0x10097060 msgid 9
17:20:00.161 res_errno: 0, res_error: <>, res_matched: <>
17:20:00.161 ldap_free_request (origid 9, msgid 9)
17:20:00.161 adding response ld 0x10097060 msgid 9 type 101:
17:20:00.161 ldap_parse_result
17:20:00.161 ldap_get_values
17:20:00.161 ldap_msgfree
17:20:00.162 ldap_sasl_interactive_bind_s: server supports: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:20:00.162 ldap_int_sasl_bind: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:20:00.162 ldap_int_sasl_open: host=12.34.56.2
17:20:00.173 ldap_free_connection 1 0
17:20:00.173 ldap_free_connection: actually freed
17:20:00.173 ldap_err2string
17:20:00.173 Unable to chase referral "ldap://DomainDnsZones.example.com/DC=DomainDnsZones,DC=example,DC=com"; (-2: Local error)
17:20:00.173 adding response ld 0x10097060 msgid 5 type 115:
17:20:00.173 wait4msg continue ld 0x10097060 msgid 7 all 1
17:20:00.173 ** ld 0x10097060 Connections:
17:20:00.174 * host: ForestDnsZones.example.com  port: 0
17:20:00.174   refcnt: 2  status: Connected
17:20:00.174   last used: Wed May 26 17:20:00 2010
  rebind in progress
17:20:00.174     queue is empty
17:20:00.174 
17:20:00.174 * host: one.example.com  port: 389  (default)
17:20:00.174   refcnt: 2  status: Connected
17:20:00.174   last used: Wed May 26 17:19:59 2010

17:20:00.174 
17:20:00.174 ** ld 0x10097060 Outstanding Requests:
17:20:00.174  * msgid 7,  origid 7, status InProgress
17:20:00.174    outstanding referrals 0, parent count 0
17:20:00.174  * msgid 5,  origid 5, status RequestCompleted
17:20:00.174    outstanding referrals 1, parent count 0
17:20:00.174   ld 0x10097060 request count 2 (abandoned 0)
17:20:00.174 ** ld 0x10097060 Response Queue:
17:20:00.174  * msgid 5,  type 115
17:20:00.174    chained responses:
17:20:00.174   * msgid 5,  type 115
17:20:00.174  * msgid 7,  type 100
17:20:00.174   ld 0x10097060 response count 2
17:20:00.174 ldap_chkResponseList ld 0x10097060 msgid 7 all 1
17:20:00.174 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.175 ldap_int_select
17:20:00.175 read1msg: ld 0x10097060 msgid 7 all 1
17:20:00.175 read1msg: ld 0x10097060 msgid 7 message type search-result
17:20:00.175 read1msg: ld 0x10097060 0 new referrals
17:20:00.175 read1msg:  mark request completed, ld 0x10097060 msgid 7
17:20:00.175 request done: ld 0x10097060 msgid 7
17:20:00.175 res_errno: 0, res_error: <>, res_matched: <>
17:20:00.175 ldap_free_request (origid 7, msgid 7)
17:20:00.175 adding response ld 0x10097060 msgid 7 type 101:
17:20:00.175 ldap_parse_result
17:20:00.175 ldap_get_values
17:20:00.175 ldap_msgfree
17:20:00.175 ldap_sasl_interactive_bind_s: server supports: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:20:00.175 ldap_int_sasl_bind: GSSAPI GSS-SPNEGO EXTERNAL DIGEST-MD5
17:20:00.176 ldap_int_sasl_open: host=12.34.56.2
17:20:00.207 ldap_free_connection 1 0
17:20:00.207 ldap_free_connection: actually freed
17:20:00.207 ldap_err2string
17:20:00.207 Unable to chase referral "ldap://ForestDnsZones.example.com/DC=ForestDnsZones,DC=example,DC=com"; (-2: Local error)
17:20:00.207 adding response ld 0x10097060 msgid 5 type 115:
17:20:00.207 wait4msg ld 0x10097060 9 s 773008 us to go
17:20:00.207 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:00.208 ** ld 0x10097060 Connections:
17:20:00.208 * host: one.example.com  port: 389  (default)
17:20:00.208   refcnt: 1  status: Connected
17:20:00.208   last used: Wed May 26 17:19:59 2010

17:20:00.208 
17:20:00.208 ** ld 0x10097060 Outstanding Requests:
17:20:00.208  * msgid 5,  origid 5, status RequestCompleted
17:20:00.208    outstanding referrals 0, parent count 0
17:20:00.208   ld 0x10097060 request count 1 (abandoned 0)
17:20:00.208 ** ld 0x10097060 Response Queue:
17:20:00.208  * msgid 5,  type 115
17:20:00.208    chained responses:
17:20:00.208   * msgid 5,  type 115
17:20:00.208   * msgid 5,  type 115
17:20:00.208   ld 0x10097060 response count 1
17:20:00.208 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:00.208 ldap_chkResponseList returns ld 0x10097060 msgid 5, type 0x73
17:20:00.208 ldap_parse_result
17:20:00.209 ldap_msgfree
17:20:00.209 ldap_result ld 0x10097060 msgid 5
17:20:00.209 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:00.209 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:00.209 ** ld 0x10097060 Connections:
17:20:00.209 * host: one.example.com  port: 389  (default)
17:20:00.209   refcnt: 1  status: Connected
17:20:00.209   last used: Wed May 26 17:19:59 2010

17:20:00.209 
17:20:00.209 ** ld 0x10097060 Outstanding Requests:
17:20:00.209  * msgid 5,  origid 5, status RequestCompleted
17:20:00.209    outstanding referrals 0, parent count 0
17:20:00.209   ld 0x10097060 request count 1 (abandoned 0)
17:20:00.209 ** ld 0x10097060 Response Queue:
17:20:00.209    Empty
17:20:00.209   ld 0x10097060 response count 0
17:20:00.209 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:00.209 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:00.210 ldap_int_select
17:20:10.221 ldap_result ld 0x10097060 msgid 5
17:20:10.221 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:10.221 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:10.221 ** ld 0x10097060 Connections:
17:20:10.221 * host: one.example.com  port: 389  (default)
17:20:10.221   refcnt: 1  status: Connected
17:20:10.221   last used: Wed May 26 17:19:59 2010

17:20:10.221 
17:20:10.221 ** ld 0x10097060 Outstanding Requests:
17:20:10.221  * msgid 5,  origid 5, status RequestCompleted
17:20:10.221    outstanding referrals 0, parent count 0
17:20:10.221   ld 0x10097060 request count 1 (abandoned 0)
17:20:10.221 ** ld 0x10097060 Response Queue:
17:20:10.221    Empty
17:20:10.221   ld 0x10097060 response count 0
17:20:10.221 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:10.221 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:10.221 ldap_int_select
17:20:20.381 ldap_result ld 0x10097060 msgid 5
17:20:20.381 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:20.381 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:20.381 ** ld 0x10097060 Connections:
17:20:20.381 * host: one.example.com  port: 389  (default)
17:20:20.381   refcnt: 1  status: Connected
17:20:20.381   last used: Wed May 26 17:19:59 2010

17:20:20.381 
17:20:20.381 ** ld 0x10097060 Outstanding Requests:
17:20:20.381  * msgid 5,  origid 5, status RequestCompleted
17:20:20.381    outstanding referrals 0, parent count 0
17:20:20.381   ld 0x10097060 request count 1 (abandoned 0)
17:20:20.381 ** ld 0x10097060 Response Queue:
17:20:20.381    Empty
17:20:20.381   ld 0x10097060 response count 0
17:20:20.381 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:20.381 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:20.382 ldap_int_select
17:20:30.393 ldap_result ld 0x10097060 msgid 5
17:20:30.393 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:30.393 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:30.393 ** ld 0x10097060 Connections:
17:20:30.393 * host: one.example.com  port: 389  (default)
17:20:30.393   refcnt: 1  status: Connected
17:20:30.393   last used: Wed May 26 17:19:59 2010

17:20:30.393 
17:20:30.393 ** ld 0x10097060 Outstanding Requests:
17:20:30.393  * msgid 5,  origid 5, status RequestCompleted
17:20:30.393    outstanding referrals 0, parent count 0
17:20:30.393   ld 0x10097060 request count 1 (abandoned 0)
17:20:30.393 ** ld 0x10097060 Response Queue:
17:20:30.393    Empty
17:20:30.393   ld 0x10097060 response count 0
17:20:30.393 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:30.393 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:30.393 ldap_int_select
17:20:40.518 ldap_result ld 0x10097060 msgid 5
17:20:40.518 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:40.518 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:40.518 ** ld 0x10097060 Connections:
17:20:40.518 * host: one.example.com  port: 389  (default)
17:20:40.518   refcnt: 1  status: Connected
17:20:40.518   last used: Wed May 26 17:19:59 2010

17:20:40.518 
17:20:40.518 ** ld 0x10097060 Outstanding Requests:
17:20:40.518  * msgid 5,  origid 5, status RequestCompleted
17:20:40.518    outstanding referrals 0, parent count 0
17:20:40.518   ld 0x10097060 request count 1 (abandoned 0)
17:20:40.518 ** ld 0x10097060 Response Queue:
17:20:40.519    Empty
17:20:40.519   ld 0x10097060 response count 0
17:20:40.519 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:40.519 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:40.519 ldap_int_select
17:20:50.530 ldap_result ld 0x10097060 msgid 5
17:20:50.530 wait4msg ld 0x10097060 msgid 5 (timeout 10000000 usec)
17:20:50.530 wait4msg continue ld 0x10097060 msgid 5 all 2
17:20:50.530 ** ld 0x10097060 Connections:
17:20:50.530 * host: one.example.com  port: 389  (default)
17:20:50.530   refcnt: 1  status: Connected
17:20:50.530   last used: Wed May 26 17:19:59 2010

17:20:50.530 
17:20:50.530 ** ld 0x10097060 Outstanding Requests:
17:20:50.530  * msgid 5,  origid 5, status RequestCompleted
17:20:50.530    outstanding referrals 0, parent count 0
17:20:50.530   ld 0x10097060 request count 1 (abandoned 0)
17:20:50.530 ** ld 0x10097060 Response Queue:
17:20:50.530    Empty
17:20:50.530   ld 0x10097060 response count 0
17:20:50.530 ldap_chkResponseList ld 0x10097060 msgid 5 all 2
17:20:50.530 ldap_chkResponseList returns ld 0x10097060 NULL
17:20:50.530 ldap_int_select