cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
3110
Views
3
Helpful
16
Replies

Help with Easy VPN Server with LDAP

ryan_david
Level 1
Level 1

Hi,

Previously, I was able to configure our Easy VPN Server with local authentication.

But now, I am trying to use LDAP authentication to match with our policies.

Can anybody help me please to check the config and tell me what is wrong with it?

My router is a Cisco1941/K9.

Thank you in advance.

Ryan


Current configuration : 5128 bytes
!
! Last configuration change at 13:25:16 UTC Tue Aug 28 2012 by admin
! NVRAM config last updated at 05:03:14 UTC Mon Aug 27 2012 by admin
! NVRAM config last updated at 05:03:14 UTC Mon Aug 27 2012 by admin
version 15.2
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname Router
!
boot-start-marker
boot-end-marker
!
!
!
aaa new-model
!
!
aaa group server ldap ASIA-LDAP
server server1.domain.net
!
aaa authentication login ciscocp_vpn_xauth_ml_1 local
aaa authentication login ASIA-LDAP-AUTHE group ldap group ASIA-LDAP
aaa authorization network VPN_Cisco local
aaa authorization network ASIA-LDAP-AUTHO group ldap group ASIA-LDAP
!
!
!
!
!
aaa session-id common
!
!
no ipv6 cef
!
!
!
!
!
ip domain name domain.net
ip cef
!
multilink bundle-name authenticated
!
crypto pki token default removal timeout 0
!
crypto pki trustpoint TP-self-signed-765105936
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-765105936
revocation-check none
rsakeypair TP-self-signed-765105936
!
!
crypto pki certificate chain TP-self-signed-765105936
certificate self-signed 01
  30820229 30820192 A0030201 02020101 300D0609 2A864886 F70D0101 05050030
  30312E30 2C060355 04031325 494F532D 53656C66 2D536967 6E65642D 43657274
  69666963 6174652D 37363531 30353933 36301E17 0D313230 36323630 39323033
  355A170D 32303031 30313030 30303030 5A303031 2E302C06 03550403 1325494F
  532D5365 6C662D53 69676E65 642D4365 72746966 69636174 652D3736 35313035
  39333630 819F300D 06092A86 4886F70D 01010105 0003818D 00308189 02818100
  C1B7E661 4893D83A EFE44B76 92BAA71A 6375C854 88D49791 4533E51A 551D8EF7
  F82E2432 E65B401D 27FE4896 2105B38A CB1908C1 9AE2FC19 8A9393C3 1B618390
  EE6CB1CC 5C8B8811 04FA198E 16F3297B 6B15F974 13EE4897 74270D31 97270547
  4590ACA6 68606596 97C5D4D5 462CACA0 CDDAC35A 17415302 CFD4E329 8E7E542D
  02030100 01A35330 51300F06 03551D13 0101FF04 05300301 01FF301F 0603551D
  23041830 1680142E FF686472 569BCCF1 552B1200 D35060DB 5B660F30 1D060355
  1D0E0416 04142EFF 68647256 9BCCF155 2B1200D3 5060DB5B 660F300D 06092A86
  4886F70D 01010505 00038181 00558F64 05207D35 AA4BD086 4579ACF6 BCF6A851
  1D0EA15B 75DBFA45 E01FBA5C 6F827C42 1A50DD11 8922F1E5 3384B8D8 8DD6C222
  0187E501 82C1C557 8AD3445C A4450241 75D771CF 3A6428A6 7E1FC7E5 8B418E65
  74D265DD 06251C7D 6EF39CE9 3D692763 FE03F795 AE865885 CFF660A5 4C1FF603
  3AF09B1E 243EA5ED 7E4C30B9 3A
        quit
license udi pid CISCO1941/K9 sn xxxxxxxxxxx

hw-module ism 0
!
!
!
username admin privilege 15 secret 5 $1$rVI4$WIP5x6at0b1Vot5LbdlGN/
username ryan privilege 0 password 0 pass1234
!
redundancy
!
!
!
!
!
!
!
crypto isakmp policy 1
encr 3des
authentication pre-share
group 2
!
crypto isakmp client configuration group VPN_Group1
key xxxxxxxxxxxx
dns 10.127.8.20
pool SDM_POOL_1
acl 100
netmask 255.255.255.0
crypto isakmp profile ciscocp-ike-profile-1
   match identity group VPN_Group1
   client authentication list ASIA-LDAP-AUTHE
   isakmp authorization list ASIA-LDAP-AUTHO
   client configuration address respond
   virtual-template 1
