[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
Double referral not handled properly (ITS#3361)
Full_Name: Ian Puleston
Version: 2.2.17
OS: vxWorks
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (64.220.173.243)
I have a vxWorks port of OpenLDAP 2.2.17 client connecting to 3 LDAP servers
using referrals. The client talks directly to server A. Server A refers
unmatched requests to server B, and server B refers unmatched requests to server
C. If I initiate a search for objects located on server A or server B it works
fine, however a search for objects located on server C (i.e. requiring two
referrals) has problems. It actually completes successfully, but goes through
additional unnecessary steps to do it. The sequence of events is:
1. The client successfully binds to server A.
2. The client sends the search request to server A. Server A returns a referral
to server B.
3. The client successfully binds to server B.
4. The client sends the search request to server B. Server B returns a referral
to server C.
5. The client successfully binds to server C.
6. The client then sends another bind to server C which is also successful.
7. The client then unbinds from server C.
8. The client then sends the search request to server B. Server B returns a
referral to server C.
9. The client successfully binds to server C.
10. The client then sends the search request to server C. Server C returns the
search results.
11. The client then unbinds from server C.
Steps 6 thru 9 are "surplus to requirements".
The following is an Ethereal trace of the LDAP packets:
Time Source Destination Info
0.028937 Client Server_A MsgId=1 Bind Request
0.030059 Server_A Client MsgId=1 Bind Result
0.141292 Client Server_A MsgId=2 Search Request, Base DN=dc=sub3,dc=
...
0.142351 Server_A Client MsgId=2 Search Result, Referral
0.362101 Client Server_B MsgId=4 Bind Request
0.364039 Server_B Client MsgId=4 Bind Result, Referral
0.597262 Client Server_C MsgId=6 Bind Request
0.658788 Server_C Client MsgId=6 Bind Result
0.739044 Client Server_C MsgId=5 Bind Request
0.802516 Server_C Client MsgId=5 Bind Result
0.874740 Client Server_C MsgId=7 Unbind Request
0.884954 Client Server_B MsgId=3 Search Request, Base DN=dc=sub3,dc=
...
0.886646 Server_B Client MsgId=3 Search Result, Referral
1.112813 Client Server_C MsgId=9 Bind Request
1.175319 Server_C Client MsgId=9 Bind Result
1.250461 Client Server_C MsgId=8 Search Request, Base DN=dc=sub3,dc=
...
1.417046 Server_C Client MsgId=8 Search Entry
1.435281 Server_C Client MsgId=8 Search Result
1.549826 Client Server_C MsgId=10 Unbind Request
And the following is a debug trace from the client through the process (note
that 10.0.77.1 is server A, 10.0.202.146 is server B and 10.0.202.51 is server
c):
LDAP: 06 15:33:52 ldapBind: server_a.sv.us.sonicwall.com
ldap_create
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP server_a.sv.us.sonicwall.com:389
LDAP_gethostbyname resolved 'server_a.sv.us.sonicwall.com' to 014d000a
ldap_new_socket: 44
ldap_prepare_socket: 44
ldap_connect_to_host: Trying 10.0.77.1:389
ldap_connect_timeout: fd: 44 tm: 10 async: 0
ldap_ndelay_on: 44
ldap_is_sock_ready: 44
ldap_ndelay_off: 44
ldap_open_defconn: successful
ldap_send_server_request
ldap_result msgid 1
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 1
wait4msg continue, msgid 1, all 1
** Connections:
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 1, origid 1, status InProgress
outstanding referrals 0, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=1, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 1, all 1
ldap_read: message type bind msgid 1, original id 1
new result: res_errno: 0, res_error: <>, res_matched: <>
read1msg: 0 new referrals
read1msg: mark request completed, id = 1
request 1 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ldap_msgfree
LDAP: 06 15:33:52 ldapBind: success
filter: (cn=Andy Capp)
requesting: ALL
ldap_search_ext
put_filter: "(cn=Andy Capp)"
put_filter: simple
put_simple_filter: "cn=Andy Capp"
ldap_send_initial_request
ldap_send_server_request
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 2, origid 2, status InProgress
outstanding referrals 0, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ldap_read: message type search-result msgid 2, original id 2
ldap_chase_v3referrals
ldap_url_parse_ext(ldap://server_b.sv.us.sonicwall.com/dc=sub3,dc=tstDomain,dc=com??sub)
re_encode_request: new msgid 3, new dn <dc=sub3,dc=tstDomain,dc=com>
re_encode_request new request is:
ber_dump: buf=0x0695bedc ptr=0x0695bf22 end=0x0695ceb8 len=70
0000: 70 70 30 00 70 70 30 00 ee ee ee ee ee ee ee ee pp0.pp0.........
0010: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0020: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0030: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0040: ee ee ee ee ee ee ......
ldap_chase_v3referral: msgid 2, url
"ldap://server_b.sv.us.sonicwall.com/dc=sub3,dc=tstDomain,dc=com??sub";
ldap_send_server_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP server_b.sv.us.sonicwall.com:389
LDAP_gethostbyname resolved 'server_b.sv.us.sonicwall.com' to 92ca000a
ldap_new_socket: 45
ldap_prepare_socket: 45
ldap_connect_to_host: Trying 10.0.202.146:389
ldap_connect_timeout: fd: 45 tm: 10 async: 0
ldap_ndelay_on: 45
ldap_is_sock_ready: 45
ldap_ndelay_off: 45
Call application rebind_proc
LDAP: 06 15:33:52 ldapReBind:
ldap://server_b.sv.us.sonicwall.com/dc=sub3,dc=tstDomain,dc=com??sub
ldap_url_parse_ext(ldap://server_b.sv.us.sonicwall.com/dc=sub3,dc=tstDomain,dc=com??sub)
LDAP: 06 15:33:52 ldapReBind binding as
cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ldap_result msgid 4
ldap_chkResponseList for msgid=4, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 4
wait4msg continue, msgid 4, all 1
** Connections:
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
rebind in progress
queue is empty
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 4, origid 4, status InProgress
outstanding referrals 0, parent count 0
* msgid 2, origid 2, status InProgress
outstanding referrals 1, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=4, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 4, all 1
ldap_read: message type bind msgid 4, original id 4
ldap_chase_v3referrals
ldap_url_parse_ext(ldap://10.0.202.51/cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com)
re_encode_request: new msgid 5, new dn
<cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com>
re_encode_request new request is:
ber_dump: buf=0x06959f14 ptr=0x06959f5d end=0x0695aef0 len=73
0000: 63 72 65 74 63 72 65 74 ee ee ee ee ee ee ee ee cretcret........
0010: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0020: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0030: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0040: ee ee ee ee ee ee ee ee ee .........
ldap_chase_v3referral: msgid 4, url
"ldap://10.0.202.51/cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com";
ldap_send_server_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP 10.0.202.51:389
ldap_new_socket: 46
ldap_prepare_socket: 46
ldap_connect_to_host: Trying 10.0.202.51:389
ldap_connect_timeout: fd: 46 tm: 10 async: 0
ldap_ndelay_on: 46
ldap_is_sock_ready: 46
ldap_ndelay_off: 46
Call application rebind_proc
LDAP: 06 15:33:52 ldapReBind:
ldap://10.0.202.51/cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com
ldap_url_parse_ext(ldap://10.0.202.51/cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com)
LDAP: 06 15:33:52 ldapReBind binding as
cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ldap_result msgid 6
ldap_chkResponseList for msgid=6, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 6
wait4msg continue, msgid 6, all 1
** Connections:
* host: 10.0.202.51 port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
rebind in progress
queue is empty
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
rebind in progress
queue is empty
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 6, origid 6, status InProgress
outstanding referrals 0, parent count 0
* msgid 4, origid 4, status InProgress
outstanding referrals 1, parent count 0
* msgid 2, origid 2, status InProgress
outstanding referrals 1, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=6, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 6, all 1
ldap_read: message type bind msgid 6, original id 6
new result: res_errno: 0, res_error: <>, res_matched: <>
read1msg: 0 new referrals
read1msg: mark request completed, id = 6
request 6 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 6, msgid 6)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ldap_msgfree
LDAP: 06 15:33:53 ldapReBind: success
read1msg: referral chased, mark request completed, id = 4
read1msg: 1 new referrals
wait4msg continue, msgid 4, all 1
** Connections:
* host: 10.0.202.51 port: 0
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:52 2004
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
rebind in progress
queue is empty
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 5, origid 4, status InProgress
outstanding referrals 0, parent count 1
* msgid 4, origid 4, status Request Completed
outstanding referrals 1, parent count 0
* msgid 2, origid 2, status InProgress
outstanding referrals 1, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=4, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 4, all 1
ldap_read: message type bind msgid 5, original id 4
new result: res_errno: 0, res_error: <>, res_matched: <>
read1msg: 0 new referrals
read1msg: mark request completed, id = 5
merged parent (id 4) error info: result errno 0, error <>, matched <>
request 4 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 4, msgid 4)
ldap_free_request (origid 4, msgid 5)
ldap_free_connection
ldap_send_unbind
ldap_free_connection: actually freed
ldap_parse_result
ldap_msgfree
LDAP: 06 15:33:53 ldapReBind: success
read1msg: referral chased, mark request completed, id = 2
read1msg: 0 new referrals
read1msg: mark request completed, id = 2
ldap_free_connection
ldap_free_connection: refcnt 1
wait4msg continue, msgid -1, all 0
** Connections:
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 3, origid 2, status InProgress
outstanding referrals 0, parent count 1
* msgid 2, origid 2, status Request Completed
outstanding referrals 1, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ldap_read: message type search-result msgid 3, original id 2
ldap_chase_v3referrals
ldap_url_parse_ext(ldap://10.0.202.51/dc=sub3,dc=tstDomain,dc=com??sub)
re_encode_request: new msgid 8, new dn <dc=sub3,dc=tstDomain,dc=com>
re_encode_request new request is:
ber_dump: buf=0x0695aef8 ptr=0x0695af3e end=0x0695bed4 len=70
0000: 70 70 30 00 70 70 30 00 72 65 74 ee ee ee ee ee pp0.pp0.ret.....
0010: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0020: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0030: ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ee ................
0040: ee ee ee ee ee ee ......
ldap_chase_v3referral: msgid 3, url
"ldap://10.0.202.51/dc=sub3,dc=tstDomain,dc=com??sub";
ldap_send_server_request
ldap_new_connection
ldap_int_open_connection
ldap_connect_to_host: TCP 10.0.202.51:389
ldap_new_socket: 46
ldap_prepare_socket: 46
ldap_connect_to_host: Trying 10.0.202.51:389
ldap_connect_timeout: fd: 46 tm: 10 async: 0
ldap_ndelay_on: 46
ldap_is_sock_ready: 46
ldap_ndelay_off: 46
Call application rebind_proc
LDAP: 06 15:33:53 ldapReBind:
ldap://10.0.202.51/dc=sub3,dc=tstDomain,dc=com??sub
ldap_url_parse_ext(ldap://10.0.202.51/dc=sub3,dc=tstDomain,dc=com??sub)
LDAP: 06 15:33:53 ldapReBind binding as
cn=administrator,ou=users,dc=sub3,dc=tstDomain,dc=com
ldap_bind_s
ldap_simple_bind_s
ldap_sasl_bind_s
ldap_sasl_bind
ldap_send_initial_request
ldap_send_server_request
ldap_result msgid 9
ldap_chkResponseList for msgid=9, all=1
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid 9
wait4msg continue, msgid 9, all 1
** Connections:
* host: 10.0.202.51 port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:53 2004
rebind in progress
queue is empty
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 2 status: Connected
last used: WED OCT 06 22:33:52 2004
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 9, origid 9, status InProgress
outstanding referrals 0, parent count 0
* msgid 3, origid 2, status InProgress
outstanding referrals 0, parent count 1
* msgid 2, origid 2, status Request Completed
outstanding referrals 2, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=9, all=1
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid 9, all 1
ldap_read: message type bind msgid 9, original id 9
new result: res_errno: 0, res_error: <>, res_matched: <>
read1msg: 0 new referrals
read1msg: mark request completed, id = 9
request 9 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 9, msgid 9)
ldap_free_connection
ldap_free_connection: refcnt 1
ldap_parse_result
ldap_msgfree
LDAP: 06 15:33:53 ldapReBind: success
read1msg: referral chased, mark request completed, id = 3
read1msg: 0 new referrals
read1msg: mark request completed, id = 3
merged parent (id 2) error info: result errno 0, error <>, matched <>
ldap_free_connection
ldap_free_connection: refcnt 1
wait4msg continue, msgid -1, all 0
** Connections:
* host: 10.0.202.51 port: 0
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:53 2004
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:53 2004
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 8, origid 2, status InProgress
outstanding referrals 0, parent count 1
* msgid 3, origid 2, status Request Completed
outstanding referrals 0, parent count 1
* msgid 2, origid 2, status Request Completed
outstanding referrals 1, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ldap_read: message type search-entry msgid 8, original id 2
ldap_get_dn_ber
dn: cn=Andy Capp,ou=users,dc=sub3,dc=tstDomain,dc=com
ldap_get_attribute_ber
objectClass: inetOrgPerson
ldap_get_attribute_ber
cn: Andy Capp
cn: Andy
ldap_get_attribute_ber
sn: Capp
ldap_get_attribute_ber
uid: acapp
ldap_get_attribute_ber
userPassword:: MTIzNA==
ldap_get_attribute_ber
# ----------
ldap_msgfree
ldap_result msgid -1
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
wait4msg (infinite timeout), msgid -1
wait4msg continue, msgid -1, all 0
** Connections:
* host: 10.0.202.51 port: 0
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:53 2004
* host: server_b.sv.us.sonicwall.com port: 0
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:53 2004
* host: server_a.sv.us.sonicwall.com port: 389 (default)
refcnt: 1 status: Connected
last used: WED OCT 06 22:33:52 2004
** Outstanding Requests:
* msgid 8, origid 2, status InProgress
outstanding referrals 0, parent count 1
* msgid 3, origid 2, status Request Completed
outstanding referrals 0, parent count 1
* msgid 2, origid 2, status Request Completed
outstanding referrals 1, parent count 0
** Response Queue:
Empty
ldap_chkResponseList for msgid=-1, all=0
ldap_chkResponseList returns NULL
ldap_int_select
read1msg: msgid -1, all 0
ldap_read: message type search-result msgid 8, original id 2
new result: res_errno: 0, res_error: <>, res_matched: <>
read1msg: 0 new referrals
read1msg: mark request completed, id = 8
merged parent (id 2) error info: result errno 0, error <>, matched <>
request 2 done
res_errno: 0, res_error: <>, res_matched: <>
ldap_free_request (origid 2, msgid 2)
ldap_free_request (origid 2, msgid 8)
ldap_free_request (origid 2, msgid 3)
ldap_free_connection
ldap_send_unbind
ldap_free_connection: actually freed
ldap_parse_result
ldap_msgfree
Search complete