Re: Troubleshoot ldap-ISR configuration

endpoint · ‎10-01-2012

Hello

i am testing ScanSafe features and was setup a ISR (C2900 Software (C2900-UNIVERSALK9-M), Version 15.2(2)T) to use ldap authentication to AD following http://www.cisco.com/en/US/docs/security/web_security/ISR_SS/ISR_ScanSafe_SolutionGuide.pdf.

Unfortunatelly when user try to access the Internet any credentials i typed in do not work.

Below is debug ldap all output from the ISR:

Oct 1 20:28:43.160: LDAP: Received timer event

Oct 1 20:28:43.160: LDAP: Connection timeout occured. Retrying

Oct 1 20:28:43.160: LDAP: Opening ldap connection ( 10.1.1.1, 3268 )ldap_open

ldap_init libldap 4.5 18-FEB-2000

open_ldap_connection

ldap_connect_to_host: 10.1.1.1:3268

Oct 1 20:28:43.160: LDAP: socket 1 - connecting to 10.1.1.1 (3268)

Oct 1 20:28:43.160: LDAP: socket 1 - connection in progress

Oct 1 20:28:43.160: LDAP: socket 1 - local address 10.3.206.33 (54052)

Oct 1 20:28:43.160: LDAP: Connection on socket 1

Oct 1 20:28:43.160: LDAP: Connection to LDAP server (CDC02.domain.net, 10.19.146.14) attempted

Oct 1 20:28:43.160: LDAP: Connection state: DOWN => CONNECTING

Oct 1 20:28:43.176: LDAP: Received socket event

Oct 1 20:28:43.176: LDAP: Checking the conn status

Oct 1 20:28:43.176: LDAP: Socket read event socket=1

Oct 1 20:28:43.176: LDAP: Found socket ctx

Oct 1 20:28:43.176: LDAP: ldap tcp transport closing on socket 1

Oct 1 20:28:43.176: LDAP: Protocol received transport down notification

Oct 1 20:28:43.176: LDAP: Server-CDC02.domain.net connection going down !!!

Oct 1 20:28:43.176: LDAP: Clearing all ldap transactions

Oct 1 20:28:43.176: LDAP: Connection state: CONNECTING => DOWN

Oct 1 20:28:43.176: LDAP: Connection state: DOWN => DOWN

Oct 1 20:28:43.176: LDAP: Connection timer started for 30 seconds for CDC02.domain.netldap_unbind

ldap_free_connection lc=0x2CAFBEF0

ldap_free_connection: actually freed

Oct 1 20:28:43.180: LDAP: socket 1 - CONN_WAIT->CONN_CLOSE

Oct 1 20:28:43.180: LDAP: Received socket event

Oct 1 20:29:13.176: LDAP: Received timer event

Oct 1 20:29:13.176: LDAP: Connection timeout occured. Retrying

Oct 1 20:29:13.176: LDAP: Opening ldap connection ( 10.1.1.1, 3268 )ldap_open

ldap_init libldap 4.5 18-FEB-2000

open_ldap_connection

ldap_connect_to_host: 10.1.1.1:3268

Oct 1 20:29:13.176: LDAP: socket 1 - connecting to 10.19.146.14 (3268)

Oct 1 20:29:13.176: LDAP: socket 1 - connection in progress

Oct 1 20:29:13.176: LDAP: socket 1 - local address 10.3.206.33 (48488)

Oct 1 20:29:13.176: LDAP: Connection on socket 1

Oct 1 20:29:13.176: LDAP: Connection to LDAP server (CDC02.domain.net, 10.19.146.14) attempted

Oct 1 20:29:13.176: LDAP: Connection state: DOWN => CONNECTING

Oct 1 20:29:13.192: LDAP: Received socket event

Oct 1 20:29:13.192: LDAP: Checking the conn status

Oct 1 20:29:13.192: LDAP: Socket read event socket=1

Oct 1 20:29:13.192: LDAP: Found socket ctx

Oct 1 20:29:13.192: LDAP: ldap tcp transport closing on socket 1

Oct 1 20:29:13.192: LDAP: Protocol received transport down notification

Oct 1 20:29:13.192: LDAP: Server-CDC02.domain.net connection going down !!!

Oct 1 20:29:13.192: LDAP: Clearing all ldap transactions

Oct 1 20:29:13.192: LDAP: Connection state: CONNECTING => DOWN

Oct 1 20:29:13.192: LDAP: Connection state: DOWN => DOWN

Oct 1 20:29:13.192: LDAP: Connection timer started for 30 seconds for CDC02.domain.netldap_unbind

ldap_free_connection lc=0x2CAFBEF0

ldap_free_connection: actually freed

from the router i do have connectivity to AD controller configured in ISR config (ping works) and there is no firewall that will prevent ldap traffic.