!
!
crypto ipsec transform-set ESP-3DES-SHA esp-3des esp-sha-hmac
!
crypto ipsec profile CiscoCP_Profile1
set transform-set ESP-3DES-SHA
set isakmp-profile ciscocp-ike-profile-1
!
!
!
!
!
!
!
interface Loopback0
ip address 10.127.15.1 255.255.255.0
!
interface Embedded-Service-Engine0/0
no ip address
shutdown
!
interface GigabitEthernet0/0
ip address xxx.xxx.xxx.xxx 255.255.255.224
duplex auto
speed auto
!
interface GigabitEthernet0/1
ip address 10.127.31.26 255.255.255.252
duplex auto
speed auto
!
interface Virtual-Template1 type tunnel
ip unnumbered Loopback0
tunnel mode ipsec ipv4
tunnel protection ipsec profile CiscoCP_Profile1
!
ip local pool SDM_POOL_1 10.127.20.129 10.127.20.254
ip forward-protocol nd
!
ip http server
ip http authentication local
ip http secure-server
ip http timeout-policy idle 60 life 86400 requests 10000
!
ip route 0.0.0.0 0.0.0.0 GigabitEthernet0/0
ip route 10.0.0.0 255.0.0.0 10.127.31.25
ip route 10.127.20.128 255.255.255.128 GigabitEthernet0/0
!
access-list 100 remark CCP_ACL Category=4
access-list 100 permit ip 10.0.0.0 0.255.255.255 any
!
!
!
!
!
!
!
ldap attribute-map ASIA-username-map
map type sAMAccountName username
!
ldap server server1.domain.net
ipv4 10.127.8.20
attribute map ASIA-username-map
bind authenticate root-dn CN=xxx\, S1234567,OU=Service Accounts,OU=Admin,OU=Acc
ounts,DC=domain,DC=net password password1
base-dn DC=domain,DC=net
authentication bind-first
!
!
control-plane
!
!
!
line con 0
line aux 0
line 2
no activation-character
no exec
transport preferred none
transport input all
transport output lat pad telnet rlogin lapb-ta mop udptn v120 ssh
stopbits 1
line 67
no activation-character
no exec
transport preferred none
transport input all
transport output lat pad telnet rlogin lapb-ta mop udptn v120 ssh
stopbits 1
line vty 0 4
transport input telnet
!
scheduler allocate 20000 1000
end

Router#

1 Accepted Solution

Accepted Solutions

Ryan,

It looks like you are running into the issue where this is documented in the section:

Issues with using "authentication bind-first" with user-defined attribute-maps:

**Then you're likely to see a failure in your authentication attempt. The  error message you will see is "Invalid credentials, Result code =49".  The logs will look something like the logs below:**

Which is the same error you are seeing. Go ahead and put back in your attribute mapping and test again.

If you remove the command "authentication bind-first" from the above configuration everything will work properly.

https://supportforums.cisco.com/docs/DOC-17780

Tarik Admani
*Please rate helpful posts*

View solution in original post

16 Replies 16

Tarik Admani
VIP Alumni
VIP Alumni

Hi,

On the client can you paste the "show crypto ipsec client ezvpn", and can you issue a debug ldap 255 and post the results of the output.

Thanks,

Tarik Admani
*Please rate helpful posts*

Hi Tarik,

Thank you for the very quick response.

Here is the result of show crypto ipsec client ezvpn:

Router#show crypto ipsec client ezvpn

Easy VPN Remote Phase: 8

Router# Router#show crypto ipsec client ezvpn
Easy VPN Remote Phase: 8
Router#

Then the "debug ldap 255" is having an invalid input detected at the 255, instead I used "debug LDAP all"

Best Regards,

Ryan

Wow that was my fault (i was assuming ASA as the head)

On the client can you issue "show ipsec client ezvpn " and on the vpn server can you run "debug crypto ipsec"

You can also issue a debug aaa authenticatoin to see if it an ldap issue.

I also wanted to know if this is the right path for the bind account: "bind authenticate root-dn CN=xxx\, S1234567,OU=Service Accounts,OU=Admin,OU=Accounts,DC=domain,DC=net password password1"

Try using the CN=S1234567.....

Thanks,

Tarik Admani
*Please rate helpful posts*

Hi Tarik,

How do I issue the show command at the client? I am using the Cisco VPN Client 5.0.07.0410.

The client does not display the window that asks for the username and password. When I click the Connect button, it does not seem to cennect at all.

I also tried CN=S1234567 but the result is the same.

Thanks,

Ryan

Sorry when you say easy vpn server I am thinking the other end is another router (easy vpn client)....since this isnt the case then issue "debug crypto ipsec" on the router and see if you see any debu,. Also did this working before you made the ldap change? If you do not see any messages from the debugs then the firewall the client is connecting behind is blocking NAT-T.

Thanks,

Tarik Admani
*Please rate helpful posts*

Hi Tarik,

I get this whe I do debug crypto ipsec:

Router#debug crypto ipsec
Crypto IPSEC debugging is on
Router#

It was working previously on local authentication (XAuth) but I need to change it to LDAP to comply with company policies.

I think the firewall on the client side is not blocking it since it was working before the change to LDAP auth.

Any other ideas?

Thanks,

Ryan

Hi,

