cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
916
Views
0
Helpful
2
Replies

IOS LDAP connection Time outed

Paul Heilmeier
Level 1
Level 1

Hi Guys,

i configured ldap, for authentication, on a Cisco 1921 with the c1900-universalk9-mz.SPA.151-4.M4.bin Image.

I configured an LDAP connection, and it works fine. except after few minutes, if no one auth, the ldap connection is lost,and it goes first up, if somebody tries to connect, but it takes ~30 sec the reconnection..

This is a littlebit unhappy, for the users, cause they think, he used wrong credentials...

Any Ideas, how to keep the ldap connection stable?

Config:

aaa group server ldap LDAP-GROUP

server backupad

!

aaa authentication login AUTH group ldap group LDAP-GROUP

!

ldap attribute-map ldap-username-map

map type sAMAccountName username

!

ldap server backupad

ipv4 192.168.2.10

attribute map ldap-username-map

timeout retransmit 5

bind authenticate root-dn CN=VPNUser01,OU=Service Accounts,DC=******,DC=com password

base-dn OU=Users,OU=****,DC=*****,DC=com

search-filter user-object-type User)(ObjectCategory=Person)(msNPAllowDialin=TRUE

LOG

Feb 23 03:39:14.808: AAA/BIND(00000205): Bind i/f

Feb 23 03:39:14.808: AAA/AUTHEN/LOGIN (00000205): Pick method list 'AUTH'

Feb 23 03:39:14.808: LDAP: LDAP: Queuing AAA request 517 for processing

Feb 23 03:39:14.808: LDAP: Received queue event, new AAA request

Feb 23 03:39:14.808: LDAP: LDAP authentication request

Feb 23 03:39:14.812: LDAP: Attempting first  next available LDAP server

Feb 23 03:39:14.812: LDAP: Got next LDAP server :backupad

Feb 23 03:39:14.812: LDAP: First Task: Send search req

Feb 23 03:39:14.812: LDAP: Dynamic map configured

Feb 23 03:39:14.812: LDAP: Dynamic map found for aaa type=username

Feb 23 03:39:14.812: LDAP: Ldap Search Req sent

                    ld          729131732

                    base dn     OU=Users,OU=Munich,DC=*****,DC=com

                    scope       2

                    filter      (&(objectclass=User)(ObjectCategory=Person)(msNPAllowDialin=TRUE)(sAMAccountName=paul))ldap_req_encode

put_filter "(&(objectclass=User)(ObjectCategory=Person)(msNPAllowDialin=TRUE)(sAMAccountName=paul))"

put_filter: AND

put_filter_list "(objectclass=User)(ObjectCategory=Person)(msNPAllowDialin=TRUE)(sAMAccountName=paul)"

put_filter "(objectclass=User)"

put_filter: simple

put_filter "(ObjectCategory=Person)"

put_filter: simple

put_filter "(msNPAllowDialin=TRUE)"

put_filter: simple

put_filter "(sAMAccountName=paul)"

put_filter: simple

Doing socket writeldap_msgfree

ldap_msgfree

ldap_conn_failed lc=0x2B611254

ldap_free_connection lc=0x2B611254

ldap_free_connection: refcnt 3

ldap_perror

ldap_search: Can't contact LDAP server

Feb 23 03:39:14.812:

Feb 23 03:39:14.812: LDAP: Failed to send search request on LDAP server

Feb 23 03:39:14.812: LDAP: Authen send failed.Clearing connection

Feb 23 03:39:14.812: LDAP: Trying for next ldap server in group

Feb 23 03:39:14.812: LDAP: No servers left in LDAP server-group. Perform method failover

Feb 23 03:39:14.812: LDAP: Failed to send request. No more LDAP servers left.

Feb 23 03:39:14.812: LDAP: Performing method failover

Feb 23 03:39:14.812: LDAP: LDAP: Queuing AAA request 517 for processing

Feb 23 03:39:14.812: LDAP: LDAP authentication request

Feb 23 03:39:14.812: LDAP: Attempting first  next available LDAP server

Feb 23 03:39:14.812: LDAP: Got next LDAP server :backupad

Feb 23 03:39:14.812: LDAP: First Task: Send search req

Feb 23 03:39:14.812: LDAP: Dynamic map configured

Feb 23 03:39:14.812: LDAP: Dynamic map found for aaa type=username

Feb 23 03:39:14.812: LDAP: Ldap Search Req sent

                    ld          729131732

                    base dn     OU=Users,OU=Munich,DC=*****,DC=com

                    scope       2

                    filter      (&(objectclass=User)(ObjectCategory=Person)(msNPAllowDialin=TRUE)(sAMAccountName=paul))ldap_req_encode

put_filter "(&(objectclass=User)(ObjectCategory=Person)(msNPAllowDialin=TRUE)(sAMAccountName=paul))"

put_filter: AND

put_filter_list "(objectclass=User)(ObjectCategory=Person)(msNPAllowDialin=TRUE)(sAMAccountName=paul)"

put_filter "(objectclass=User)"

put_filter: simple

put_filter "(ObjectCategory=Person)"

put_filter: simple

put_filter "(msNPAllowDialin=TRUE)"

put_filter: simple

put_filter "(sAMAccountName=paul)"

put_filter: simple

Doing socket writeldap_msgfree

ldap_msgfree

ldap_conn_failed lc=0x2B611254

ldap_free_connection lc=0x2B611254

ldap_free_connection: refcnt 2

ldap_perror

ldap_search: Can't contact LDAP server

Feb 23 03:39:14.812:

Feb 23 03:39:14.812: LDAP: Failed to send search request on LDAP server

Feb 23 03:39:14.812: LDAP: Authen send failed.Clearing connection

Feb 23 03:39:14.812: LDAP: Trying for next ldap server in group

Feb 23 03:39:14.812: LDAP: No servers left in LDAP server-group. Perform method failover

Feb 23 03:39:14.812: LDAP: Failed to send request. No more LDAP servers left.

Feb 23 03:39:14.812: LDAP: Performing method failover

Feb 23 03:39:14.812: LDAP: Received message event

Feb 23 03:39:14.812: LDAP: ldap tcp transport closing on socket 0

Feb 23 03:39:14.812: LDAP: Protocol received transport down notification

Feb 23 03:39:14.812: LDAP: Server-backupad connection going down !!!

Feb 23 03:39:14.812: LDAP: Clearing all ldap transactions

Feb 23 03:39:14.812: LDAP: Connection state: UP => DOWN

Feb 23 03:39:14.812: LDAP: Connection state: DOWN => DOWN

Feb 23 03:39:14.812: LDAP: Connection timer started for 30 seconds for backupadldap_unbind

ldap_free_connection lc=0x2B611254

ldap_send_unbind sock=0 host=192.168.2.10 port=389

Doing socket writeldap_free_connection: actually freed

Feb 23 03:39:14.812: LDAP: socket 0 - CONN_UP->CONN_CLOSE

Feb 23 03:39:14.812: LDAP: ldap tcp transport closing on socket 0

Feb 23 03:39:14.812: LDAP: Socket context missing for socket 0

Feb 23 03:39:14.812: LDAP: Socket context missing!! Closing socket

Feb 23 03:39:14.812: LDAP: Received queue event, new AAA request

Feb 23 03:39:44.812: LDAP: Received timer event

Feb 23 03:39:44.812: LDAP: Connection timeout occured. Retrying

Feb 23 03:39:44.812: LDAP: Opening ldap connection ( 192.168.2.10, 389 )ldap_open

ldap_init libldap 4.5 18-FEB-2000

open_ldap_connection

ldap_connect_to_host: 192.168.2.10:389

Feb 23 03:39:44.812: LDAP: socket 0 - connecting to 192.168.2.10 (389)

Feb 23 03:39:44.812: LDAP: socket 0 - connection in progress

Feb 23 03:39:44.812: LDAP: socket 0 - local address 192.168.2.1 (30598)

Feb 23 03:39:44.812: LDAP: Connection on socket 0

Feb 23 03:39:44.812: LDAP: Connection to LDAP server (backupad, 192.168.2.10) attempted

Feb 23 03:39:44.812: LDAP: Connection state: DOWN => CONNECTING

Feb 23 03:39:44.812: LDAP: Received socket event

Feb 23 03:39:44.812: LDAP: Checking the conn status

Feb 23 03:39:44.812: LDAP: Socket read event socket=0

Feb 23 03:39:44.812: LDAP: Found socket ctx

Feb 23 03:39:44.812: LDAP: Making socket conn up

Feb 23 03:39:44.812: LDAP: Notify the protocol codeldap_open successful

Notify LDAP main if it has to initiate any bind requests

Feb 23 03:39:44.812: LDAP: Protocol received transport up notication

Feb 23 03:39:44.812: LDAP: Connection state: CONNECTING => UP

Feb 23 03:39:44.812: LDAP: Set socket=0 to non blocking mode

Feb 23 03:39:44.812: LDAP: Performing Root-Dn bind operationldap_req_encode

Doing socket write

Feb 23 03:39:44.812: LDAP: Root Bind on CN=VPNUser01,OU=Service Accounts,DC=*****,DC=com initiated.

Feb 23 03:39:44.812: LDAP: Received socket event

Feb 23 03:39:45.316: LDAP: Received socket event

Feb 23 03:39:45.316: LDAP: Checking the conn status

Feb 23 03:39:45.316: LDAP: Socket read event socket=0

Feb 23 03:39:45.316: LDAP: Found socket ctx

Feb 23 03:39:45.316: LDAP: Receive event: read=1, errno=9 (Bad file number)

Feb 23 03:39:45.316: LDAP: Passing the client ctx=2B75AAD4ldap_result

wait4msg (timeout 0 sec, 1 usec)

ldap_select_fd_wait (select)

ldap_read_activity lc 0x2B613F6C

Doing socket read

LDAP-TCP:Bytes read = 22

ldap_match_request succeeded for msgid 1 h 0

changing lr 0x2B61ECC0 to COMPLETE as no continuations

removing request 0x2B61ECC0 from list as lm 0x329BC310 all 0

ldap_msgfree

ldap_msgfree

Feb 23 03:39:45.316: LDAP: LDAP Messages to be processed: 1

Feb 23 03:39:45.316: LDAP: LDAP Message type: 97

Feb 23 03:39:45.316: LDAP: Got ldap transaction context from reqid 174ldap_parse_result

Feb 23 03:39:45.316: LDAP: resultCode:    0     (Success)

Feb 23 03:39:45.316: LDAP: Received Bind Response

Feb 23 03:39:45.316: LDAP: Received Root Bind Response ldap_parse_result

Feb 23 03:39:45.316: LDAP: Ldap Result Msg: SUCCESS, Result code =0

Feb 23 03:39:45.316: LDAP: Root DN bind Successful on :CN=VPNUser01,OU=Service Accounts,DC=*****,DC=com

Feb 23 03:39:45.316: LDAP: Transaction context removed from list [ldap reqid=174]ldap_msgfree

ldap_result

wait4msg (timeout 0 sec, 1 usec)

ldap_select_fd_wait (select)

ldap_err2string

Feb 23 03:39:45.316: LDAP: Finished processing ldap msg, Result:Success

Feb 23 03:39:45.316: LDAP: Received socket event

Thank you in advanced.

Best Regards

Paul

2 Replies 2

spencerquek1908
Level 1
Level 1

Hi Paul,

I am having this problem too as well n reported to Cisco Tac in early Jan. They mentioned that this is a bug and will be fixed on the next IOS upgrade but the problem still exist. Currently i am using 2911 running IOS c2900-universalk9-mz.SPA.152-3.T4.bin after the upgrade.

Does anyone have a bug ID for this issue? We see exactly the same thing. IOS 15.1(4)M8

Review Cisco Networking products for a $25 gift card