Any good troubleshooting ideas that will help getting this setup running?

Ken Stieers · ‎10-01-2012

I'd have to see your config, but here are the things that come to mind first:

Is the user and password you put in the ISR for the bind statement correct?

Are you sure that the firewall on the Windows box off? Or an AV app with a network monitoring piece?

Is the AD box you're connecting to actually configed as a Global Catalog?

Does the AD box require SSL?

Joe Lourenco · ‎08-23-2013

I have a similar problem as well with Scansafe, on a 3945 ISR with IOS 15 (C3900-UNIVERSALK9-M). LDAP binding to the LDAP Server when authenticating any domain user, except for the default Scansafe Bind Root-DN user, is failing. Which I believe could also be your problem, unless, from the logs you presented, it appears as connection to the LDAP Server itself is failing; post your LDAP configuration.

Try running:

# sh ldap server all (to see if any LDAP server exists)

Try testing the Scansafe AAA LDAP server via:

# test aaa group new-code

In my case, testing any user's sAMaccount name, is failing, and it defaults to the default usergroup.

My config is exactly as the link you posted and I am using NTLM PASSIVE AUTHENTICATION.

In that PDF, there is this paragraph that describes exactly what is happening to my Scansafe.

Configuring a Default User Group

You can configure a default user group to assign to each client when the ISR cannot determine the

credentials for a user. Define a default user group using the following CLI command:

[no] user-group default

The ISR uses the default user group name here to iden

tify all clients connected to a specific interface on

the ISR when it cannot determine the user’s credenti

als. You might want to define a default user group

so that all traffic redirected to

the ScanSafe proxy servers are assigned a user group so particular

ScanSafe policies can be applied a

ppropriately. For example, you might want to create a default user

group for guest users on the wireless network.

Only one user group can be defined per interface.

Here is what my logs show regarding LDAP BINDING OPERATION, from # debug ldap all:

-- Testing with jltestuser (this is just any random user, as all users are failing anyway)

barra-gate#

051646: Aug 23 23:10:34.983 BRST: LDAP: LDAP: Queuing AAA request 0 for processing

051647: Aug 23 23:10:34.983 BRST: LDAP: Received queue event, new AAA request

051648: Aug 23 23:10:34.983 BRST: LDAP: LDAP authentication request

051649: Aug 23 23:10:34.983 BRST: LDAP: Invalid hash index 512, nothing to remove

051650: Aug 23 23:10:34.983 BRST: LDAP: New LDAP request

051651: Aug 23 23:10:34.983 BRST: LDAP: Attempting first next available LDAP server

051652: Aug 23 23:10:34.983 BRST: LDAP: Got next LDAP server :

051653: Aug 23 23:10:34.983 BRST: LDAP: First Task: Send bind req

051654: Aug 23 23:10:34.983 BRST: LDAP: Authentication policy: bind-first

051655: Aug 23 23:10:34.983 BRST: LDAP: Bind: User-DN=cn=jltestuser,CN=Users,DC=,DC=,DC=com ldap_req_encode

Doing socket write

051656: Aug 23 23:10:34.983 BRST: LDAP: LDAP bind request sent successfully (reqid=92)

051657: Aug 23 23:10:34.983 BRST: LDAP: Sent transit request to server

051658: Aug 23 23:10:34.983 BRST: LDAP: LDAP request successfully processed

051659: Aug 23 23:10:35.539 BRST: LDAP: Received socket event

051660: Aug 23 23:10:35.539 BRST: LDAP: Process socket event for socket = 0

051661: Aug 23 23:10:35.539 BRST: LDAP: Conn Status = 4

051662: Aug 23 23:10:35.539 BRST: LDAP: Non-TLS read event on socket 0

051663: Aug 23 23:10:35.539 BRST: LDAP: Found socket ctx

051664: Aug 23 23:10:35.539 BRST: LDAP: Receive event: read=1, errno=11 (Resource temporarily unavailable)

051665: Aug 23 23:10:35.539 BRST: LDAP: Passing the client ctx=1855243Cldap_result

wait4msg (timeout 0 sec, 1 usec)

ldap_select_fd_wait (select)

ldap_read_activity lc 0x1AADABD8

Doing socket read

LDAP-TCP:Bytes read = 110

ldap_match_request succeeded for msgid 7 h 0

changing lr 0x11A14BFC to COMPLETE as no continuations

removing request 0x11A14BFC from list as lm 0x1AAB8494 all 0

ldap_msgfree

051666: Aug 23 23:10:35.539 BRST: LDAP: LDAP Messages to be processed: 1

051667: Aug 23 23:10:35.539 BRST: LDAP: LDAP Message type: 97

051668: Aug 23 23:10:35.539 BRST: LDAP: Got ldap transaction context from reqid 92ldap_parse_result

051669: Aug 23 23:10:35.539 BRST: LDAP: resultCode: 49 (Invalid credentials)