Can you also issue the "debug crypto isakmp" also make sure that term mon is enabled.

thanks,

Tarik Admani
*Please rate helpful posts*

Hi Tarik,

Thank you for that. I forgot terminal monitor was not enabled.

Here is the result when I tried to connect:

Router#terminal monitor
Router#debug crypto isakmp
Crypto ISAKMP debugging is on
Router#
Aug 29 02:09:56.945: AAA/BIND(00000362): Bind i/f
Aug 29 02:10:18.601: ISAKMP (0): received packet from xxx.xxx.164.108 dport 500 s
port 63859 Global (N) NEW SA
Aug 29 02:10:18.601: ISAKMP: Created a peer struct for xxx.xxx.164.108, peer port
63859
Aug 29 02:10:18.601: ISAKMP: New peer created peer = 0x31DAADE0 peer_handle = 0x
8000009E
Aug 29 02:10:18.601: ISAKMP: Locking peer struct 0x31DAADE0, refcount 1 for cryp
to_isakmp_process_block
Aug 29 02:10:18.601: ISAKMP: local port 500, remote port 63859
Aug 29 02:10:18.601: ISAKMP:(0):insert sa successfully sa = 32198434
Aug 29 02:10:18.601: ISAKMP:(0): processing SA payload. message ID = 0
Aug 29 02:10:18.601: ISAKMP:(0): processing ID payload. message ID = 0
Aug 29 02:10:18.601: ISAKMP (0): ID payload
        next-payload : 13
        type         : 11
        group id     : VPN_Group1
        protocol     : 17
        port         : 500
        length       : 18
Aug 29 02:10:18.601: ISAKMP:(0):: peer matches ciscocp-ike-profile-1 profile
Aug 29 02:10:18.601: ISAKMP:(0):Setting client config settings 2A053B6C
Aug 29 02:10:18.601: ISAKMP:(0):(Re)Setting client xauth list  and state
Aug 29 02:10:18.601: ISAKMP/xauth: initializing AAA request
Aug 29 02:10:18.601: AAA/BIND(00000363): Bind i/f
Aug 29 02:10:18.601: ISAKMP:(0): processing vendor id payload
Aug 29 02:10:18.601: ISAKMP:(0): vendor ID seems Unity/DPD but major 215 mismatc
h
Aug 29 02:10:18.601: ISAKMP:(0): vendor ID is XAUTH
Aug 29 02:10:18.601: ISAKMP:(0): processing vendor id payload
Aug 29 02:10:18.601: ISAKMP:(0): vendor ID is DPD
Aug 29 02:10:18.601: ISAKMP:(0): processing vendor id payload
Aug 29 02:10:18.601: ISAKMP:(0): processing IKE frag vendor id payload
Aug 29 02:10:18.601: ISAKMP:(0):Support for IKE Fragmentation not enabled
Aug 29 02:10:18.601: ISAKMP:(0): processing vendor id payload
Aug 29 02:10:18.601: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatc
h
Aug 29 02:10:18.601: ISAKMP:(0): vendor ID is NAT-T v2
Aug 29 02:10:18.601: ISAKMP:(0): processing vendor id payload
Aug 29 02:10:18.605: ISAKMP:(0): vendor ID is Unity
Aug 29 02:10:18.605: ISAKMP:(0): Authentication by xauth preshared
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash SHA
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth XAUTHInitPreShared
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 256
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 2 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash MD5
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth XAUTHInitPreShared
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 256
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 3 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash SHA
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth pre-share
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 256
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 4 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash MD5
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth pre-share
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 256
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 5 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash SHA
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth XAUTHInitPreShared
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 128
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 6 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash MD5
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth XAUTHInitPreShared
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 128
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 7 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash SHA
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth pre-share
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 128
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 8 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption AES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash MD5
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth pre-share
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:      keylength of 128
Aug 29 02:10:18.605: ISAKMP:(0):Encryption algorithm offered does not match poli
cy!
Aug 29 02:10:18.605: ISAKMP:(0):atts are not acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Checking ISAKMP transform 9 against priority 1 p
olicy
Aug 29 02:10:18.605: ISAKMP:      encryption 3DES-CBC
Aug 29 02:10:18.605: ISAKMP:      hash SHA
Aug 29 02:10:18.605: ISAKMP:      default group 2
Aug 29 02:10:18.605: ISAKMP:      auth XAUTHInitPreShared
Aug 29 02:10:18.605: ISAKMP:      life type in seconds
Aug 29 02:10:18.605: ISAKMP:      life duration (VPI) of  0x0 0x20 0xC4 0x9B
Aug 29 02:10:18.605: ISAKMP:(0):atts are acceptable. Next payload is 3
Aug 29 02:10:18.605: ISAKMP:(0):Acceptable atts:actual life: 86400
Aug 29 02:10:18.605: ISAKMP:(0):Acceptable atts:life: 0
Aug 29 02:10:18.605: ISAKMP:(0):Fill atts in sa vpi_length:4
Aug 29 02:10:18.605: ISAKMP:(0):Fill atts in sa life_in_seconds:2147483
Aug 29 02:10:18.605: ISAKMP:(0):Returning Actual lifetime: 86400
Aug 29 02:10:18.605: ISAKMP:(0)::Started lifetime timer: 86400.

