[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
ldap search bug
- To: openldap-technical@openldap.org
- Subject: ldap search bug
- From: Jeremiah Martell <inlovewithgod@gmail.com>
- Date: Thu, 3 Jun 2010 11:05:10 -0400
- Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:mime-version:received:received:date:message-id :subject:from:to:content-type; bh=/PSe+He3j4AwBBHODb3D2Eq7N/OwrW+zfT/SsXe5DBk=; b=ctkcy4N0wQZPIefcNWdzEb/XFKe04x5fq5FRcFmPRcq7oHzTofg2uhY+zg/m9sMPXE pR4C2n5uFVnbNdWcyL7tg9Va+Ba/p4kjty1p0os8pyttJDPeU1HYbuoyMx02ba4iOd7U v0URXna+82IUOhFf6ucxX8C3kxtZI4CN67nic=
- Domainkey-signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=mime-version:date:message-id:subject:from:to:content-type; b=tFA8U8nTH5boQ6BaIbmL+K3+K7hrQfiGFLAkkgeIgISOpIfXAxUgh/Fg8ew7GgABTE JNaDH2awshKBvZPK7owivJxerc0pTcNSWTV38kC/hp8PUhEFl3wMe4lp4yk4IvCViu4j pE+N541bFfyjmlXcslVDcpsoVduIHPHlvUE3o=
Just pinging the mailing list again.
I'm hoping someone has some advice or guidance on this.
Thanks,
- Jeremiah
---------- Forwarded message ----------
From:
Jeremiah Martell <inlovewithgod@gmail.com>
Date: Thu, May 27, 2010 at 3:42 PM
Subject: ldap search hangs forever
To:
openldap-technical@openldap.orgI'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.comServer: 12.34.56.99
Address 1: 12.34.56.99
dns1.example.com
Name:
one.example.comAddress 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.comName:
two.example.comAddress 1: 12.34.56.2
/ nslookup
example.com
Server: 12.34.56.99
Address 1: 12.34.56.99
dns1.example.comName:
example.comAddress 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.comName: 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.comName: 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