051670: Aug 23 23:10:35.539 BRST: LDAP: Received Bind Responseldap_parse_result

ldap_err2string

051671: Aug 23 23:10:35.539 BRST: LDAP: Ldap Result Msg: FAILED:Invalid credentials, Result code =49

051672: Aug 23 23:10:35.539 BRST: LDAP: LDAP Bind operation result : failed <<<<<<<<<<-----------------------LOOK!!!!!

051673: Aug 23 23:10:35.539 BRST: LDAP: Connection 0 already exist for reuseldap_msgfree

051674: Aug 23 23:10:35.539 BRST: LDAP: Closing transaction and reporting error to AAA

051675: Aug 23 23:10:35.539 BRST: LDAP: Transaction context removed from list [ldap reqid=92]

051676: Aug 23 23:10:35.539 BRST: LDAP: Notifying AAA: REQUEST FAILED

051677: Aug 23 23:10:35.539 BRST: LDAP: Received socket event

--- Testing with the scansafe assigned user that binds to the Bind DN. This is the only user that succeeds authentication!!!!

barra-gate#

051684: Aug 23 23:13:57.664 BRST: LDAP: LDAP: Queuing AAA request 0 for processing

051685: Aug 23 23:13:57.664 BRST: LDAP: Received queue event, new AAA request

051686: Aug 23 23:13:57.664 BRST: LDAP: LDAP authentication request

051687: Aug 23 23:13:57.664 BRST: LDAP: Invalid hash index 512, nothing to remove

051688: Aug 23 23:13:57.664 BRST: LDAP: New LDAP request

051689: Aug 23 23:13:57.664 BRST: LDAP: Attempting first next available LDAP server

051690: Aug 23 23:13:57.664 BRST: LDAP: Got next LDAP server :

051691: Aug 23 23:13:57.664 BRST: LDAP: First Task: Send bind req

051692: Aug 23 23:13:57.664 BRST: LDAP: Authentication policy: bind-first

051693: Aug 23 23:13:57.664 BRST: LDAP: Bind: User-DN=cn=,CN=Users,DC=,,DC=comldap_req_encode

Doing socket write

051694: Aug 23 23:13:57.664 BRST: LDAP: LDAP bind request sent successfully (reqid=93)

051695: Aug 23 23:13:57.664 BRST: LDAP: Sent transit request to server

051696: Aug 23 23:13:57.664 BRST: LDAP: LDAP request successfully processed

051697: Aug 23 23:13:58.164 BRST: LDAP: Received socket event

051698: Aug 23 23:13:58.164 BRST: LDAP: Process socket event for socket = 0

051699: Aug 23 23:13:58.164 BRST: LDAP: Conn Status = 4

051700: Aug 23 23:13:58.164 BRST: LDAP: Non-TLS read event on socket 0

051701: Aug 23 23:13:58.164 BRST: LDAP: Found socket ctx

051702: Aug 23 23:13:58.164 BRST: LDAP: Receive event: read=1, errno=11 (Resource temporarily unavailable)

051703: Aug 23 23:13:58.164 BRST: LDAP: Passing the client ctx=1855243Cldap_result

wait4msg (timeout 0 sec, 1 usec)

ldap_select_fd_wait (select)

ldap_read_activity lc 0x1AADABD8

Doing socket read

LDAP-TCP:Bytes read = 22

ldap_match_request succeeded for msgid 8 h 0

changing lr 0x11A14BFC to COMPLETE as no continuations

removing request 0x11A14BFC from list as lm 0x1AAB9D14 all 0

ldap_msgfree

051704: Aug 23 23:13:58.164 BRST: LDAP: LDAP Messages to be processed: 1

051705: Aug 23 23:13:58.164 BRST: LDAP: LDAP Message type: 97

051706: Aug 23 23:13:58.164 BRST: LDAP: Got ldap transaction context from reqid 93ldap_parse_result

051707: Aug 23 23:13:58.164 BRST: LDAP: resultCode: 0 (Success)

051708: Aug 23 23:13:58.168 BRST: LDAP: Received Bind Responseldap_parse_result

051709: Aug 23 23:13:58.168 BRST: LDAP: Ldap Result Msg: SUCCESS, Result code =0

051710: Aug 23 23:13:58.168 BRST: LDAP: LDAP Bind successful for DN:cn=CN=Users,DC=,DC=,DC=com

Now, what does this problem affect? I cannot enforce the application of filters from the Scansafe site to specific user groups. Users can use the internet under the default usergroup. Everyone defaults to the default filter. I have a filter established for say Purchasing, allowing them extra leeway on what they can view, but the members of that group cannot authenticate, and thus their filter is not applied.

Application of filters is essential to Scansafe, without them, it defeats the purpose.

I appreciate all the help I can get on this.