Aug 29 02:10:18.605: ISAKMP:(0): processing KE payload. message ID = 0
Aug 29 02:10:18.609: ISAKMP:(0): processing NONCE payload. message ID = 0
Aug 29 02:10:18.609: ISAKMP:(0): vendor ID is NAT-T v2
Aug 29 02:10:18.609: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
Aug 29 02:10:18.609: ISAKMP:(0):Old State = IKE_READY  New State = IKE_R_AM_AAA_
AWAIT

Aug 29 02:10:18.609: LDAP: LDAP: Queuing AAA request 867 for processing
Aug 29 02:10:18.609: LDAP: Received queue event, new AAA request
Aug 29 02:10:18.609: LDAP: LDAP authorization request
Aug 29 02:10:18.609: LDAP: AUTHOR: Getting first available LDAP server
Aug 29 02:10:18.609: LDAP: Got next LDAP server :server1.domain.net
Aug 29 02:10:18.609: LDAP: Dynamic map configured
Aug 29 02:10:18.609: LDAP: Dynamic map found for aaa type=username
Aug 29 02:10:18.609: LDAP: Ldap Search Req sent
                    ld          833519964
                    base dn     DC=domain,DC=net
                    scope       2
                    filter      (&(objectclass=*)(sAMAccountName=VPN_Group1))lda
p_req_encode
put_filter "(&(objectclass=*)(sAMAccountName=VPN_Group1))"
put_filter: AND
put_filter_list "(objectclass=*)(sAMAccountName=VPN_Group1)"
put_filter "(objectclass=*)"
put_filter: simple
put_filter "(sAMAccountName=VPN_Group1)"
put_filter: simple
Doing socket write
Aug 29 02:10:18.609: LDAP:  LDAP search request sent successfully (reqid:375)
Aug 29 02:10:18.609: LDAP: Sent the LDAP request to server
Aug 29 02:10:18.945: LDAP: Received socket event
Aug 29 02:10:18.945: LDAP: Checking the conn status
Aug 29 02:10:18.945: LDAP: Socket read event socket=0
Aug 29 02:10:18.945: LDAP: Found socket ctx
Aug 29 02:10:18.945: LDAP: Receive event: read=1, errno=9 (Bad file number)
Aug 29 02:10:18.945: LDAP: Passing the client ctx=31AE815Cldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x28C276B4

Doing socket read
LDAP-TCP:Bytes read = 127
ldap_match_request succeeded for msgid 2 h 0

Aug 29 02:10:18.945: LDAP: LDAP Messages to be processed: 1
Aug 29 02:10:18.945: LDAP: LDAP Message type: 115
Aug 29 02:10:18.945: LDAP: Got ldap transaction context from reqid 375
Aug 29 02:10:18.945: LDAP: Unrecognised ldap message type. Cant parse
Aug 29 02:10:18.945: LDAP: Uninterested message type=115 ignoredldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x28C276B4
ldap_match_request succeeded for msgid 2 h 0
changing lr 0x29FD609C to COMPLETE as no continuations
removing request 0x29FD609C from list as lm 0x29C24F7C all 0
ldap_msgfree
ldap_msgfree

Aug 29 02:10:18.945: LDAP: LDAP Messages to be processed: 1
Aug 29 02:10:18.945: LDAP: LDAP Message type: 101
Aug 29 02:10:18.949: LDAP: Got ldap transaction context from reqid 375ldap_parse
_result

Aug 29 02:10:18.949: LDAP: resultCode:    0     (Success)
Aug 29 02:10:18.949: LDAP: Received Search Response resultldap_parse_result

Aug 29 02:10:18.949: LDAP: Ldap Result Msg: SUCCESS, Result code =0
Aug 29 02:10:18.949: LDAP: Failed to get any search entries ldap_msgfree

Aug 29 02:10:18.949: LDAP: Closing transaction and reporting error to AAA
Aug 29 02:10:18.949: LDAP: Transaction context removed from list [ldap reqid=375
]
Aug 29 02:10:18.949: LDAP: Notifying AAA: REQUEST FAILED
Aug 29 02:10:18.949: ISAKMP:(0): constructed NAT-T vendor-02 ID
Aug 29 02:10:18.949: ISAKMP:(0):SA is doing pre-shared key authentication plus X
AUTH using id type ID_IPV4_ADDR
Aug 29 02:10:18.949: ISAKMP (0): ID payload
        next-payload : 10
        type         : 1
        address      : xxx.xxx.164.121
        protocol     : 0
        port         : 0
        length       : 12
Aug 29 02:10:18.949: ISAKMP:(0):Total payload length: 12
Aug 29 02:10:18.949: ISAKMP:(0): sending packet to xxx.xxx.164.108 my_port 500 pe
er_port 63859 (R) AG_INIT_EXCH
Aug 29 02:10:18.949: ISAKMP:(0):Sending an IKE IPv4 Packet.
Aug 29 02:10:18.949: ISAKMP:(0):Input = IKE_MESG_FROM_AAA, PRESHARED_KEY_REPLY
Aug 29 02:10:18.949: ISAKMP:(0):Old State = IKE_R_AM_AAA_AWAIT  New State = IKE_
R_AM2

Aug 29 02:10:18.949: LDAP: Received socket event
Aug 29 02:10:19.033: ISAKMP (0): received packet from xxx.xxx.164.108 dport 500 s
port 63859 Global (R) AG_INIT_EXCH
Aug 29 02:10:19.033: %CRYPTO-6-IKMP_NOT_ENCRYPTED: IKE packet from xxx.xx.164.10
8 was not encrypted and it should've been.
Aug 29 02:10:19.033: ISAKMP (0): incrementing error counter on sa, attempt 1 of
5: reset_retransmission
Aug 29 02:10:19.033: ISAKMP (0): received packet from xxx.xxx.164.108 dport 500 s
port 63859 Global (R) AG_INIT_EXCH
Aug 29 02:10:19.033: %CRYPTO-6-IKMP_NOT_ENCRYPTED: IKE packet from xxx.xxx.164.10
8 was not encrypted and it should've been.
Aug 29 02:10:19.033: ISAKMP (0): incrementing error counter on sa, attempt 2 of
5: reset_retransmission
Aug 29 02:10:20.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH...
Aug 29 02:10:20.033: ISAKMP (0): incrementing error counter on sa, attempt 3 of
5: retransmit phase 1
Aug 29 02:10:20.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH
Aug 29 02:10:20.033: ISAKMP:(0): sending packet to xxx.xxx.164.108 my_port 500 pe
er_port 63859 (R) AG_INIT_EXCH
Aug 29 02:10:20.033: ISAKMP:(0):Sending an IKE IPv4 Packet.
Aug 29 02:10:23.837: AAA/BIND(00000364): Bind i/f
Aug 29 02:10:30.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH...
Aug 29 02:10:30.033: ISAKMP (0): incrementing error counter on sa, attempt 4 of
5: retransmit phase 1
Aug 29 02:10:30.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH
Aug 29 02:10:30.033: ISAKMP:(0): sending packet to xxx.xxx.164.108 my_port 500 pe
er_port 63859 (R) AG_INIT_EXCH
Aug 29 02:10:30.033: ISAKMP:(0):Sending an IKE IPv4 Packet.
Aug 29 02:10:40.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH...
Aug 29 02:10:40.033: ISAKMP (0): incrementing error counter on sa, attempt 5 of
5: retransmit phase 1
Aug 29 02:10:40.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH
Aug 29 02:10:40.033: ISAKMP:(0): sending packet to xxx.xxx.164.108 my_port 500 pe
er_port 63859 (R) AG_INIT_EXCH
Aug 29 02:10:40.033: ISAKMP:(0):Sending an IKE IPv4 Packet.
Aug 29 02:10:50.033: ISAKMP:(0): retransmitting phase 1 AG_INIT_EXCH...
Aug 29 02:10:50.033: ISAKMP:(0):peer does not do paranoid keepalives.

Aug 29 02:10:50.033: ISAKMP:(0):deleting SA reason "Death by retransmission P1"
state (R) AG_INIT_EXCH (peer xxx.xxx.164.108)
Aug 29 02:10:50.033: ISAKMP:(0):deleting SA reason "Death by retransmission P1"
state (R) AG_INIT_EXCH (peer xxx.xxx.164.108)
Aug 29 02:10:50.033: ISAKMP: Unlocking peer struct 0x31DAADE0 for isadb_mark_sa_
deleted(), count 0
Aug 29 02:10:50.033: ISAKMP: Deleting peer node by peer_reap for xxx.xxx.164.108:
31DAADE0
Aug 29 02:10:50.033: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Aug 29 02:10:50.033: ISAKMP:(0):Old State = IKE_R_AM2  New State = IKE_DEST_SA

Aug 29 02:10:50.033: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Aug 29 02:11:28.937: AAA/BIND(00000365): Bind i/f

I hope this debug info helps.

Thanks,

Ryan

Thanks,

Looks like a ldap issue just as you called it, can you issue "debug ldap" and see what errors or events you see.

thanks,

Tarik Admani
*Please rate helpful posts*

Hi Tarik,

Here is the debug info:

Router#show ldap server all
Server Information for server1.domain.net
================================
Server name             :server1.domain.net
Server IP               :10.127.8.20
Server listening Port   :3268
Connection status       :UP
Bind Root-dn            :CN=NDB\, S1234567,OU=Service Accounts,OU=Admin,OU=Accou
nts,DC=asia,DC=pilkington,DC=net
Root Bind status        :Root-dn Bind Done
Server mode             :Non-Secure
Cipher Suite            :0x00
Authentication Seq      :Bind/Compare password first. Search next
Authentication Procedure:Bind with user password
Base-Dn                 :DC=domain,DC=net
Attribute map           :ASIA-username-map
Request timeout             :30
----------------------------------
* LDAP STATISTICS *
Total messages  [Sent:68, Received:68]
Response delay(ms) [Average:473, Maximum:548]
Total search    [Request:0, ResultEntry:0, ResultDone:0]
Total bind      [Request:68, Response:68]
Total extended  [Request:0, Response:0]
Total compare   [Request:0, Response:0]
----------------------------------


Router#
Aug 31 03:04:27.404: AAA/BIND(00000056): Bind i/f
Aug 31 03:04:27.424: AAA/BIND(00000057): Bind i/f
Aug 31 03:04:31.896: AAA/AUTHEN/LOGIN (00000057): Pick method list 'ciscocp_vpn_
xauth_ml_1'
Aug 31 03:04:31.896: LDAP: LDAP: Queuing AAA request 87 for processing
Aug 31 03:04:31.896: LDAP: Received queue event, new AAA request
Aug 31 03:04:31.896: LDAP: LDAP authentication request
Aug 31 03:04:31.900: LDAP: Attempting first  next available LDAP server
Aug 31 03:04:31.900: LDAP: Got next LDAP server :server1.domain.net
Aug 31 03:04:31.900: LDAP: First Task: Send bind req
Aug 31 03:04:31.900: LDAP: Authentication policy: bind-first
Aug 31 03:04:31.900: LDAP: Dynamic map configured
Aug 31 03:04:31.900: LDAP: Dynamic map found for aaa type=username
Aug 31 03:04:31.900: LDAP: Bind: User-DN=sAMAccountName=ryan,DC=domain,DC=netldap_req_encode
Doing socket write
Aug 31 03:04:31.900: LDAP:  LDAP bind request sent successfully (reqid=115)
Aug 31 03:04:31.900: LDAP: Sent the LDAP request to server
Aug 31 03:04:32.364: LDAP: Received socket event
Aug 31 03:04:32.364: LDAP: Checking the conn status
Aug 31 03:04:32.364: LDAP: Socket read event socket=0
Aug 31 03:04:32.364: LDAP: Found socket ctx
Aug 31 03:04:32.364: LDAP: Receive event: read=1, errno=9 (Bad file number)
Aug 31 03:04:32.364: LDAP: Passing the client ctx=31BC7010ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x30C757EC

Doing socket read
LDAP-TCP:Bytes read = 109
ldap_match_request succeeded for msgid 4 h 0
changing lr 0x30DA1630 to COMPLETE as no continuations
removing request 0x30DA1630 from list as lm 0x31BF7518 all 0
ldap_msgfree
ldap_msgfree

Aug 31 03:04:32.364: LDAP: LDAP Messages to be processed: 1
Aug 31 03:04:32.364: LDAP: LDAP Message type: 97
Aug 31 03:04:32.364: LDAP: Got ldap transaction context from reqid 115ldap_parse
_result

Aug 31 03:04:32.364: LDAP: resultCode:    49     (Invalid credentials)
Aug 31 03:04:32.364: LDAP: Received Bind Responseldap_parse_result
ldap_err2string

Aug 31 03:04:32.364: LDAP: Ldap Result Msg: FAILED:Invalid credentials, Result c
ode =49
Aug 31 03:04:32.364: LDAP: LDAP Bind operation result : failed
Aug 31 03:04:32.364: LDAP: Restoring root bind status of the connection
Aug 31 03:04:32.364: LDAP: Performing Root-Dn bind operationldap_req_encode
Doing socket write
Aug 31 03:04:32.364: LDAP: Root Bind on CN=NDB\, S1234567,OU=Service Accounts,OU
=Admin,OU=Accounts,DC=domain,DC=net initiated.ldap_msgfree

Aug 31 03:04:32.364: LDAP: Closing transaction and reporting error to AAA
Aug 31 03:04:32.364: LDAP: Transaction context removed from list [ldap reqid=115
]
Aug 31 03:04:32.364: LDAP: Notifying AAA: REQUEST FAILED
Aug 31 03:04:32.364: LDAP: Received socket event
Aug 31 03:04:32.912: LDAP: Received socket event
Aug 31 03:04:32.912: LDAP: Checking the conn status
Aug 31 03:04:32.912: LDAP: Socket read event socket=0
Aug 31 03:04:32.912: LDAP: Found socket ctx
Aug 31 03:04:32.912: LDAP: Receive event: read=1, errno=9 (Bad file number)
Aug 31 03:04:32.912: LDAP: Passing the client ctx=31BC7010ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x30C757EC

Doing socket read
LDAP-TCP:Bytes read = 22
ldap_match_request succeeded for msgid 5 h 0
changing lr 0x29DA08BC to COMPLETE as no continuations
removing request 0x29DA08BC from list as lm 0x31BF7518 all 0
ldap_msgfree
ldap_msgfree

Aug 31 03:04:32.912: LDAP: LDAP Messages to be processed: 1
Aug 31 03:04:32.912: LDAP: LDAP Message type: 97
Aug 31 03:04:32.912: LDAP: Got ldap transaction context from reqid 116ldap_parse
_result

Aug 31 03:04:32.912: LDAP: resultCode:    0     (Success)
Aug 31 03:04:32.912: LDAP: Received Bind Response
Aug 31 03:04:32.912: LDAP: Received Root Bind Response ldap_parse_result

Aug 31 03:04:32.912: LDAP: Ldap Result Msg: SUCCESS, Result code =0
Aug 31 03:04:32.912: LDAP: Root DN bind Successful on :CN=NDB\, S1234567,OU=Serv
ice Accounts,OU=Admin,OU=Accounts,DC=domain,DC=net
Aug 31 03:04:32.912: LDAP: Transaction context removed from list [ldap reqid=116
]ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string

Aug 31 03:04:32.912: LDAP: Finished processing ldap msg, Result:Success
Aug 31 03:04:32.912: LDAP: Received socket event

Thank you and Best Regards,

Ryan

Thanks looks like you are having issue with the ldap binding action....I do not like the netbios format that you are using in your configuration. If you have an ldap browser like softerra or ldp.exe you should be able to get the full DN of the admin or serice account and try using that. for some reason I can not understand how this format will work; CN=NDB\, S1234567,OU=Service Accounts,OU....

Sorry that i am still hung up on this but here is some help ariticle on how to use softerra...attached is a pdf that will walk you through how to connect the ldap browser to your network and how to browse for the dn.

Thanks,

Tarik Admani
*Please rate helpful posts*

Hi Tarik,

Thank you for your reply.

Sorry but I do not have the appropriate access to AD to change the name of the service account. But I verified it with dsquery and it shows the same netbios format. Also the show ldap server all shows that there is root-dn bind done.

Thank you and Best Regards,

Ryan

Ryan,

Something looks a little off in the way the ldap request is leaving the router can you remove your ldap attribute map and see if the ldap bind succeeds

Aug 31 03:04:31.900: LDAP: Bind: User-DN=sAMAccountName=ryan,DC=domain,DC=netldap_req_encode

Doing socket write I can't find examples if this is even a valid DN search string should be CN=ryan....

Aug 31 03:04:31.900: LDAP:  LDAP bind request sent successfully (reqid=115)

Aug 31 03:04:31.900: LDAP: Sent the LDAP request to server

Aug 31 03:04:32.364: LDAP: Received socket event

Aug 31 03:04:32.364: LDAP: Checking the conn status

Aug 31 03:04:32.364: LDAP: Socket read event socket=0

Aug 31 03:04:32.364: LDAP: Found socket ctx

Aug 31 03:04:32.364: LDAP: Receive event: read=1, errno=9 (Bad file number)

Aug 31 03:04:32.364: LDAP: Passing the client ctx=31BC7010ldap_result

wait4msg (timeout 0 sec, 1 usec)

ldap_select_fd_wait (select)

ldap_read_activity lc 0x30C757EC

Doing socket read
LDAP-TCP:Bytes read = 109
ldap_match_request succeeded for msgid 4 h 0
changing lr 0x30DA1630 to COMPLETE as no continuations
removing request 0x30DA1630 from list as lm 0x31BF7518 all 0
ldap_msgfree
ldap_msgfree

Aug 31 03:04:32.364: LDAP: LDAP Messages to be processed: 1
Aug 31 03:04:32.364: LDAP: LDAP Message type: 97
Aug 31 03:04:32.364: LDAP: Got ldap transaction context from reqid 115ldap_parse
_result

Aug 31 03:04:32.364: LDAP: resultCode:    49     (Invalid credentials)
Aug 31 03:04:32.364: LDAP: Received Bind Responseldap_parse_result
ldap_err2string

See if you can remove that attribute map and test again, also post the debugs...

Thanks,

Tarik Admani

Hi Tarik,

Here is the debug info after removing the attribute map:

Router#
Aug 31 05:53:04.919: AAA/BIND(00000064): Bind i/f
Aug 31 05:53:04.939: AAA/BIND(00000065): Bind i/f
Aug 31 05:53:10.295: AAA/AUTHEN/LOGIN (00000065): Pick method list 'ciscocp_vpn_
xauth_ml_1'
Aug 31 05:53:10.295: LDAP: LDAP: Queuing AAA request 101 for processing
Aug 31 05:53:10.295: LDAP: Received queue event, new AAA request
Aug 31 05:53:10.295: LDAP: LDAP authentication request
Aug 31 05:53:10.295: LDAP: Attempting first  next available LDAP server
Aug 31 05:53:10.295: LDAP: Got next LDAP server :server1.domain.net
Aug 31 05:53:10.295: LDAP: First Task: Send bind req
Aug 31 05:53:10.295: LDAP: Authentication policy: bind-first
Aug 31 05:53:10.295: LDAP: Check the default map for aaa type=username
Aug 31 05:53:10.295: LDAP: Bind: User-DN=cn=ryan,DC=domain,DC=netldap_req_encode
Doing socket write
Aug 31 05:53:10.295: LDAP:  LDAP bind request sent successfully (reqid=141)
Aug 31 05:53:10.295: LDAP: Sent the LDAP request to server
Aug 31 05:53:10.779: LDAP: Received socket event
Aug 31 05:53:10.779: LDAP: Checking the conn status
Aug 31 05:53:10.779: LDAP: Socket read event socket=0
Aug 31 05:53:10.779: LDAP: Found socket ctx
Aug 31 05:53:10.779: LDAP: Receive event: read=1, errno=9 (Bad file number)
Aug 31 05:53:10.779: LDAP: Passing the client ctx=31BC70B8ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x30C757EC

Doing socket read
LDAP-TCP:Bytes read = 109
ldap_match_request succeeded for msgid 12 h 0
changing lr 0x29D9B000 to COMPLETE as no continuations
removing request 0x29D9B000 from list as lm 0x31BF6D58 all 0
ldap_msgfree
ldap_msgfree

Aug 31 05:53:10.779: LDAP: LDAP Messages to be processed: 1
Aug 31 05:53:10.779: LDAP: LDAP Message type: 97
Aug 31 05:53:10.779: LDAP: Got ldap transaction context from reqid 141ldap_parse
_result

Aug 31 05:53:10.779: LDAP: resultCode:    49     (Invalid credentials)
Aug 31 05:53:10.779: LDAP: Received Bind Responseldap_parse_result
ldap_err2string

Aug 31 05:53:10.779: LDAP: Ldap Result Msg: FAILED:Invalid credentials, Result c
ode =49
Aug 31 05:53:10.779: LDAP: LDAP Bind operation result : failed
Aug 31 05:53:10.779: LDAP: Restoring root bind status of the connection
Aug 31 05:53:10.779: LDAP: Performing Root-Dn bind operationldap_req_encode
Doing socket write
Aug 31 05:53:10.783: LDAP: Root Bind on CN=NDB\, S1234567,OU=Service Accounts,OU
=Admin,OU=Accounts,DC=domain,DC=net initiated.ldap_msgfree

Aug 31 05:53:10.783: LDAP: Closing transaction and reporting error to AAA
Aug 31 05:53:10.783: LDAP: Transaction context removed from list [ldap reqid=141
]
Aug 31 05:53:10.783: LDAP: Notifying AAA: REQUEST FAILED
Aug 31 05:53:10.783: LDAP: Received socket event
Aug 31 05:53:11.327: LDAP: Received socket event
Aug 31 05:53:11.327: LDAP: Checking the conn status
Aug 31 05:53:11.327: LDAP: Socket read event socket=0
Aug 31 05:53:11.327: LDAP: Found socket ctx
Aug 31 05:53:11.327: LDAP: Receive event: read=1, errno=9 (Bad file number)
Aug 31 05:53:11.327: LDAP: Passing the client ctx=31BC70B8ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x30C757EC

Doing socket read
LDAP-TCP:Bytes read = 22
ldap_match_request succeeded for msgid 13 h 0
changing lr 0x3057EA64 to COMPLETE as no continuations
removing request 0x3057EA64 from list as lm 0x31BF6D58 all 0
ldap_msgfree
ldap_msgfree

Aug 31 05:53:11.327: LDAP: LDAP Messages to be processed: 1
Aug 31 05:53:11.327: LDAP: LDAP Message type: 97
Aug 31 05:53:11.327: LDAP: Got ldap transaction context from reqid 142ldap_parse
_result

Aug 31 05:53:11.327: LDAP: resultCode:    0     (Success)
Aug 31 05:53:11.327: LDAP: Received Bind Response
Aug 31 05:53:11.327: LDAP: Received Root Bind Response ldap_parse_result

Aug 31 05:53:11.327: LDAP: Ldap Result Msg: SUCCESS, Result code =0
Aug 31 05:53:11.327: LDAP: Root DN bind Successful on :CN=NDB\, S1234567,OU=Serv
ice Accounts,OU=Admin,OU=Accounts,DC=domain,DC=net
Aug 31 05:53:11.327: LDAP: Transaction context removed from list [ldap reqid=142
]ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string

Aug 31 05:53:11.327: LDAP: Finished processing ldap msg, Result:Success
Aug 31 05:53:11.327: LDAP: Received socket event

Thanks,

Ryan

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: