IOS EasyVPN Server with LDAP authentication
Posted by ltlnetworker on November 9, 2010
LDAP support for authentication and authorization was introduced in IOS 15.1(1)T. In this article we are testing Cisco VPN client connection authenticated against Novell NetWare eDirectory.
Structure of the LDAP directory:
O=AXX
CN=G1 (group)
CN=UG (group)
CN=U1 (user)
CN=U2 (user)
OU=X
CN=U1(user)
O=NXXI
CN=VPN (group)
CN=U1 (user)
CN=U2 (user)
OU=X
CN=U3 (user)
CN=U4 (user)
The base config is created following the configuration guide:
username userloc secret userloc
ldap server nw650
ipv4 10.55.5.223
!transport port 389
bind authenticate root-dn cn=admin,o=AXX password xxxxx
base-dn o=AXX
aaa group server ldap Novell
server nw650
aaa new-model
! VPN xauth user authentication
aaa authentication login eDir group Novell local
! VPN group authorization
aaa authorization network loc-author local
crypto isakmp client configuration group RNXX-EZVPN
key pw1
domain nxx.hu
pool RNXX_Loopback1
acl EZsplit
netmask 255.255.255.0
crypto isakmp profile EZVPN
match identity group RNXX-EZVPN
! Xauth user authentication:
client authentication list eDir
! VPN group authorization:
isakmp authorization list loc-author
client configuration address respond
virtual-template 5
Base DN: this setting works, but there’s no way setting the Base DN to [Root] or “” or RootDSE. Either the syntax is denied or the search does not work. So be ready to place all your users in a subtree under a named container.
Router_NXX#debug ldap all
Router_NXX#sh ldap servers all
Server Information for nw650
================================
Server name :nw650
Server IP :10.55.5.223
Server listening Port :389
Connection status :UP
Bind Root-dn :cn=admin,o=AXX
Root Bind status :Root-dn Bind Done
Server mode :Non-Secure
Cipher Suite :0x00
Authentication Seq :Search first. Then Bind/Compare password next
Authentication Procedure:Bind with user password
Base-Dn :o=AXX
Request timeout :30
----------------------------------
* LDAP STATISTICS *
Total messages [Sent:1, Received:1]
Response delay(ms) [Average:3, Maximum:3]
Total search [Request:0, ResultEntry:0, ResultDone:0]
Total bind [Request:1, Response:1]
Total extended [Request:0, Response:0]
Total compare [Request:0, Response:0]
----------------------------------
--More--
The router’s Root bind is successful, it should be able to perform LDAP operations. Now we connect with the VPN client:
VPN group name: RNXX-EZVPN
VPN group password: pw1
username: u1
password: u1
*Oct 28 09:40:25.903: LDAP: LDAP: Queuing AAA request 17 for processing
*Oct 28 09:40:25.903: LDAP: Received queue event, new AAA request
*Oct 28 09:40:25.903: LDAP: LDAP authentication request
*Oct 28 09:40:25.903: LDAP: Attempting first next available LDAP server
*Oct 28 09:40:25.903: LDAP: Got next LDAP server :nw650
*Oct 28 09:40:25.903: LDAP: First Task: Send search req
*Oct 28 09:40:25.903: LDAP: Check the default map for aaa type=username
! a search request to find username u1 in the directory
! no search filter yet, objectclass can be any type of object
! scope value is 2 (whole subtree) and cannot be modified
*Oct 28 09:40:25.903: LDAP: Ldap Search Req sent
ld 1730613888
base dn o=AXX
scope 2
filter (&(objectclass=*)(cn=u1))ldap_req_encode
put_filter "(&(objectclass=*)(cn=u1))"
put_filter: AND
put_filter_list "(objectclass=*)(cn=u1)"
put_filter "(objectclass=*)"
put_filter: simple
put_filter "(cn=u1)"
put_filter: simple
Doing socket write
*Oct 28 09:40:25.907: LDAP: LDAP search request sent successfully (reqid:3)
*Oct 28 09:40:25.907: LDAP: Sent the LDAP request to server
*Oct 28 09:40:25.919: LDAP: Received socket event
*Oct 28 09:40:25.919: LDAP: Checking the conn status
*Oct 28 09:40:25.919: LDAP: Socket read event socket=0
*Oct 28 09:40:25.919: LDAP: Found socket ctx
*Oct 28 09:40:25.919: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 28 09:40:25.919: LDAP: Passing the client ctx=67271280ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x671BE328
Doing socket read
LDAP-TCP:Bytes read = 1497
ldap_match_request succeeded for msgid 3 h 0
*Oct 28 09:40:25.923: LDAP: LDAP Messages to be processed: 1
*Oct 28 09:40:25.923: LDAP: LDAP Message type: 100
*Oct 28 09:40:25.923: LDAP: Got ldap transaction context from reqid 3
! attributes of the user found
*Oct 28 09:40:25.923: LDAP: Attribute Length Valueldap_get_dn
*Oct 28 09:40:25.923: LDAP: dn 16 cn=U1,o=AXX
*Oct 28 09:40:25.923: LDAP: Check the default map for aaa type=password
*Oct 28 09:40:25.923: LDAP: nGWVisibility 1 2
*Oct 28 09:40:25.923: LDAP: nGWObjectID 2 U1
*Oct 28 09:40:25.923: LDAP: nGWPostOffice 19 cn=GW_PO,o=AXX
*Oct 28 09:40:25.923: LDAP: nGWFileID 3 c35
*Oct 28 09:40:25.923: LDAP: nGWGroupWiseID 56 GW_DOM.GW_PO.U1{106}BBB1C360-18B0-0000-8806-B400FA009E00
*Oct 28 09:40:25.923: LDAP: mail 11 U1@proba.hu
*Oct 28 09:40:25.923: LDAP: uid 2 U1
*Oct 28 09:40:25.923: LDAP: givenName 4 Geza
*Oct 28 09:40:25.923: LDAP: Language 7 ENGLISH
*Oct 28 09:40:25.923: LDAP: title 9 Beosztott
*Oct 28 09:40:25.923: LDAP: telephoneNumber 8 2345-678
*Oct 28 09:40:25.923: LDAP: sn 2 U1
*Oct 28 09:40:25.923: LDAP: securityEquals 16 cn=G1,o=AXX
*Oct 28 09:40:25.927: LDAP: ou 5 Uzem1
*Oct 28 09:40:25.927: LDAP: objectClass 13 inetOrgPerson
*Oct 28 09:40:25.927: LDAP: objectClass 20 organizationalPerson
*Oct 28 09:40:25.927: LDAP: objectClass 6 Person
*Oct 28 09:40:25.927: LDAP: objectClass 18 ndsLoginProperties
*Oct 28 09:40:25.927: LDAP: objectClass 3 Top
*Oct 28 09:40:25.927: LDAP: eMailAddress 13 7#U1@proba.hu
*Oct 28 09:40:25.927: LDAP: loginTime 15 20091116172404Z
! group membership. In Active Directory, this is called memberOf
*Oct 28 09:40:25.927: LDAP: groupMembership 16 cn=G1,o=AXX
*Oct 28 09:40:25.927: LDAP: cn 2 U1
*Oct 28 09:40:25.927: LDAP: ACL 50 2#subtree#cn=U1,o=AXX#[All Attributes Rights]
*Oct 28 09:40:25.927: LDAP: ACL 36 6#entry#cn=U1,o=AXX#loginScript
*Oct 28 09:40:25.927: LDAP: ACL 30 2#entry#[Public]#messageServer
*Oct 28 09:40:25.927: LDAP: ACL 30 2#entry#[Root]#groupMembership
*Oct 28 09:40:25.927: LDAP: ACL 46 6#entry#cn=U1,o=AXX#printJobConfiguration
*Oct 28 09:40:25.927: LDAP: ACL 29 2#entry#[Root]#networkAddress
*Oct 28 09:40:25.927: LDAP: Received a Search Response entryldap_get_dn
*Oct 28 09:40:25.927: LDAP: LDAP: GOT ENTRY: DN => cn=U1,o=AXX
*Oct 28 09:40:25.927: LDAP: Check the default map for aaa type=password
*Oct 28 09:40:25.927: LDAP: Attr-Map:No map for ldap attr(nGWVisibility)
*Oct 28 09:40:25.927: LDAP: Attr-Map:No map for ldap attr(nGWObjectID)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(nGWPostOffice)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(nGWFileID)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(nGWGroupWiseID)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(mail)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(uid)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(givenName)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(Language)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(title)
*Oct 28 09:40:25.931: LDAP: Attr-Map:ldap=telephoneNumber ,aaa=telephone-number
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(sn)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(securityEquals)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(ou)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(eMailAddress)
*Oct 28 09:40:25.931: LDAP: Attr-Map:No map for ldap attr(loginTime)
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Oct 28 09:40:25.935: LDAP: Attr-Map:ldap=cn ,aaa=username
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:40:25.935: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:40:25.935: LDAP: Retrieved an entry from search response
*Oct 28 09:40:25.935: LDAP: Waiting for search result. . .ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x671BE328
ldap_match_request succeeded for msgid 3 h 0
*Oct 28 09:40:25.935: LDAP: LDAP Messages to be processed: 1
*Oct 28 09:40:25.935: LDAP: LDAP Message type: 100
*Oct 28 09:40:25.935: LDAP: Got ldap transaction context from reqid 3
! Oops...another hit to the search:
*Oct 28 09:40:25.935: LDAP: Attribute Length Valueldap_get_dn
*Oct 28 09:40:25.935: LDAP: dn 21 cn=U1,ou=X,o=AXX
*Oct 28 09:40:25.935: LDAP: Check the default map for aaa type=password
*Oct 28 09:40:25.935: LDAP: xTier-LocationList 21 cn=T1,ou=X,o=AXX
*Oct 28 09:40:25.935: LDAP: Language 7 English
*Oct 28 09:40:25.935: LDAP: sn 2 U1
*Oct 28 09:40:25.935: LDAP: passwordRequired 5 FALSE
*Oct 28 09:40:25.939: LDAP: passwordAllowChange 4 TRUE
*Oct 28 09:40:25.939: LDAP: objectClass 13 inetOrgPerson
*Oct 28 09:40:25.939: LDAP: objectClass 20 organizationalPerson
*Oct 28 09:40:25.939: LDAP: objectClass 6 Person
*Oct 28 09:40:25.939: LDAP: objectClass 18 ndsLoginProperties
*Oct 28 09:40:25.939: LDAP: objectClass 3 Top
*Oct 28 09:40:25.939: LDAP: objectClass 15 xTier-Locations
*Oct 28 09:40:25.939: LDAP: loginTime 15 20090121155444Z
*Oct 28 09:40:25.939: LDAP: cn 2 U1
*Oct 28 09:40:25.939: LDAP: ACL 55 2#subtree#cn=U1,ou=X,o=AXX#[All Attributes Rights]
*Oct 28 09:40:25.939: LDAP: ACL 41 6#entry#cn=U1,ou=X,o=AXX#loginScript
*Oct 28 09:40:25.939: LDAP: ACL 30 2#entry#[Public]#messageServer
*Oct 28 09:40:25.939: LDAP: ACL 30 2#entry#[Root]#groupMembership
*Oct 28 09:40:25.939: LDAP: ACL 51 6#entry#cn=U1,ou=X,o=AXX#printJobConfiguration
*Oct 28 09:40:25.939: LDAP: ACL 29 2#entry#[Root]#networkAddress
*Oct 28 09:40:25.939: LDAP: ACL 33 3#entry#[Root]#xTier-LocationList
*Oct 28 09:40:25.939: LDAP: Received a Search Response entry
! IOS documented behavior: in case of receiving multiple user entries an error is reported to AAA and access is not permitted
*Oct 28 09:40:25.939: LDAP: LDAP: More than one entries in search
responseldap_msgfree
*Oct 28 09:40:25.939: LDAP: Closing transaction and reporting error to AAA
*Oct 28 09:40:25.939: LDAP: Transaction context removed from list [ldap reqid=3]
*Oct 28 09:40:25.939: LDAP: Notifying AAA: REQUEST FAILED
*Oct 28 09:40:25.943: LDAP: Received socket event
Now we connect with U2 which has no duplicates :
VPN group name: RNXX-EZVPN
VPN group password: pw1
username: u2
password: u2
*Oct 28 09:47:53.379: LDAP: LDAP: Queuing AAA request 23 for processing
*Oct 28 09:47:53.379: LDAP: Received queue event, new AAA request
*Oct 28 09:47:53.379: LDAP: LDAP authentication request
*Oct 28 09:47:53.379: LDAP: Attempting first next available LDAP server
*Oct 28 09:47:53.379: LDAP: Got next LDAP server :nw650
*Oct 28 09:47:53.379: LDAP: First Task: Send search req
*Oct 28 09:47:53.379: LDAP: Check the default map for aaa type=username
*Oct 28 09:47:53.379: LDAP: Ldap Search Req sent
ld 1730613888
base dn o=AXX
scope 2
filter (&(objectclass=*)(cn=u2))ldap_req_encode
put_filter "(&(objectclass=*)(cn=u2))"
put_filter: AND
put_filter_list "(objectclass=*)(cn=u2)"
put_filter "(objectclass=*)"
put_filter: simple
put_filter "(cn=u2)"
put_filter: simple
Doing socket write
*Oct 28 09:47:53.383: LDAP: LDAP search request sent successfully (reqid:6)
*Oct 28 09:47:53.383: LDAP: Sent the LDAP request to server
*Oct 28 09:47:53.387: LDAP: Received socket event
*Oct 28 09:47:53.387: LDAP: Checking the conn status
*Oct 28 09:47:53.387: LDAP: Socket read event socket=0
*Oct 28 09:47:53.387: LDAP: Found socket ctx
*Oct 28 09:47:53.387: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 28 09:47:53.387: LDAP: Passing the client ctx=67271280ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x671BE328
Doing socket read
LDAP-TCP:Bytes read = 592
ldap_match_request succeeded for msgid 6 h 0
*Oct 28 09:47:53.387: LDAP: LDAP Messages to be processed: 1
*Oct 28 09:47:53.391: LDAP: LDAP Message type: 100
*Oct 28 09:47:53.391: LDAP: Got ldap transaction context from reqid 6
*Oct 28 09:47:53.391: LDAP: Attribute Length Valueldap_get_dn
*Oct 28 09:47:53.391: LDAP: dn 16 cn=U2,o=AXX
*Oct 28 09:47:53.391: LDAP: Check the default map for aaa type=password
*Oct 28 09:47:53.391: LDAP: Language 7 English
*Oct 28 09:47:53.391: LDAP: sn 2 U2
*Oct 28 09:47:53.391: LDAP: securityEquals 16 cn=UG,o=AXX
*Oct 28 09:47:53.391: LDAP: securityEquals 16 cn=G1,o=AXX
*Oct 28 09:47:53.391: LDAP: objectClass 13 inetOrgPerson
*Oct 28 09:47:53.391: LDAP: objectClass 20 organizationalPerson
*Oct 28 09:47:53.391: LDAP: objectClass 6 Person
*Oct 28 09:47:53.391: LDAP: objectClass 18 ndsLoginProperties
*Oct 28 09:47:53.391: LDAP: objectClass 3 Top
*Oct 28 09:47:53.391: LDAP: ndsHomeDirectory 30 cn=NW650_SYS,o=AXX#0#Home
*Oct 28 09:47:53.391: LDAP: groupMembership 16 cn=UG,o=AXX
*Oct 28 09:47:53.391: LDAP: groupMembership 16 cn=G1,o=AXX
*Oct 28 09:47:53.391: LDAP: cn 2 U2
*Oct 28 09:47:53.391: LDAP: ACL 50 2#subtree#cn=U2,o=AXX#[All Attributes Rights]
*Oct 28 09:47:53.391: LDAP: ACL 36 6#entry#cn=U2,o=AXX#loginScript
*Oct 28 09:47:53.391: LDAP: ACL 30 2#entry#[Public]#messageServer
*Oct 28 09:47:53.391: LDAP: ACL 30 2#entry#[Root]#groupMembership
*Oct 28 09:47:53.391: LDAP: ACL 46 6#entry#cn=U2,o=AXX#printJobConfiguration
*Oct 28 09:47:53.391: LDAP: ACL 29 2#entry#[Root]#networkAddress
*Oct 28 09:47:53.391: LDAP: Received a Search Response entryldap_get_dn
*Oct 28 09:47:53.395: LDAP: LDAP: GOT ENTRY: DN => cn=U2,o=AXX
*Oct 28 09:47:53.395: LDAP: Check the default map for aaa type=password
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(Language)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(sn)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(securityEquals)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(securityEquals)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ndsHomeDirectory)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Oct 28 09:47:53.395: LDAP: Attr-Map:ldap=cn ,aaa=username
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:47:53.395: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 28 09:47:53.395: LDAP: Retrieved an entry from search response
*Oct 28 09:47:53.395: LDAP: Waiting for search result. . .ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x671BE328
ldap_match_request succeeded for msgid 6 h 0
changing lr 0x671DA6FC to COMPLETE as no continuations
removing request 0x671DA6FC from list as lm 0x67236FA4 all 0
ldap_msgfree
ldap_msgfree
*Oct 28 09:47:53.399: LDAP: LDAP Messages to be processed: 1
*Oct 28 09:47:53.399: LDAP: LDAP Message type: 101
*Oct 28 09:47:53.399: LDAP: Got ldap transaction context from reqid 6ldap_parse_result
*Oct 28 09:47:53.399: LDAP: resultCode: 0 (Success)
*Oct 28 09:47:53.399: LDAP: Received Search Response resultldap_parse_result
*Oct 28 09:47:53.399: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 28 09:47:53.399: LDAP: * LDAP SEARCH DONE *
*Oct 28 09:47:53.399: LDAP: Next Task: Send bind req
*Oct 28 09:47:53.399: LDAP: Transaction context removed from list [ldap reqid=6]
*Oct 28 09:47:53.399: LDAP: Bind: User-DN=cn=U2,o=AXXldap_req_encode
Doing socket write
*Oct 28 09:47:53.399: LDAP: LDAP bind request sent successfully (reqid=7)ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 28 09:47:53.403: LDAP: Finished processing ldap msg, Result:Success
*Oct 28 09:47:53.403: LDAP: Received socket event
*Oct 28 09:47:53.403: LDAP: Checking the conn status
*Oct 28 09:47:53.403: LDAP: Socket read event socket=0
*Oct 28 09:47:53.403: LDAP: Found socket ctx
*Oct 28 09:47:53.403: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 28 09:47:53.403: LDAP: Passing the client ctx=67271280ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x671BE328
Doing socket read
LDAP-TCP:Bytes read = 14
ldap_match_request succeeded for msgid 7 h 0
changing lr 0x671DA6FC to COMPLETE as no continuations
removing request 0x671DA6FC from list as lm 0x67236FA4 all 0
ldap_msgfree
ldap_msgfree
*Oct 28 09:47:53.407: LDAP: LDAP Messages to be processed: 1
*Oct 28 09:47:53.407: LDAP: LDAP Message type: 97
*Oct 28 09:47:53.407: LDAP: Got ldap transaction context from reqid 7ldap_parse_result
*Oct 28 09:47:53.407: LDAP: resultCode: 0 (Success)
*Oct 28 09:47:53.407: LDAP: Received Bind Responseldap_parse_result
*Oct 28 09:47:53.407: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 28 09:47:53.407: LDAP: LDAP Bind successful for DN:cn=U2,o=AXX
*Oct 28 09:47:53.407: LDAP: * LDAP PASSWORD VERIFY DONE *
*Oct 28 09:47:53.407: LDAP: Next Task: All authentication task completed
*Oct 28 09:47:53.407: LDAP: Transaction context removed from list [ldap reqid=7]
*Oct 28 09:47:53.407: LDAP: * * AUTHENTICATION COMPLETED SUCCESSFULLY * *
*Oct 28 09:47:53.407: LDAP: Notifying AAA: REQUEST SUCCESSldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 28 09:47:53.407: LDAP: Finished processing ldap msg, Result:Success
*Oct 28 09:47:53.411: LDAP: Received socket event
*Oct 28 09:47:53.551: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down
*Oct 28 09:48:03.419: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
VPN Connection succeeded.
Now we narrow the search to the object type User (User and Person are both accepted in Novell eDirectory)
ldap server nw650
search-filter user-object-type User
do clear ldap server nw650
Router resets the connection and rebinds:
Router_NXX(config-ldap-server)#
*Oct 28 14:09:51.590: LDAP: Received timer event
*Oct 28 14:09:51.590: LDAP: Connection timeout occured. Retrying
*Oct 28 14:09:51.590: LDAP: Opening ldap connection ( 10.55.5.223, 389 )ldap_open
ldap_init libldap 4.5 18-FEB-2000
open_ldap_connection
ldap_connect_to_host: 10.55.5.223:389
*Oct 28 14:09:51.590: LDAP: socket 0 - connecting to 10.55.5.223 (389)
*Oct 28 14:09:51.590: LDAP: socket 0 - connection in progress
*Oct 28 14:09:51.590: LDAP: socket 0 - local address 10.55.5.150 (14746)
*Oct 28 14:09:51.590: LDAP: Connection on socket 0
*Oct 28 14:09:51.590: LDAP: Connection to LDAP server (nw650, 10.55.5.223) attempted
*Oct 28 14:09:51.590: LDAP: Connection state: DOWN => CONNECTING
*Oct 28 14:09:51.594: LDAP: Received socket event
*Oct 28 14:09:51.594: LDAP: Checking the conn status
*Oct 28 14:09:51.594: LDAP: Socket read event socket=0
*Oct 28 14:09:51.594: LDAP: Found socket ctx
*Oct 28 14:09:51.594: LDAP: Making socket conn up
*Oct 28 14:09:51.594: LDAP: Notify the protocol codeldap_open successful
Notify LDAP main if it has to initiate any bind requests
*Oct 28 14:09:51.594: LDAP: Protocol received transport up notication
*Oct 28 14:09:51.594: LDAP: Connection state: CONNECTING => UP
*Oct 28 14:09:51.594: LDAP: Set socket=0 to non blocking mode
*Oct 28 14:09:51.594: LDAP: Performing Root-Dn bind operationldap_req_encode
Doing socket write
*Oct 28 14:09:51.594: LDAP: Root Bind on cn=admin,o=AXX initiated.
*Oct 28 14:09:51.598: LDAP: Received socket event
*Oct 28 14:09:51.598: LDAP: Checking the conn status
*Oct 28 14:09:51.598: LDAP: Socket read event socket=0
*Oct 28 14:09:51.598: LDAP: Found socket ctx
*Oct 28 14:09:51.598: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 28 14:09:51.598: LDAP: Passing the client ctx=67271280ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x671BE328
Doing socket read
LDAP-TCP:Bytes read = 14
ldap_match_request succeeded for msgid 1 h 0
changing lr 0x673F3DE8 to COMPLETE as no continuations
removing request 0x673F3DE8 from list as lm 0x67235F64 all 0
ldap_msgfree
ldap_msgfree
*Oct 28 14:09:51.602: LDAP: LDAP Messages to be processed: 1
*Oct 28 14:09:51.602: LDAP: LDAP Message type: 97
*Oct 28 14:09:51.602: LDAP: Got ldap transaction context from reqid 25ldap_parse_result
*Oct 28 14:09:51.602: LDAP: resultCode: 0 (Success)
*Oct 28 14:09:51.602: LDAP: Received Bind Response
*Oct 28 14:09:51.602: LDAP: Received Root Bind Response ldap_parse_result
*Oct 28 14:09:51.602: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 28 14:09:51.602: LDAP: Root DN bind Successful on :cn=admin,o=AXX
*Oct 28 14:09:51.602: LDAP: Transaction context removed from list [ldap reqid=25]ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 28 14:09:51.602: LDAP: Finished processing ldap msg, Result:Success
*Oct 28 14:09:51.602: LDAP: Received socket event
However, this is not enough. For the search filter to make effect, I had to re-enter part of the config:
no ldap server nw650
ldap server nw650
ipv4 10.55.5.223
!transport port 389
bind authenticate root-dn cn=admin,o=AXX password xxxxx
base-dn o=AXX
search-filter user-object-type User
Now the search filter contains the desired object class:
*Oct 28 14:48:44.106: LDAP: Ldap Search Req sent
ld 1730612236
base dn o=AXX
scope 2
filter (&(objectclass=User)(cn=u2))ldap_req_encode
put_filter "(&(objectclass=User)(cn=u2))"
put_filter: AND
put_filter_list "(objectclass=User)(cn=u2)"
put_filter "(objectclass=User)"
put_filter: simple
put_filter "(cn=u2)"
put_filter: simple
Doing socket write
So you can influence that field in the search with the search-filter user-object-type command and the username (u2) after cn= comes from the VPN client. Without filtering to User types the server might return any kind of object matching the username.
Now let’s deal with the group information. We’d like to allow only a certain group to connect. We can make use of an LDAP attribute map which maps LDAP attributes to Cisco AAA attribute. LDAP attributes are listed in the directory (and printed in the debug logs) but Cisco attributes are hardly documented. The best you can do is type a ‘?’ in CLI:
Router_NXX(config-attr-map)#map type groupMembership ? and so on…be ready to page and scan it many times until you find a good-looking one (I have it saved it into a text file).
aaa-authenticator
AAA authenticator
access-restrict
VPN group access
account-code
Account code input from telephony call leg
account-delay
Accounting delay start
account-send-stop
Send accounting information even with failure
account-send-success-remote
Send accounting for remote authenticated users
accounting-list
Subscriber accounting method-list
acct-delay-time
Accounting record delay time
Finally I found a group-lock and a user-vpn-group attribute.
1st try: map groupMembership attribute to cisco group-lock attribute. No luck.
2nd try: map groupMembership attribute to cisco user-vpn-group AAA attribute. We have luck.
ldap attribute-map map1
map type groupMembership user-vpn-group
ldap server nw650
attribute map map1
You don’t need a group-lock command as the user-vpn-group attribute is always enforced:
Router_NXX#debug aaa subsys
Router_NXX#debug aaa authentication
Router_NXX#debug aaa authorization
Router_NXX#debug crypto isakmp aaa
Connect with VPN client:
VPN group name: RNXX-EZVPN
VPN group password: pw1
username: u2
password: u2
*Oct 29 09:33:20.471: AAA/AUTHOR: auth_need : user= 'userloc' ruser= 'Router_NXX'rem_addr= '10.127.0.101' priv= 15 list= '' AUTHOR-TYPE= 'command'
*Oct 29 09:33:28.351: ISAKMP AAA: NAS Port Id is set to 10.55.5.150
*Oct 29 09:33:28.351: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Oct 29 09:33:28.351: AAA/BIND(00000015): Bind i/f
*Oct 29 09:33:28.351: ISAKMP/aaa: unique id = 21
*Oct 29 09:33:28.423: ISAKMP:(0):ISAKMP/tunnel: setting up tunnel RNXX-EZVPN pw request
*Oct 29 09:33:28.427: AAA/AUTHOR (0x15): Pick method list 'loc-author'
*Oct 29 09:33:28.427: ISAKMP:(0):ISAKMP/tunnel: Tunnel RNXX-EZVPN PW Request successfully sent to AAA
*Oct 29 09:33:28.427: AAA SRV(00000015): process author req
*Oct 29 09:33:28.427: AAA SRV(00000015): Author method=LOCAL
*Oct 29 09:33:28.427: AAA SRV(00000015): protocol reply PASS for Authorization
*Oct 29 09:33:28.427: AAA SRV(00000015): Return Authorization status=PASS
*Oct 29 09:33:28.427: ISAKMP:(0):ISAKMP/tunnel: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV addr-pool
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
AAA/AUTHOR/IKE: Processing AV wins-servers
AAA/AUTHOR/IKE: Processing AV banner
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Oct 29 09:33:28.427: ISAKMP/tunnel: received tunnel atts
*Oct 29 09:33:28.463: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Oct 29 09:33:28.463: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Oct 29 09:33:28.463: AAA/BIND(00000016): Bind i/f
*Oct 29 09:33:28.463: ISAKMP AAA: Accounting is not enabled
*Oct 29 09:33:30.151: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Oct 29 09:33:30.151: ISAKMP:(1004):AAA Authen: setting up authen_request
*Oct 29 09:33:30.151: AAA/AUTHEN/LOGIN (00000016): Pick method list 'eDir'
*Oct 29 09:33:30.155: ISAKMP:(1004):AAA Authen: Successfully sent authen info to AAA
*Oct 29 09:33:30.155: AAA SRV(00000016): process authen req
*Oct 29 09:33:30.155: AAA SRV(00000016): Authen method=SERVER_GROUP Novell
*Oct 29 09:33:30.155: LDAP: LDAP: Queuing AAA request 22 for processing
*Oct 29 09:33:30.155: LDAP: Received queue event, new AAA request
*Oct 29 09:33:30.155: LDAP: LDAP authentication request
*Oct 29 09:33:30.155: LDAP: Attempting first next available LDAP server
*Oct 29 09:33:30.155: LDAP: Got next LDAP server :nw650
*Oct 29 09:33:30.155: LDAP: First Task: Send search req
*Oct 29 09:33:30.155: LDAP: Dynamic map configured
*Oct 29 09:33:30.155: LDAP: Check the default map for aaa type=username
*Oct 29 09:33:30.155: LDAP: Ldap Search Req sent
ld 1730970084
base dn o=AXX
scope 2
filter (&(objectclass=User)(cn=u2))ldap_req_encode
put_filter "(&(objectclass=User)(cn=u2))"
put_filter: AND
put_filter_list "(objectclass=User)(cn=u2)"
put_filter "(objectclass=User)"
put_filter: simple
put_filter "(cn=u2)"
put_filter: simple
Doing socket write
*Oct 29 09:33:30.159: LDAP: LDAP search request sent successfully (reqid:8)
*Oct 29 09:33:30.159: LDAP: Sent the LDAP request to server
*Oct 29 09:33:30.163: LDAP: Received socket event
*Oct 29 09:33:30.163: LDAP: Checking the conn status
*Oct 29 09:33:30.163: LDAP: Socket read event socket=0
*Oct 29 09:33:30.163: LDAP: Found socket ctx
*Oct 29 09:33:30.163: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 29 09:33:30.163: LDAP: Passing the client ctx=672C81E4ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x6712243C
Doing socket read
LDAP-TCP:Bytes read = 624
ldap_match_request succeeded for msgid 8 h 0
*Oct 29 09:33:30.167: LDAP: LDAP Messages to be processed: 1
*Oct 29 09:33:30.167: LDAP: LDAP Message type: 100
*Oct 29 09:33:30.167: LDAP: Got ldap transaction context from reqid 8
*Oct 29 09:33:30.167: LDAP: Attribute Length Valueldap_get_dn
*Oct 29 09:33:30.167: LDAP: dn 16 cn=U2,o=AXX
*Oct 29 09:33:30.167: LDAP: Dynamic map configured
*Oct 29 09:33:30.167: LDAP: Check the default map for aaa type=password
*Oct 29 09:33:30.167: LDAP: Language 7 English
*Oct 29 09:33:30.167: LDAP: sn 2 U2
*Oct 29 09:33:30.167: LDAP: securityEquals 16 cn=UG,o=AXX
*Oct 29 09:33:30.167: LDAP: securityEquals 16 cn=G1,o=AXX
*Oct 29 09:33:30.167: LDAP: objectClass 13 inetOrgPerson
*Oct 29 09:33:30.167: LDAP: objectClass 20 organizationalPerson
*Oct 29 09:33:30.167: LDAP: objectClass 6 Person
*Oct 29 09:33:30.167: LDAP: objectClass 18 ndsLoginProperties
*Oct 29 09:33:30.167: LDAP: objectClass 3 Top
*Oct 29 09:33:30.167: LDAP: loginTime 15 20101029082745Z
*Oct 29 09:33:30.167: LDAP: ndsHomeDirectory 30 cn=NW650_SYS,o=AXX#0#Home
*Oct 29 09:33:30.167: LDAP: groupMembership 16 cn=UG,o=AXX
*Oct 29 09:33:30.167: LDAP: groupMembership 16 cn=G1,o=AXX
*Oct 29 09:33:30.167: LDAP: cn 2 U2
*Oct 29 09:33:30.167: LDAP: ACL 50 2#subtree#cn=U2,o=AXX#[All Attributes Rights]
*Oct 29 09:33:30.167: LDAP: ACL 36 6#entry#cn=U2,o=AXX#loginScript
*Oct 29 09:33:30.167: LDAP: ACL 30 2#entry#[Public]#messageServer
*Oct 29 09:33:30.167: LDAP: ACL 30 2#entry#[Root]#groupMembership
*Oct 29 09:33:30.167: LDAP: ACL 46 6#entry#cn=U2,o=AXX#printJobConfiguration
*Oct 29 09:33:30.171: LDAP: ACL 29 2#entry#[Root]#networkAddress
*Oct 29 09:33:30.171: LDAP: Received a Search Response entryldap_get_dn
*Oct 29 09:33:30.171: LDAP: LDAP: GOT ENTRY: DN => cn=U2,o=AXX
*Oct 29 09:33:30.171: LDAP: Dynamic map configured
*Oct 29 09:33:30.171: LDAP: Check the default map for aaa type=password
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(Language)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(sn)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(securityEquals)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(securityEquals)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(loginTime)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(ndsHomeDirectory)
! our attribute map works:
*Oct 29 09:33:30.171: LDAP: Attr-Map:ldap=groupMembership ,aaa=user-vpn-group
*Oct 29 09:33:30.171: LDAP: Attr-Map:ldap=groupMembership ,aaa=user-vpn-group
! there are default attribute mappings as well, check with the sh ldap attributes command
*Oct 29 09:33:30.171: LDAP: Attr-Map:ldap=cn ,aaa=username
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 09:33:30.171: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 09:33:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 09:33:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 09:33:30.175: LDAP: Retrieved an entry from search response
*Oct 29 09:33:30.175: LDAP: Waiting for search result. . .ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x6712243C
ldap_match_request succeeded for msgid 8 h 0
changing lr 0x670B9A84 to COMPLETE as no continuations
removing request 0x670B9A84 from list as lm 0x67248478 all 0
ldap_msgfree
ldap_msgfree
*Oct 29 09:33:30.175: LDAP: LDAP Messages to be processed: 1
*Oct 29 09:33:30.175: LDAP: LDAP Message type: 101
*Oct 29 09:33:30.175: LDAP: Got ldap transaction context from reqid 8ldap_parse_result
*Oct 29 09:33:30.175: LDAP: resultCode: 0 (Success)
*Oct 29 09:33:30.175: LDAP: Received Search Response resultldap_parse_result
*Oct 29 09:33:30.175: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 29 09:33:30.175: LDAP: * LDAP SEARCH DONE *
*Oct 29 09:33:30.175: LDAP: Next Task: Send bind req
*Oct 29 09:33:30.175: LDAP: Transaction context removed from list [ldap reqid=8]
*Oct 29 09:33:30.175: LDAP: Bind: User-DN=cn=U2,o=AXXldap_req_encode
Doing socket write
*Oct 29 09:33:30.179: LDAP: LDAP bind request sent successfully (reqid=9)ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 29 09:33:30.179: LDAP: Finished processing ldap msg, Result:Success
*Oct 29 09:33:30.179: LDAP: Received socket event
*Oct 29 09:33:30.179: LDAP: Checking the conn status
*Oct 29 09:33:30.179: LDAP: Socket read event socket=0
*Oct 29 09:33:30.179: LDAP: Found socket ctx
*Oct 29 09:33:30.179: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 29 09:33:30.179: LDAP: Passing the client ctx=672C81E4ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x6712243C
Doing socket read
LDAP-TCP:Bytes read = 14
ldap_match_request succeeded for msgid 9 h 0
changing lr 0x670B9A84 to COMPLETE as no continuations
removing request 0x670B9A84 from list as lm 0x67248478 all 0
ldap_msgfree
ldap_msgfree
*Oct 29 09:33:30.183: LDAP: LDAP Messages to be processed: 1
*Oct 29 09:33:30.183: LDAP: LDAP Message type: 97
*Oct 29 09:33:30.183: LDAP: Got ldap transaction context from reqid 9ldap_parse_result
*Oct 29 09:33:30.183: LDAP: resultCode: 0 (Success)
*Oct 29 09:33:30.183: LDAP: Received Bind Responseldap_parse_result
*Oct 29 09:33:30.183: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 29 09:33:30.183: LDAP: LDAP Bind successful for DN:cn=U2,o=AXX
*Oct 29 09:33:30.183: LDAP: * LDAP PASSWORD VERIFY DONE *
*Oct 29 09:33:30.183: LDAP: Next Task: All authentication task completed
*Oct 29 09:33:30.183: LDAP: Transaction context removed from list [ldap reqid=9]
*Oct 29 09:33:30.183: LDAP: * * AUTHENTICATION COMPLETED SUCCESSFULLY * *
*Oct 29 09:33:30.183: LDAP: Notifying AAA: REQUEST SUCCESS
*Oct 29 09:33:30.183: AAA SRV(00000016): protocol reply PASS for Authentication
*Oct 29 09:33:30.183: AAA SRV(00000016): Return Authentication status=PASSldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 29 09:33:30.183: LDAP: Finished processing ldap msg, Result:Success
AAA/AUTHOR/IKE: Processing AV user-vpn-group
AAA/AUTHOR/IKE: Processing AV user-vpn-group
*Oct 29 09:33:30.187:
AAA/AUTHOR/IKE: User group cn=UG,o=AXX does not match VPN group RNXX-EZVPN - access denied
*Oct 29 09:33:30.187: ISAKMP:(1004):AAA Authen: Received atts but denied access
*Oct 29 09:33:30.187: LDAP: Received socket event
The group check works. Unfortunately, the tests show that only the first returned group attribute is considered. The VPN client cannot connect with the other group (cn=G1,o=AXX) which makes the feature effectively unusable. After all, in most companies there are a bunch of other groups apart from the VPN group and noone can assure that VPN is always the first in the order. Apparently, we could pick up a rarely used attribute (e. g. seeAlso) and use it as a VPN flag. The problem is, the router allows any user without that attribute to connect. So it seems you will need a mandatory attribute added to everyone and should you forget to set it up on some user, you will open VPN access to him or her.
crypto isakmp client configuration group cn=G1,o=AXX
key pw1
domain nxx.hu
pool RNXX_Loopback1
acl EZsplit
netmask 255.255.255.0
ldap attribute-map map1
map type seeAlso user-vpn-group
*Oct 29 13:25:26.199: ISAKMP AAA: NAS Port Id is set to 10.55.5.150
*Oct 29 13:25:26.203: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Oct 29 13:25:26.203: AAA/BIND(00000013): Bind i/f
*Oct 29 13:25:26.203: ISAKMP/aaa: unique id = 19
*Oct 29 13:25:26.275: ISAKMP:(0):ISAKMP/tunnel: setting up tunnel cn=VPN,o=NXXI pw request
*Oct 29 13:25:26.275: ISAKMP:(0):ISAKMP/tunnel: Tunnel cn=VPN,o=NXXI PW Request successfully sent to AAA
*Oct 29 13:25:26.275: AAA SRV(00000013): process author req
*Oct 29 13:25:26.275: AAA SRV(00000013): Author method=LOCAL
*Oct 29 13:25:26.279: AAA SRV(00000013): protocol reply PASS for Authorization
*Oct 29 13:25:26.279: AAA SRV(00000013): Return Authorization status=PASS
*Oct 29 13:25:26.279: ISAKMP:(0):ISAKMP/tunnel: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV addr-pool
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
AAA/AUTHOR/IKE: Processing AV wins-servers
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Oct 29 13:25:26.279: ISAKMP/tunnel: received tunnel atts
*Oct 29 13:25:26.427: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Oct 29 13:25:26.427: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Oct 29 13:25:26.427: AAA/BIND(00000014): Bind i/f
*Oct 29 13:25:26.431: ISAKMP AAA: Accounting is not enabled
*Oct 29 13:25:30.155: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Oct 29 13:25:30.155: ISAKMP:(1004):AAA Authen: setting up authen_request
*Oct 29 13:25:30.155: AAA/AUTHEN/LOGIN (00000014): Pick method list 'eDir'
*Oct 29 13:25:30.155: ISAKMP:(1004):AAA Authen: Successfully sent authen info to AAA
*Oct 29 13:25:30.155: AAA SRV(00000014): process authen req
*Oct 29 13:25:30.155: AAA SRV(00000014): Authen method=SERVER_GROUP Novell
*Oct 29 13:25:30.155: LDAP: LDAP: Queuing AAA request 20 for processing
*Oct 29 13:25:30.155: LDAP: Received queue event, new AAA request
*Oct 29 13:25:30.155: LDAP: LDAP authentication request
*Oct 29 13:25:30.159: LDAP: Attempting first next available LDAP server
*Oct 29 13:25:30.159: LDAP: Got next LDAP server :nw650
*Oct 29 13:25:30.159: LDAP: First Task: Send search req
*Oct 29 13:25:30.159: LDAP: Dynamic map configured
*Oct 29 13:25:30.159: LDAP: Check the default map for aaa type=username
*Oct 29 13:25:30.159: LDAP: Ldap Search Req sent
ld 1730580372
base dn o=NXXI
scope 2
filter (&(objectclass=Person)(cn=u2))ldap_req_encode
put_filter "(&(objectclass=Person)(cn=u2))"
put_filter: AND
put_filter_list "(objectclass=Person)(cn=u2)"
put_filter "(objectclass=Person)"
put_filter: simple
put_filter "(cn=u2)"
put_filter: simple
Doing socket write
*Oct 29 13:25:30.159: LDAP: LDAP search request sent successfully (reqid:7)
*Oct 29 13:25:30.159: LDAP: Sent the LDAP request to server
*Oct 29 13:25:30.167: LDAP: Received socket event
*Oct 29 13:25:30.167: LDAP: Checking the conn status
*Oct 29 13:25:30.167: LDAP: Socket read event socket=0
*Oct 29 13:25:30.167: LDAP: Found socket ctx
*Oct 29 13:25:30.167: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 29 13:25:30.167: LDAP: Passing the client ctx=67268F94ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x67175AE8
Doing socket read
LDAP-TCP:Bytes read = 521
ldap_match_request succeeded for msgid 2 h 0
*Oct 29 13:25:30.167: LDAP: LDAP Messages to be processed: 1
*Oct 29 13:25:30.167: LDAP: LDAP Message type: 100
*Oct 29 13:25:30.167: LDAP: Got ldap transaction context from reqid 7
*Oct 29 13:25:30.167: LDAP: Attribute Length Valueldap_get_dn
*Oct 29 13:25:30.167: LDAP: dn 12 cn=U2,o=NXXI
*Oct 29 13:25:30.167: LDAP: Dynamic map configured
*Oct 29 13:25:30.167: LDAP: Check the default map for aaa type=password
*Oct 29 13:25:30.167: LDAP: uid 2 U2
*Oct 29 13:25:30.167: LDAP: Language 7 ENGLISH
*Oct 29 13:25:30.167: LDAP: sn 2 U2
*Oct 29 13:25:30.167: LDAP: seeAlso 13 cn=VPN,o=NXXI
*Oct 29 13:25:30.167: LDAP: securityEquals 13 cn=VPN,o=NXXI
*Oct 29 13:25:30.171: LDAP: objectClass 13 inetOrgPerson
*Oct 29 13:25:30.171: LDAP: objectClass 20 organizationalPerson
*Oct 29 13:25:30.171: LDAP: objectClass 6 Person
*Oct 29 13:25:30.171: LDAP: objectClass 18 ndsLoginProperties
*Oct 29 13:25:30.171: LDAP: objectClass 3 Top
*Oct 29 13:25:30.171: LDAP: groupMembership 13 cn=VPN,o=NXXI
*Oct 29 13:25:30.171: LDAP: cn 2 U2
*Oct 29 13:25:30.171: LDAP: ACL 46 2#subtree#cn=U2,o=NXXI#[All Attributes Rights]
*Oct 29 13:25:30.171: LDAP: ACL 32 6#entry#cn=U2,o=NXXI#loginScript
*Oct 29 13:25:30.171: LDAP: ACL 30 2#entry#[Public]#messageServer
*Oct 29 13:25:30.171: LDAP: ACL 30 2#entry#[Root]#groupMembership
*Oct 29 13:25:30.171: LDAP: ACL 42 6#entry#cn=U2,o=NXXI#printJobConfiguration
*Oct 29 13:25:30.171: LDAP: ACL 29 2#entry#[Root]#networkAddress
*Oct 29 13:25:30.171: LDAP: Received a Search Response entryldap_get_dn
*Oct 29 13:25:30.171: LDAP: LDAP: GOT ENTRY: DN => cn=U2,o=NXXI
*Oct 29 13:25:30.171: LDAP: Dynamic map configured
*Oct 29 13:25:30.171: LDAP: Check the default map for aaa type=password
*Oct 29 13:25:30.171: LDAP: Attr-Map:No map for ldap attr(uid)
*Oct 29 13:25:30.171: LDAP: Attr-Map:No map for ldap attr(Language)
*Oct 29 13:25:30.171: LDAP: Attr-Map:No map for ldap attr(sn)
*Oct 29 13:25:30.171: LDAP: Attr-Map:ldap=seeAlso ,aaa=user-vpn-group
*Oct 29 13:25:30.171: LDAP: Attr-Map:No map for ldap attr(securityEquals)
*Oct 29 13:25:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 13:25:30.171: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Oct 29 13:25:30.175: LDAP: Attr-Map:ldap=cn ,aaa=username
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 13:25:30.175: LDAP: Attr-Map:No map for ldap attr(ACL)
*Oct 29 13:25:30.175: LDAP: Retrieved an entry from search response
*Oct 29 13:25:30.175: LDAP: Waiting for search result. . .ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x67175AE8
ldap_match_request succeeded for msgid 2 h 0
changing lr 0x67210948 to COMPLETE as no continuations
removing request 0x67210948 from list as lm 0x6724D330 all 0
ldap_msgfree
ldap_msgfree
*Oct 29 13:25:30.175: LDAP: LDAP Messages to be processed: 1
*Oct 29 13:25:30.175: LDAP: LDAP Message type: 101
*Oct 29 13:25:30.175: LDAP: Got ldap transaction context from reqid 7ldap_parse_result
*Oct 29 13:25:30.175: LDAP: resultCode: 0 (Success)
*Oct 29 13:25:30.175: LDAP: Received Search Response resultldap_parse_result
*Oct 29 13:25:30.175: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 29 13:25:30.175: LDAP: * LDAP SEARCH DONE *
*Oct 29 13:25:30.179: LDAP: Next Task: Send bind req
*Oct 29 13:25:30.179: LDAP: Transaction context removed from list [ldap reqid=7]
*Oct 29 13:25:30.179: LDAP: Bind: User-DN=cn=U2,o=NXXIldap_req_encode
Doing socket write
*Oct 29 13:25:30.179: LDAP: LDAP bind request sent successfully (reqid=8)ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 29 13:25:30.179: LDAP: Finished processing ldap msg, Result:Success
*Oct 29 13:25:30.183: LDAP: Received socket event
*Oct 29 13:25:30.183: LDAP: Checking the conn status
*Oct 29 13:25:30.183: LDAP: Socket read event socket=0
*Oct 29 13:25:30.183: LDAP: Found socket ctx
*Oct 29 13:25:30.183: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Oct 29 13:25:30.183: LDAP: Passing the client ctx=67268F94ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x67175AE8
Doing socket read
LDAP-TCP:Bytes read = 14
ldap_match_request succeeded for msgid 3 h 0
changing lr 0x67210948 to COMPLETE as no continuations
removing request 0x67210948 from list as lm 0x6724D330 all 0
ldap_msgfree
ldap_msgfree
*Oct 29 13:25:30.183: LDAP: LDAP Messages to be processed: 1
*Oct 29 13:25:30.183: LDAP: LDAP Message type: 97
*Oct 29 13:25:30.183: LDAP: Got ldap transaction context from reqid 8ldap_parse_result
*Oct 29 13:25:30.183: LDAP: resultCode: 0 (Success)
*Oct 29 13:25:30.183: LDAP: Received Bind Responseldap_parse_result
*Oct 29 13:25:30.183: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Oct 29 13:25:30.183: LDAP: LDAP Bind successful for DN:cn=U2,o=NXXI
*Oct 29 13:25:30.183: LDAP: * LDAP PASSWORD VERIFY DONE *
*Oct 29 13:25:30.183: LDAP: Next Task: All authentication task completed
*Oct 29 13:25:30.183: LDAP: Transaction context removed from list [ldap reqid=8]
*Oct 29 13:25:30.183: LDAP: * * AUTHENTICATION COMPLETED SUCCESSFULLY * *
*Oct 29 13:25:30.187: LDAP: Notifying AAA: REQUEST SUCCESS
*Oct 29 13:25:30.187: AAA SRV(00000014): protocol reply PASS for Authentication
*Oct 29 13:25:30.187: AAA SRV(00000014): Return Authentication status=PASSldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Oct 29 13:25:30.187: LDAP: Finished processing ldap msg, Result:Success
AAA/AUTHOR/IKE: Processing AV user-vpn-group
*Oct 29 13:25:30.187: ISAKMP:(1004):ISAKMP/author: No Class attributes
*Oct 29 13:25:30.187: ISAKMP:(1004):AAA Authen: No group atts added
*Oct 29 13:25:30.187: ISAKMP:(1004):AAA Authen: Set accounting session id 0xA
*Oct 29 13:25:30.187: LDAP: Received socket event
*Oct 29 13:25:30.291: ISAKMP:(1004):ISAKMP/author: setting up the authorization request for cn=VPN,o=NXXI
*Oct 29 13:25:30.295: AAA SRV(00000014): process author req
*Oct 29 13:25:30.295: AAA SRV(00000014): Author method=LOCAL
*Oct 29 13:25:30.295: AAA SRV(00000014): protocol reply PASS for Authorization
*Oct 29 13:25:30.295: AAA SRV(00000014): Return Authorization status=PASS
*Oct 29 13:25:30.295: ISAKMP:(0):ISAKMP/author: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV addr-pool
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
*Oct 29 13:25:30.295:
AAA/AUTHOR/IKE: no DNS addresses
AAA/AUTHOR/IKE: Processing AV wins-servers
*Oct 29 13:25:30.295:
AAA/AUTHOR/IKE: no WINS addresses
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Oct 29 13:25:30.295: ISAKMP:(1004):ISAKMP/author: No Class attributes
*Oct 29 13:25:30.359: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down
Router_NXX#
Router_NXX#
Router_NXX#
Router_NXX#
Router_NXX#
*Oct 29 13:25:40.211: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
Router_NXX#
Router_NXX#
Router_NXX#
Router_NXX#
Router_NXX#sh crypto session detail
Crypto session current status
Code: C - IKE Configuration mode, D - Dead Peer Detection
K - Keepalives, N - NAT-traversal, T - cTCP encapsulation
X - IKE Extended Authentication, F - IKE Fragmentation
Interface: Virtual-Access2
Username: u2
Profile: EZVPN
Group: cn=VPN,o=NXXI
Assigned address: 192.168.102.11
Uptime: 00:02:06
Session status: UP-ACTIVE
Peer: 10.127.0.101 port 2502 fvrf: (none) ivrf: (none)
Phase1_id: cn=VPN,o=NXXI
Desc: (none)
IKEv1 SA: local 10.55.5.150/500 remote 10.127.0.101/2502 Active
Capabilities:CX connid:1004 lifetime:23:57:49
IPSEC FLOW: permit ip 0.0.0.0/0.0.0.0 host 192.168.102.11
Active SAs: 2, origin: crypto map
Inbound: #pkts dec'ed 0 drop 0 life (KB/Sec) 4416154/3473
Outbound: #pkts enc'ed 0 drop 0 life (KB/Sec) 4416154/3473
UPDATE:
A better appoach is to obtain the address-pool name from LDAP as Cisco TAC suggested to me. A client won’t be able to connect without assigning a valid IP address as the pool statement is removed from the VPN group config. A new vpnAddressPool attribute is intruduced in the directory for VPN users. We define a pool called VALIDpool on the router and a user can only connect if his/her attribute value matches that:
crypto isakmp client configuration group
cn=VPN,o=NXXI
key pw1
domain nxx.hu
acl EZsplit
netmask 255.255.255.0
ldap attribute-map mapvpn
map type vpnAddressPool addr-pool
ldap server nw650
attribute map mapvpn
ip local pool VALIDpool 192.168.102.31 192.168.102.39
*Dec 6 15:22:45.427: ISAKMP (0): received packet from 10.55.5.19 dport 500 sport 2299 Global (N) NEW SA
*Dec 6 15:22:45.427: ISAKMP: Created a peer struct for 10.55.5.19, peer port 2299
*Dec 6 15:22:45.427: ISAKMP: New peer created peer = 0x67195BFC peer_handle = 0x8000000F
*Dec 6 15:22:45.431: ISAKMP: Locking peer struct 0x67195BFC, refcount 1 for crypto_isakmp_process_block
*Dec 6 15:22:45.431: ISAKMP: local port 500, remote port 2299
*Dec 6 15:22:45.431: ISAKMP:(0):insert sa successfully sa = 6733EA68
*Dec 6 15:22:45.431: ISAKMP:(0): processing SA payload. message ID = 0
*Dec 6 15:22:45.431: ISAKMP:(0): processing ID payload. message ID = 0
*Dec 6 15:22:45.431: ISAKMP (0): ID payload
next-payload : 13
type : 11
group id : cn=VPN,o=NXXI
protocol : 17
port : 500
length : 21
*Dec 6 15:22:45.431: ISAKMP:(0):: peer matches EZVPN profile
*Dec 6 15:22:45.431: ISAKMP:(0):Setting client config settings 67280640
*Dec 6 15:22:45.431: ISAKMP:(0):(Re)Setting client xauth list and state
*Dec 6 15:22:45.431: ISAKMP/xauth: initializing AAA request
*Dec 6 15:22:45.431: ISAKMP AAA: NAS Port Id is set to 10.55.5.150
*Dec 6 15:22:45.431: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Dec 6 15:22:45.431: ISAKMP/aaa: unique id = 35
*Dec 6 15:22:45.431: ISAKMP:(0): processing vendor id payload
*Dec 6 15:22:45.431: ISAKMP:(0): vendor ID seems Unity/DPD but major 215 mismatch
*Dec 6 15:22:45.431: ISAKMP:(0): vendor ID is XAUTH
*Dec 6 15:22:45.431: ISAKMP:(0): processing vendor id payload
*Dec 6 15:22:45.435: ISAKMP:(0): vendor ID is DPD
*Dec 6 15:22:45.435: ISAKMP:(0): processing vendor id payload
*Dec 6 15:22:45.435: ISAKMP:(0): processing IKE frag vendor id payload
*Dec 6 15:22:45.435: ISAKMP:(0):Support for IKE Fragmentation not enabled
*Dec 6 15:22:45.435: ISAKMP:(0): processing vendor id payload
*Dec 6 15:22:45.435: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
*Dec 6 15:22:45.435: ISAKMP:(0): vendor ID is NAT-T v2
*Dec 6 15:22:45.435: ISAKMP:(0): processing vendor id payload
*Dec 6 15:22:45.435: ISAKMP:(0): vendor ID is Unity
*Dec 6 15:22:45.435: ISAKMP:(0): Authentication by xauth preshared
*Dec 6 15:22:45.435: ISAKMP:(0):Checking ISAKMP transform 1 against priority 10 policy
*Dec 6 15:22:45.435: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.435: ISAKMP: hash SHA
*Dec 6 15:22:45.435: ISAKMP: default group 2
*Dec 6 15:22:45.435: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.435: ISAKMP: life type in seconds
*Dec 6 15:22:45.435: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.435: ISAKMP: keylength of 256
*Dec 6 15:22:45.435: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:22:45.435: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.435: ISAKMP:(0):Checking ISAKMP transform 2 against priority 10 policy
*Dec 6 15:22:45.435: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.435: ISAKMP: hash MD5
*Dec 6 15:22:45.435: ISAKMP: default group 2
*Dec 6 15:22:45.435: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.435: ISAKMP: life type in seconds
*Dec 6 15:22:45.435: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.435: ISAKMP: keylength of 256
*Dec 6 15:22:45.435: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:22:45.435: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.435: ISAKMP:(0):Checking ISAKMP transform 3 against priority 10 policy
*Dec 6 15:22:45.439: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.439: ISAKMP: hash SHA
*Dec 6 15:22:45.439: ISAKMP: default group 2
*Dec 6 15:22:45.439: ISAKMP: auth pre-share
*Dec 6 15:22:45.439: ISAKMP: life type in seconds
*Dec 6 15:22:45.439: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.439: ISAKMP: keylength of 256
*Dec 6 15:22:45.439: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:22:45.439: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.439: ISAKMP:(0):Checking ISAKMP transform 4 against priority 10 policy
*Dec 6 15:22:45.439: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.439: ISAKMP: hash MD5
*Dec 6 15:22:45.439: ISAKMP: default group 2
*Dec 6 15:22:45.439: ISAKMP: auth pre-share
*Dec 6 15:22:45.439: ISAKMP: life type in seconds
*Dec 6 15:22:45.439: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.439: ISAKMP: keylength of 256
*Dec 6 15:22:45.439: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:22:45.439: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.439: ISAKMP:(0):Checking ISAKMP transform 5 against priority 10 policy
*Dec 6 15:22:45.439: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.439: ISAKMP: hash SHA
*Dec 6 15:22:45.439: ISAKMP: default group 2
*Dec 6 15:22:45.439: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.439: ISAKMP: life type in seconds
*Dec 6 15:22:45.439: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.439: ISAKMP: keylength of 128
*Dec 6 15:22:45.439: ISAKMP:(0):Diffie-Hellman group offered does not match policy!
*Dec 6 15:22:45.439: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.439: ISAKMP:(0):Checking ISAKMP transform 6 against priority 10 policy
*Dec 6 15:22:45.439: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.439: ISAKMP: hash MD5
*Dec 6 15:22:45.439: ISAKMP: default group 2
*Dec 6 15:22:45.439: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.443: ISAKMP: life type in seconds
*Dec 6 15:22:45.443: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.443: ISAKMP: keylength of 128
*Dec 6 15:22:45.443: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:22:45.443: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.443: ISAKMP:(0):Checking ISAKMP transform 7 against priority 10 policy
*Dec 6 15:22:45.443: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.443: ISAKMP: hash SHA
*Dec 6 15:22:45.443: ISAKMP: default group 2
*Dec 6 15:22:45.443: ISAKMP: auth pre-share
*Dec 6 15:22:45.443: ISAKMP: life type in seconds
*Dec 6 15:22:45.443: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.443: ISAKMP: keylength of 128
*Dec 6 15:22:45.443: ISAKMP:(0):Diffie-Hellman group offered does not match policy!
*Dec 6 15:22:45.443: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.443: ISAKMP:(0):Checking ISAKMP transform 8 against priority 10 policy
*Dec 6 15:22:45.443: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.443: ISAKMP: hash MD5
*Dec 6 15:22:45.443: ISAKMP: default group 2
*Dec 6 15:22:45.443: ISAKMP: auth pre-share
*Dec 6 15:22:45.443: ISAKMP: life type in seconds
*Dec 6 15:22:45.443: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.443: ISAKMP: keylength of 128
*Dec 6 15:22:45.443: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:22:45.443: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.443: ISAKMP:(0):Checking ISAKMP transform 9 against priority 10 policy
*Dec 6 15:22:45.443: ISAKMP: encryption 3DES-CBC
*Dec 6 15:22:45.443: ISAKMP: hash SHA
*Dec 6 15:22:45.443: ISAKMP: default group 2
*Dec 6 15:22:45.443: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.443: ISAKMP: life type in seconds
*Dec 6 15:22:45.443: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.443: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:22:45.443: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.443: ISAKMP:(0):Checking ISAKMP transform 10 against priority 10 policy
*Dec 6 15:22:45.443: ISAKMP: encryption 3DES-CBC
*Dec 6 15:22:45.443: ISAKMP: hash MD5
*Dec 6 15:22:45.443: ISAKMP: default group 2
*Dec 6 15:22:45.443: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.443: ISAKMP: life type in seconds
*Dec 6 15:22:45.443: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.443: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:22:45.443: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.447: ISAKMP:(0):Checking ISAKMP transform 11 against priority 10 policy
*Dec 6 15:22:45.447: ISAKMP: encryption 3DES-CBC
*Dec 6 15:22:45.447: ISAKMP: hash SHA
*Dec 6 15:22:45.447: ISAKMP: default group 2
*Dec 6 15:22:45.447: ISAKMP: auth pre-share
*Dec 6 15:22:45.447: ISAKMP: life type in seconds
*Dec 6 15:22:45.447: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.447: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:22:45.447: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.447: ISAKMP:(0):Checking ISAKMP transform 12 against priority 10 policy
*Dec 6 15:22:45.447: ISAKMP: encryption 3DES-CBC
*Dec 6 15:22:45.447: ISAKMP: hash MD5
*Dec 6 15:22:45.447: ISAKMP: default group 2
*Dec 6 15:22:45.447: ISAKMP: auth pre-share
*Dec 6 15:22:45.447: ISAKMP: life type in seconds
*Dec 6 15:22:45.447: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.447: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:22:45.447: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.447: ISAKMP:(0):Checking ISAKMP transform 13 against priority 10 policy
*Dec 6 15:22:45.447: ISAKMP: encryption DES-CBC
*Dec 6 15:22:45.447: ISAKMP: hash MD5
*Dec 6 15:22:45.447: ISAKMP: default group 2
*Dec 6 15:22:45.447: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.447: ISAKMP: life type in seconds
*Dec 6 15:22:45.447: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.447: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:22:45.447: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.447: ISAKMP:(0):Checking ISAKMP transform 14 against priority 10 policy
*Dec 6 15:22:45.447: ISAKMP: encryption DES-CBC
*Dec 6 15:22:45.447: ISAKMP: hash MD5
*Dec 6 15:22:45.447: ISAKMP: default group 2
*Dec 6 15:22:45.447: ISAKMP: auth pre-share
*Dec 6 15:22:45.447: ISAKMP: life type in seconds
*Dec 6 15:22:45.447: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.447: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:22:45.447: ISAKMP:(0):atts are not acceptable. Next payload is 0
*Dec 6 15:22:45.447: ISAKMP:(0):Checking ISAKMP transform 1 against priority 20 policy
*Dec 6 15:22:45.447: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.447: ISAKMP: hash SHA
*Dec 6 15:22:45.447: ISAKMP: default group 2
*Dec 6 15:22:45.447: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.447: ISAKMP: life type in seconds
*Dec 6 15:22:45.447: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.447: ISAKMP: keylength of 256
*Dec 6 15:22:45.451: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:22:45.451: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.451: ISAKMP:(0):Checking ISAKMP transform 2 against priority 20 policy
*Dec 6 15:22:45.451: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.451: ISAKMP: hash MD5
*Dec 6 15:22:45.451: ISAKMP: default group 2
*Dec 6 15:22:45.451: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.451: ISAKMP: life type in seconds
*Dec 6 15:22:45.451: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.451: ISAKMP: keylength of 256
*Dec 6 15:22:45.451: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:22:45.451: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.451: ISAKMP:(0):Checking ISAKMP transform 3 against priority 20 policy
*Dec 6 15:22:45.451: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.451: ISAKMP: hash SHA
*Dec 6 15:22:45.451: ISAKMP: default group 2
*Dec 6 15:22:45.451: ISAKMP: auth pre-share
*Dec 6 15:22:45.451: ISAKMP: life type in seconds
*Dec 6 15:22:45.451: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.451: ISAKMP: keylength of 256
*Dec 6 15:22:45.451: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:22:45.451: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.451: ISAKMP:(0):Checking ISAKMP transform 4 against priority 20 policy
*Dec 6 15:22:45.451: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.451: ISAKMP: hash MD5
*Dec 6 15:22:45.451: ISAKMP: default group 2
*Dec 6 15:22:45.451: ISAKMP: auth pre-share
*Dec 6 15:22:45.451: ISAKMP: life type in seconds
*Dec 6 15:22:45.451: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.451: ISAKMP: keylength of 256
*Dec 6 15:22:45.451: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:22:45.451: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:22:45.451: ISAKMP:(0):Checking ISAKMP transform 5 against priority 20 policy
*Dec 6 15:22:45.451: ISAKMP: encryption AES-CBC
*Dec 6 15:22:45.451: ISAKMP: hash SHA
*Dec 6 15:22:45.451: ISAKMP: default group 2
*Dec 6 15:22:45.451: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:22:45.451: ISAKMP: life type in seconds
*Dec 6 15:22:45.451: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:45.451: ISAKMP: keylength of 128
*Dec 6 15:22:45.451: ISAKMP:(0):atts are acceptable. Next payload is 3
*Dec 6 15:22:45.451: ISAKMP:(0):Acceptable atts:actual life: 86400
*Dec 6 15:22:45.451: ISAKMP:(0):Acceptable atts:life: 0
*Dec 6 15:22:45.451: ISAKMP:(0):Fill atts in sa vpi_length:4
*Dec 6 15:22:45.451: ISAKMP:(0):Fill atts in sa life_in_seconds:2147483
*Dec 6 15:22:45.455: ISAKMP:(0):Returning Actual lifetime: 86400
*Dec 6 15:22:45.455: ISAKMP:(0)::Started lifetime timer: 86400.
*Dec 6 15:22:45.455: ISAKMP:(0): processing KE payload. message ID = 0
*Dec 6 15:22:45.531: ISAKMP:(0): processing NONCE payload. message ID = 0
*Dec 6 15:22:45.531: ISAKMP:(0): vendor ID is NAT-T v2
*Dec 6 15:22:45.531: ISAKMP:(0):ISAKMP/tunnel: setting up tunnel cn=VPN,o=NXXI pw request
*Dec 6 15:22:45.531: ISAKMP:(0):ISAKMP/tunnel: Tunnel cn=VPN,o=NXXI PW Request successfully sent to AAA
*Dec 6 15:22:45.535: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Dec 6 15:22:45.535: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_AM_AAA_AWAIT
*Dec 6 15:22:45.535: AAA SRV(00000023): process author req
*Dec 6 15:22:45.535: AAA SRV(00000023): Author method=LOCAL
*Dec 6 15:22:45.535: AAA SRV(00000023): protocol reply PASS for Authorization
*Dec 6 15:22:45.535: AAA SRV(00000023): Return Authorization status=PASS
*Dec 6 15:22:45.539: ISAKMP:(0):ISAKMP/tunnel: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
AAA/AUTHOR/IKE: Processing AV wins-servers
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Dec 6 15:22:45.539: ISAKMP/tunnel: received tunnel atts
*Dec 6 15:22:45.539: ISAKMP:(1012): constructed NAT-T vendor-02 ID
*Dec 6 15:22:45.539: ISAKMP:(1012):SA is doing pre-shared key authentication plus XAUTH using id type ID_IPV4_ADDR
*Dec 6 15:22:45.539: ISAKMP (1012): ID payload
next-payload : 10
type : 1
address : 10.55.5.150
protocol : 0
port : 0
length : 12
*Dec 6 15:22:45.539: ISAKMP:(1012):Total payload length: 12
*Dec 6 15:22:45.539: ISAKMP:(1012): sending packet to 10.55.5.19 my_port 500 peer_port 2299 (R) AG_INIT_EXCH
*Dec 6 15:22:45.539: ISAKMP:(1012):Sending an IKE IPv4 Packet.
*Dec 6 15:22:45.543: ISAKMP:(1012):Input = IKE_MESG_FROM_AAA, PRESHARED_KEY_REPLY
*Dec 6 15:22:45.543: ISAKMP:(1012):Old State = IKE_R_AM_AAA_AWAIT New State = IKE_R_AM2
*Dec 6 15:22:45.559: ISAKMP (1012): received packet from 10.55.5.19 dport 500 sport 2299 Global (R) AG_INIT_EXCH
*Dec 6 15:22:45.559: ISAKMP:(1012): processing HASH payload. message ID = 0
*Dec 6 15:22:45.559: ISAKMP:(1012): processing NOTIFY INITIAL_CONTACT protocol 1
spi 0, message ID = 0, sa = 0x6733EA68
*Dec 6 15:22:45.559: ISAKMP:received payload type 20
*Dec 6 15:22:45.559: ISAKMP (1012): His hash no match - this node outside NAT
*Dec 6 15:22:45.559: ISAKMP:received payload type 20
*Dec 6 15:22:45.559: ISAKMP (1012): No NAT Found for self or peer
*Dec 6 15:22:45.559: ISAKMP:(1012):SA authentication status: authenticated
*Dec 6 15:22:45.559: ISAKMP:(1012):SA has been authenticated with 10.55.5.19
*Dec 6 15:22:45.563: ISAKMP:(1012):SA authentication status:authenticated
*Dec 6 15:22:45.563: ISAKMP:(1012): Process initial contact,
bring down existing phase 1 and 2 SA's with local 10.55.5.150 remote 10.55.5.19 remote port 2299
*Dec 6 15:22:45.563: ISAKMP:(1012):returning IP addr to the address pool
*Dec 6 15:22:45.563: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Dec 6 15:22:45.563: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Dec 6 15:22:45.563: ISAKMP: Trying to insert a peer 10.55.5.150/10.55.5.19/2299/, and inserted successfully 67195BFC.
*Dec 6 15:22:45.563: ISAKMP:(1012):Returning Actual lifetime: 86400
*Dec 6 15:22:45.563: ISAKMP: set new node 1267765512 to CONF_XAUTH
*Dec 6 15:22:45.563: ISAKMP:(1012):Sending NOTIFY RESPONDER_LIFETIME protocol 1
spi 1719026824, message ID = 1267765512
*Dec 6 15:22:45.563: ISAKMP:(1012): sending packet to 10.55.5.19 my_port 500 peer_port 2299 (R) QM_IDLE
*Dec 6 15:22:45.563: ISAKMP:(1012):Sending an IKE IPv4 Packet.
*Dec 6 15:22:45.563: ISAKMP:(1012):purging node 1267765512
*Dec 6 15:22:45.567: ISAKMP: Sending phase 1 responder lifetime 86400
*Dec 6 15:22:45.567: ISAKMP AAA: Accounting is not enabled
*Dec 6 15:22:45.567: ISAKMP:(1012):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Dec 6 15:22:45.567: ISAKMP:(1012):Old State = IKE_R_AM2 New State = IKE_P1_COMPLETE
*Dec 6 15:22:45.567: ISAKMP:(1012):Need XAUTH
*Dec 6 15:22:45.567: ISAKMP: set new node -1686203497 to CONF_XAUTH
*Dec 6 15:22:45.567: ISAKMP/xauth: request attribute XAUTH_USER_NAME_V2
*Dec 6 15:22:45.567: ISAKMP/xauth: request attribute XAUTH_USER_PASSWORD_V2
*Dec 6 15:22:45.567: ISAKMP:(1012): initiating peer config to 10.55.5.19. ID = -1686203497
*Dec 6 15:22:45.567: ISAKMP:(1012): sending packet to 10.55.5.19 my_port 500 peer_port 2299 (R) CONF_XAUTH
*Dec 6 15:22:45.567: ISAKMP:(1012):Sending an IKE IPv4 Packet.
*Dec 6 15:22:45.571: ISAKMP:(1012):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:22:45.571: ISAKMP:(1012):Old State = IKE_P1_COMPLETE New State = IKE_XAUTH_REQ_SENT
*Dec 6 15:22:49.251: ISAKMP (1012): received packet from 10.55.5.19 dport 500 sport 2299 Global (R) CONF_XAUTH
*Dec 6 15:22:49.251: ISAKMP:(1012):processing transaction payload from 10.55.5.19. message ID = -1686203497
*Dec 6 15:22:49.251: ISAKMP: Config payload REPLY
*Dec 6 15:22:49.251: ISAKMP/xauth: reply attribute XAUTH_USER_NAME_V2
*Dec 6 15:22:49.251: ISAKMP/xauth: reply attribute XAUTH_USER_PASSWORD_V2
*Dec 6 15:22:49.251: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Dec 6 15:22:49.251: ISAKMP:(1012):AAA Authen: setting up authen_request
*Dec 6 15:22:49.255: ISAKMP:(1012):AAA Authen: Successfully sent authen info to AAA
*Dec 6 15:22:49.255: ISAKMP:(1012):deleting node -1686203497 error FALSE reason "Done with xauth request/reply exchange"
*Dec 6 15:22:49.255: ISAKMP:(1012):Input = IKE_MESG_FROM_PEER, IKE_CFG_REPLY
*Dec 6 15:22:49.255: ISAKMP:(1012):Old State = IKE_XAUTH_REQ_SENT New State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT
*Dec 6 15:22:49.255: AAA SRV(00000024): process authen req
*Dec 6 15:22:49.255: AAA SRV(00000024): Authen method=SERVER_GROUP Novell
*Dec 6 15:22:49.255: LDAP: LDAP: Queuing AAA request 36 for processing
*Dec 6 15:22:49.255: LDAP: Received queue event, new AAA request
*Dec 6 15:22:49.255: LDAP: LDAP authentication request
*Dec 6 15:22:49.255: LDAP: Attempting first next available LDAP server
*Dec 6 15:22:49.255: LDAP: Got next LDAP server :nw650
*Dec 6 15:22:49.255: LDAP: First Task: Send search req
*Dec 6 15:22:49.255: LDAP: Dynamic map configured
*Dec 6 15:22:49.255: LDAP: Check the default map for aaa type=username
*Dec 6 15:22:49.255: LDAP: Ldap Search Req sent
ld 1730517904
base dn o=NXXI
scope 2
filter (&(objectclass=User)(cn=u1))ldap_req_encode
put_filter "(&(objectclass=User)(cn=u1))"
put_filter: AND
put_filter_list "(objectclass=User)(cn=u1)"
put_filter "(objectclass=User)"
put_filter: simple
put_filter "(cn=u1)"
put_filter: simple
Doing socket write
*Dec 6 15:22:49.259: LDAP: LDAP search request sent successfully (reqid:23)
*Dec 6 15:22:49.259: LDAP: Sent the LDAP request to server
*Dec 6 15:22:49.271: LDAP: Received socket event
*Dec 6 15:22:49.275: LDAP: Checking the conn status
*Dec 6 15:22:49.275: LDAP: Socket read event socket=0
*Dec 6 15:22:49.275: LDAP: Found socket ctx
*Dec 6 15:22:49.275: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Dec 6 15:22:49.275: LDAP: Passing the client ctx=67259B90ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x670416CC
Doing socket read
LDAP-TCP:Bytes read = 325
ldap_match_request succeeded for msgid 23 h 0
*Dec 6 15:22:49.275: LDAP: LDAP Messages to be processed: 1
*Dec 6 15:22:49.275: LDAP: LDAP Message type: 100
*Dec 6 15:22:49.275: LDAP: Got ldap transaction context from reqid 23
*Dec 6 15:22:49.275: LDAP: Attribute Length Valueldap_get_dn
*Dec 6 15:22:49.275: LDAP: dn 12 cn=U1,o=NXXI
*Dec 6 15:22:49.275: LDAP: Dynamic map configured
*Dec 6 15:22:49.275: LDAP: Check the default map for aaa type=password
*Dec 6 15:22:49.275: LDAP: vpnAddressPool 9 VALIDpool
*Dec 6 15:22:49.275: LDAP: uid 2 U1
*Dec 6 15:22:49.275: LDAP: sn 2 U1
*Dec 6 15:22:49.275: LDAP: seeAlso 19 cn=VALIDpool,o=NXXI
*Dec 6 15:22:49.275: LDAP: objectClass 13 inetOrgPerson
*Dec 6 15:22:49.275: LDAP: objectClass 20 organizationalPerson
*Dec 6 15:22:49.275: LDAP: objectClass 6 Person
*Dec 6 15:22:49.275: LDAP: objectClass 18 ndsLoginProperties
*Dec 6 15:22:49.275: LDAP: objectClass 3 Top
*Dec 6 15:22:49.279: LDAP: loginMaximumSimultaneous 1 1
*Dec 6 15:22:49.279: LDAP: groupMembership 16 cn=G1,o=Albacomp
*Dec 6 15:22:49.279: LDAP: groupMembership 19 cn=VALIDpool,o=NXXI
*Dec 6 15:22:49.279: LDAP: cn 2 U1
*Dec 6 15:22:49.279: LDAP: Received a Search Response entryldap_get_dn
*Dec 6 15:22:49.279: LDAP: LDAP: GOT ENTRY: DN => cn=U1,o=NXXI
*Dec 6 15:22:49.279: LDAP: Dynamic map configured
*Dec 6 15:22:49.279: LDAP: Check the default map for aaa type=password
*Dec 6 15:22:49.279: LDAP: Attr-Map:ldap=vpnAddressPool ,aaa=addr-pool
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(uid)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(sn)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(seeAlso)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(loginMaximumSimultaneous)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Dec 6 15:22:49.279: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Dec 6 15:22:49.279: LDAP: Attr-Map:ldap=cn ,aaa=username
*Dec 6 15:22:49.279: LDAP: Retrieved an entry from search response
*Dec 6 15:22:49.283: LDAP: Waiting for search result. . .ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x670416CC
ldap_match_request succeeded for msgid 23 h 0
changing lr 0x677A4B64 to COMPLETE as no continuations
removing request 0x677A4B64 from list as lm 0x671E4DC0 all 0
ldap_msgfree
ldap_msgfree
*Dec 6 15:22:49.283: LDAP: LDAP Messages to be processed: 1
*Dec 6 15:22:49.283: LDAP: LDAP Message type: 101
*Dec 6 15:22:49.283: LDAP: Got ldap transaction context from reqid 23ldap_parse_result
*Dec 6 15:22:49.283: LDAP: resultCode: 0 (Success)
*Dec 6 15:22:49.283: LDAP: Received Search Response resultldap_parse_result
*Dec 6 15:22:49.283: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Dec 6 15:22:49.283: LDAP: * LDAP SEARCH DONE *
*Dec 6 15:22:49.283: LDAP: Next Task: Send bind req
*Dec 6 15:22:49.283: LDAP: Transaction context removed from list [ldap reqid=23]
*Dec 6 15:22:49.283: LDAP: Bind: User-DN=cn=U1,o=NXXIldap_req_encode
Doing socket write
*Dec 6 15:22:49.283: LDAP: LDAP bind request sent successfully (reqid=24)ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Dec 6 15:22:49.287: LDAP: Finished processing ldap msg, Result:Success
*Dec 6 15:22:49.287: LDAP: Received socket event
*Dec 6 15:22:49.287: LDAP: Checking the conn status
*Dec 6 15:22:49.287: LDAP: Socket read event socket=0
*Dec 6 15:22:49.287: LDAP: Found socket ctx
*Dec 6 15:22:49.287: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Dec 6 15:22:49.287: LDAP: Passing the client ctx=67259B90ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x670416CC
Doing socket read
LDAP-TCP:Bytes read = 14
ldap_match_request succeeded for msgid 24 h 0
changing lr 0x677A4B64 to COMPLETE as no continuations
removing request 0x677A4B64 from list as lm 0x671E4DC0 all 0
ldap_msgfree
ldap_msgfree
*Dec 6 15:22:49.291: LDAP: LDAP Messages to be processed: 1
*Dec 6 15:22:49.291: LDAP: LDAP Message type: 97
*Dec 6 15:22:49.291: LDAP: Got ldap transaction context from reqid 24ldap_parse_result
*Dec 6 15:22:49.291: LDAP: resultCode: 0 (Success)
*Dec 6 15:22:49.291: LDAP: Received Bind Responseldap_parse_result
*Dec 6 15:22:49.291: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Dec 6 15:22:49.291: LDAP: LDAP Bind successful for DN:cn=U1,o=NXXI
*Dec 6 15:22:49.291: LDAP: * LDAP PASSWORD VERIFY DONE *
*Dec 6 15:22:49.291: LDAP: Next Task: All authentication task completed
*Dec 6 15:22:49.291: LDAP: Transaction context removed from list [ldap reqid=24]
*Dec 6 15:22:49.291: LDAP: * * AUTHENTICATION COMPLETED SUCCESSFULLY * *
*Dec 6 15:22:49.291: LDAP: Notifying AAA: REQUEST SUCCESS
*Dec 6 15:22:49.291: AAA SRV(00000024): protocol reply PASS for Authentication
*Dec 6 15:22:49.291: AAA SRV(00000024): Return Authentication status=PASSldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Dec 6 15:22:49.291: LDAP: Finished processing ldap msg, Result:Success
AAA/AUTHOR/IKE: Processing AV addr-pool
*Dec 6 15:22:49.295: ISAKMP:(1012):ISAKMP/author: No Class attributes
*Dec 6 15:22:49.295: ISAKMP:(1012):AAA Authen: Received group atts
*Dec 6 15:22:49.295: ISAKMP:(1012):AAA Authen: Set accounting session id 0x1A
*Dec 6 15:22:49.295: ISAKMP: set new node 755779360 to CONF_XAUTH
*Dec 6 15:22:49.295: ISAKMP:(1012): initiating peer config to 10.55.5.19. ID = 755779360
*Dec 6 15:22:49.295: ISAKMP:(1012): sending packet to 10.55.5.19 my_port 500 peer_port 2299 (R) CONF_XAUTH
*Dec 6 15:22:49.295: ISAKMP:(1012):Sending an IKE IPv4 Packet.
*Dec 6 15:22:49.295: ISAKMP:(1012):Input = IKE_MESG_FROM_AAA, IKE_AAA_CONT_LOGIN
*Dec 6 15:22:49.295: ISAKMP:(1012):Old State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT New State = IKE_XAUTH_SET_SENT
*Dec 6 15:22:49.299: ISAKMP (1012): received packet from 10.55.5.19 dport 500 sport 2299 Global (R) CONF_XAUTH
*Dec 6 15:22:49.299: ISAKMP:(1012):processing transaction payload from 10.55.5.19. message ID = 755779360
*Dec 6 15:22:49.299: ISAKMP: Config payload ACK
*Dec 6 15:22:49.299: ISAKMP:(1012): (blank) XAUTH ACK Processed
*Dec 6 15:22:49.299: ISAKMP:(1012):deleting node 755779360 error FALSE reason "Transaction mode done"
*Dec 6 15:22:49.299: ISAKMP:(1012):Talking to a Unity Client
*Dec 6 15:22:49.299: ISAKMP:(1012):Input = IKE_MESG_FROM_PEER, IKE_CFG_ACK
*Dec 6 15:22:49.299: ISAKMP:(1012):Old State = IKE_XAUTH_SET_SENT New State = IKE_P1_COMPLETE
*Dec 6 15:22:49.299: ISAKMP:(1012):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:22:49.299: ISAKMP:(1012):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
*Dec 6 15:22:49.311: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down
*Dec 6 15:22:49.315: ISAKMP:(1012):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:22:49.315: ISAKMP:(1012):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
*Dec 6 15:22:49.319: LDAP: Received socket event
*Dec 6 15:22:49.391: ISAKMP (1012): received packet from 10.55.5.19 dport 500 sport 2299 Global (R) QM_IDLE
*Dec 6 15:22:49.391: ISAKMP: set new node -897952038 to QM_IDLE
*Dec 6 15:22:49.391: ISAKMP:(1012):processing transaction payload from 10.55.5.19. message ID = -897952038
*Dec 6 15:22:49.391: ISAKMP: Config payload REQUEST
*Dec 6 15:22:49.391: ISAKMP:(1012):checking request:
*Dec 6 15:22:49.391: ISAKMP: IP4_ADDRESS
*Dec 6 15:22:49.391: ISAKMP: IP4_NETMASK
*Dec 6 15:22:49.391: ISAKMP: IP4_DNS
*Dec 6 15:22:49.391: ISAKMP: IP4_NBNS
*Dec 6 15:22:49.391: ISAKMP: ADDRESS_EXPIRY
*Dec 6 15:22:49.391: ISAKMP: MODECFG_BANNER
*Dec 6 15:22:49.391: ISAKMP: MODECFG_SAVEPWD
*Dec 6 15:22:49.391: ISAKMP: DEFAULT_DOMAIN
*Dec 6 15:22:49.395: ISAKMP: SPLIT_INCLUDE
*Dec 6 15:22:49.395: ISAKMP: SPLIT_DNS
*Dec 6 15:22:49.395: ISAKMP: PFS
*Dec 6 15:22:49.395: ISAKMP: MODECFG_BROWSER_PROXY
*Dec 6 15:22:49.395: ISAKMP: BACKUP_SERVER
*Dec 6 15:22:49.395: ISAKMP: MODECFG_SMARTCARD_REMOVAL_DISCONNECT
*Dec 6 15:22:49.395: ISAKMP: APPLICATION_VERSION
*Dec 6 15:22:49.395: ISAKMP: Client Version is : Cisco Systems VPN Client 5.0.07.0290:WinNTp
*Dec 6 15:22:49.395: ISAKMP: FW_RECORD
*Dec 6 15:22:49.395: ISAKMP: MODECFG_HOSTNAME
*Dec 6 15:22:49.395: ISAKMP: CONFIG_MODE_UNKNOWN Unknown Attr: 0x7005
*Dec 6 15:22:49.395: ISAKMP:(1012):ISAKMP/author: setting up the authorization request for cn=VPN,o=NXXI
*Dec 6 15:22:49.395: ISAKMP/author: Author request for group cn=VPN,o=NXXIsuccessfully sent to AAA
*Dec 6 15:22:49.395: ISAKMP:(1012):Input = IKE_MESG_FROM_PEER, IKE_CFG_REQUEST
*Dec 6 15:22:49.395: ISAKMP:(1012):Old State = IKE_P1_COMPLETE New State = IKE_CONFIG_AUTHOR_AAA_AWAIT
*Dec 6 15:22:49.395: AAA SRV(00000024): process author req
*Dec 6 15:22:49.395: AAA SRV(00000024): Author method=LOCAL
*Dec 6 15:22:49.395: AAA SRV(00000024): protocol reply PASS for Authorization
*Dec 6 15:22:49.395: AAA SRV(00000024): Return Authorization status=PASS
*Dec 6 15:22:49.395: ISAKMP:(0):ISAKMP/author: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
*Dec 6 15:22:49.399:
AAA/AUTHOR/IKE: no DNS addresses
AAA/AUTHOR/IKE: Processing AV wins-servers
*Dec 6 15:22:49.399:
AAA/AUTHOR/IKE: no WINS addresses
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Dec 6 15:22:49.399: ISAKMP:(1012):ISAKMP/author: No Class attributes
*Dec 6 15:22:49.399: ISAKMP:(1012):attributes sent in message:
*Dec 6 15:22:49.399: Address: 0.2.0.0
*Dec 6 15:22:49.399: ISAKMP:(1012):allocating address 192.168.102.32
*Dec 6 15:22:49.399: ISAKMP: Sending private address: 192.168.102.32
*Dec 6 15:22:49.399: ISAKMP: Sending subnet mask: 255.255.255.0
*Dec 6 15:22:49.399: ISAKMP: Sending ADDRESS_EXPIRY seconds left to use the address: 86396
*Dec 6 15:22:49.399: ISAKMP: Sending save password reply value 0
*Dec 6 15:22:49.399: ISAKMP: Sending DEFAULT_DOMAIN default domain name: nxx.hu
*Dec 6 15:22:49.399: ISAKMP: Sending split include name EZsplit network 10.54.0.0 mask 255.254.0.0 protocol 0, src port 0, dst port 0
*Dec 6 15:22:49.399: ISAKMP: Sending smartcard_removal_disconnect reply
value 0
*Dec 6 15:22:49.399: ISAKMP: Sending APPLICATION_VERSION string: Cisco IOS Software, 2801 Software (C2801-ADVSECURITYK9-M), Version 15.1(2)T1, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2010 by Cisco Systems, Inc.
Compiled Wed 11-Aug-10 13:13 by prod_rel_team
*Dec 6 15:22:49.399: ISAKMP (1012): Unknown Attr: MODECFG_HOSTNAME (0x700A)
*Dec 6 15:22:49.399: ISAKMP (1012): Unknown Attr: CONFIG_MODE_UNKNOWN (0x7005)
*Dec 6 15:22:49.403: ISAKMP:(1012): responding to peer config from 10.55.5.19. ID = -897952038
*Dec 6 15:22:49.403: ISAKMP: Marking node -897952038 for late deletion
*Dec 6 15:22:49.403: ISAKMP:(1012): sending packet to 10.55.5.19 my_port 500 peer_port 2299 (R) CONF_ADDR
*Dec 6 15:22:49.403: ISAKMP:(1012):Sending an IKE IPv4 Packet.
*Dec 6 15:22:49.403: ISAKMP:(1012):Talking to a Unity Client
*Dec 6 15:22:49.403: ISAKMP:(1012):Input = IKE_MESG_FROM_AAA, IKE_AAA_GROUP_ATTR
*Dec 6 15:22:49.403: ISAKMP:(1012):Old State = IKE_CONFIG_AUTHOR_AAA_AWAIT New State = IKE_P1_COMPLETE
*Dec 6 15:22:49.403: ISAKMP:FSM error - Message from AAA grp/user.
*Dec 6 15:22:49.403: ISAKMP:(1012):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:22:49.403: ISAKMP:(1012):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
*Dec 6 15:22:49.435: ISAKMP (1012): received packet from 10.55.5.19 dport 500 sport 2299 Global (R) QM_IDLE
*Dec 6 15:22:49.435: ISAKMP: set new node 1354442609 to QM_IDLE
*Dec 6 15:22:49.435: ISAKMP:(1012): processing HASH payload. message ID = 1354442609
*Dec 6 15:22:49.435: ISAKMP:(1012): processing SA payload. message ID = 1354442609
*Dec 6 15:22:49.435: ISAKMP:(1012):Checking IPSec proposal 1
*Dec 6 15:22:49.435: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.439: ISAKMP: attributes in transform:
*Dec 6 15:22:49.439: ISAKMP: authenticator is HMAC-MD5
*Dec 6 15:22:49.439: ISAKMP: key length is 256
*Dec 6 15:22:49.439: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.439: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.439: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.439: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.439: ISAKMP:(1012):Checking IPSec proposal 1
*Dec 6 15:22:49.439: ISAKMP:(1012):transform 1, IPPCP LZS
*Dec 6 15:22:49.439: ISAKMP: attributes in transform:
*Dec 6 15:22:49.439: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.439: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.439: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.439: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.439: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.439: ISAKMP:(1012):Checking IPSec proposal 2
*Dec 6 15:22:49.439: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.439: ISAKMP: attributes in transform:
*Dec 6 15:22:49.439: ISAKMP: authenticator is HMAC-SHA
*Dec 6 15:22:49.439: ISAKMP: key length is 256
*Dec 6 15:22:49.439: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.439: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.439: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.439: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.439: ISAKMP:(1012):Checking IPSec proposal 2
*Dec 6 15:22:49.439: ISAKMP:(1012):transform 1, IPPCP LZS
*Dec 6 15:22:49.439: ISAKMP: attributes in transform:
*Dec 6 15:22:49.439: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.443: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.443: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.443: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.443: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.443: ISAKMP:(1012):Checking IPSec proposal 3
*Dec 6 15:22:49.443: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.443: ISAKMP: attributes in transform:
*Dec 6 15:22:49.443: ISAKMP: authenticator is HMAC-MD5
*Dec 6 15:22:49.443: ISAKMP: key length is 128
*Dec 6 15:22:49.443: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.443: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.443: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.443: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.443: ISAKMP:(1012):Checking IPSec proposal 3
*Dec 6 15:22:49.443: ISAKMP:(1012):transform 1, IPPCP LZS
*Dec 6 15:22:49.443: ISAKMP: attributes in transform:
*Dec 6 15:22:49.443: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.443: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.443: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.443: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.443: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.443: ISAKMP:(1012):Checking IPSec proposal 4
*Dec 6 15:22:49.443: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.443: ISAKMP: attributes in transform:
*Dec 6 15:22:49.443: ISAKMP: authenticator is HMAC-SHA
*Dec 6 15:22:49.443: ISAKMP: key length is 128
*Dec 6 15:22:49.443: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.447: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.447: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.447: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.447: ISAKMP:(1012):Checking IPSec proposal 4
*Dec 6 15:22:49.447: ISAKMP:(1012):transform 1, IPPCP LZS
*Dec 6 15:22:49.447: ISAKMP: attributes in transform:
*Dec 6 15:22:49.447: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.447: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.447: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.447: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.447: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.447: ISAKMP:(1012):Checking IPSec proposal 5
*Dec 6 15:22:49.447: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.447: ISAKMP: attributes in transform:
*Dec 6 15:22:49.447: ISAKMP: authenticator is HMAC-MD5
*Dec 6 15:22:49.447: ISAKMP: key length is 256
*Dec 6 15:22:49.447: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.447: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.447: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.447: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.447: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.447: ISAKMP:(1012):Checking IPSec proposal 6
*Dec 6 15:22:49.447: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.447: ISAKMP: attributes in transform:
*Dec 6 15:22:49.447: ISAKMP: authenticator is HMAC-SHA
*Dec 6 15:22:49.447: ISAKMP: key length is 256
*Dec 6 15:22:49.447: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.447: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.447: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.447: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.451: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.451: ISAKMP:(1012):Checking IPSec proposal 7
*Dec 6 15:22:49.451: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.451: ISAKMP: attributes in transform:
*Dec 6 15:22:49.451: ISAKMP: authenticator is HMAC-MD5
*Dec 6 15:22:49.451: ISAKMP: key length is 128
*Dec 6 15:22:49.451: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.451: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.451: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.451: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.451: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.451: ISAKMP:(1012):Checking IPSec proposal 8
*Dec 6 15:22:49.451: ISAKMP: transform 1, ESP_AES
*Dec 6 15:22:49.451: ISAKMP: attributes in transform:
*Dec 6 15:22:49.451: ISAKMP: authenticator is HMAC-SHA
*Dec 6 15:22:49.451: ISAKMP: key length is 128
*Dec 6 15:22:49.451: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.451: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.451: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.451: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.451: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.451: ISAKMP:(1012):Checking IPSec proposal 9
*Dec 6 15:22:49.451: ISAKMP: transform 1, ESP_3DES
*Dec 6 15:22:49.451: ISAKMP: attributes in transform:
*Dec 6 15:22:49.451: ISAKMP: authenticator is HMAC-MD5
*Dec 6 15:22:49.451: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.451: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.451: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.451: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.451: ISAKMP:(1012):Checking IPSec proposal 9
*Dec 6 15:22:49.451: ISAKMP:(1012):transform 1, IPPCP LZS
*Dec 6 15:22:49.451: ISAKMP: attributes in transform:
*Dec 6 15:22:49.451: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.451: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.451: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.451: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.455: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.455: ISAKMP:(1012):Checking IPSec proposal 10
*Dec 6 15:22:49.455: ISAKMP: transform 1, ESP_3DES
*Dec 6 15:22:49.455: ISAKMP: attributes in transform:
*Dec 6 15:22:49.455: ISAKMP: authenticator is HMAC-SHA
*Dec 6 15:22:49.455: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.455: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.455: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.455: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.455: ISAKMP:(1012):Checking IPSec proposal 10
*Dec 6 15:22:49.455: ISAKMP:(1012):transform 1, IPPCP LZS
*Dec 6 15:22:49.455: ISAKMP: attributes in transform:
*Dec 6 15:22:49.455: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.455: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.455: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.455: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.455: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
*Dec 6 15:22:49.455: ISAKMP:(1012):Checking IPSec proposal 11
*Dec 6 15:22:49.455: ISAKMP: transform 1, ESP_3DES
*Dec 6 15:22:49.455: ISAKMP: attributes in transform:
*Dec 6 15:22:49.455: ISAKMP: authenticator is HMAC-MD5
*Dec 6 15:22:49.455: ISAKMP: encaps is 1 (Tunnel)
*Dec 6 15:22:49.455: ISAKMP: SA life type in seconds
*Dec 6 15:22:49.455: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:22:49.455: ISAKMP:(1012):atts are acceptable.
*Dec 6 15:22:49.459: ISAKMP:(1012): processing NONCE payload. message ID = 1354442609
*Dec 6 15:22:49.459: ISAKMP:(1012): processing ID payload. message ID = 1354442609
*Dec 6 15:22:49.459: ISAKMP:(1012): processing ID payload. message ID = 1354442609
*Dec 6 15:22:49.459: ISAKMP:(1012):QM Responder gets spi
*Dec 6 15:22:49.459: ISAKMP:(1012):Node 1354442609, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Dec 6 15:22:49.459: ISAKMP:(1012):Old State = IKE_QM_READY New State = IKE_QM_SPI_STARVE
*Dec 6 15:22:49.459: ISAKMP:(1012):deleting node -897952038 error FALSE reason "No Error"
*Dec 6 15:22:49.459: ISAKMP:(1012): Creating IPSec SAs
*Dec 6 15:22:49.459: inbound SA from 10.55.5.19 to 10.55.5.150 (f/i) 0/ 0
(proxy 192.168.102.32 to 0.0.0.0)
*Dec 6 15:22:49.463: has spi 0x47676D26 and conn_id 0
*Dec 6 15:22:49.463: lifetime of 2147483 seconds
*Dec 6 15:22:49.463: outbound SA from 10.55.5.150 to 10.55.5.19 (f/i) 0/0
(proxy 0.0.0.0 to 192.168.102.32)
*Dec 6 15:22:49.463: has spi 0x3F4D498C and conn_id 0
*Dec 6 15:22:49.463: lifetime of 2147483 seconds
*Dec 6 15:22:49.463: ISAKMP:(1012): sending packet to 10.55.5.19 my_port 500 peer_port 2299 (R) QM_IDLE
*Dec 6 15:22:49.463: ISAKMP:(1012):Sending an IKE IPv4 Packet.
*Dec 6 15:22:49.463: ISAKMP:(1012):Node 1354442609, Input = IKE_MESG_INTERNAL, IKE_GOT_SPI
*Dec 6 15:22:49.463: ISAKMP:(1012):Old State = IKE_QM_SPI_STARVE New State = IKE_QM_R_QM2
*Dec 6 15:22:49.471: ISAKMP (1012): received packet from 10.55.5.19 dport 500 sport 2299 Global (R) QM_IDLE
*Dec 6 15:22:49.471: ISAKMP:(1012):deleting node 1354442609 error FALSE reason "QM done (await)"
*Dec 6 15:22:49.475: ISAKMP:(1012):Node 1354442609, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
*Dec 6 15:22:49.475: ISAKMP:(1012):Old State = IKE_QM_R_QM2 New State = IKE_QM_PHASE2_COMPLETE
*Dec 6 15:22:59.307: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
A user without that attribute cannot connect:
*Dec 6 15:27:16.159: ISAKMP (0): received packet from 10.55.5.19 dport 500 sport 2341 Global (N) NEW SA
*Dec 6 15:27:16.159: ISAKMP: Created a peer struct for 10.55.5.19, peer port 2341
*Dec 6 15:27:16.159: ISAKMP: New peer created peer = 0x67195BFC peer_handle = 0x80000010
*Dec 6 15:27:16.159: ISAKMP: Locking peer struct 0x67195BFC, refcount 1 for crypto_isakmp_process_block
*Dec 6 15:27:16.159: ISAKMP: local port 500, remote port 2341
*Dec 6 15:27:16.159: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 67131DCC
*Dec 6 15:27:16.159: ISAKMP:(0): processing SA payload. message ID = 0
*Dec 6 15:27:16.159: ISAKMP:(0): processing ID payload. message ID = 0
*Dec 6 15:27:16.163: ISAKMP (0): ID payload
next-payload : 13
type : 11
group id : cn=VPN,o=NXXI
protocol : 17
port : 500
length : 21
*Dec 6 15:27:16.163: ISAKMP:(0):: peer matches EZVPN profile
*Dec 6 15:27:16.163: ISAKMP:(0):Setting client config settings 67280640
*Dec 6 15:27:16.163: ISAKMP:(0):(Re)Setting client xauth list and state
*Dec 6 15:27:16.163: ISAKMP/xauth: initializing AAA request
*Dec 6 15:27:16.163: ISAKMP AAA: NAS Port Id is set to 10.55.5.150
*Dec 6 15:27:16.163: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Dec 6 15:27:16.163: ISAKMP/aaa: unique id = 37
*Dec 6 15:27:16.163: ISAKMP:(0): processing vendor id payload
*Dec 6 15:27:16.163: ISAKMP:(0): vendor ID seems Unity/DPD but major 215 mismatch
*Dec 6 15:27:16.163: ISAKMP:(0): vendor ID is XAUTH
*Dec 6 15:27:16.163: ISAKMP:(0): processing vendor id payload
*Dec 6 15:27:16.163: ISAKMP:(0): vendor ID is DPD
*Dec 6 15:27:16.163: ISAKMP:(0): processing vendor id payload
*Dec 6 15:27:16.163: ISAKMP:(0): processing IKE frag vendor id payload
*Dec 6 15:27:16.163: ISAKMP:(0):Support for IKE Fragmentation not enabled
*Dec 6 15:27:16.163: ISAKMP:(0): processing vendor id payload
*Dec 6 15:27:16.163: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
*Dec 6 15:27:16.163: ISAKMP:(0): vendor ID is NAT-T v2
*Dec 6 15:27:16.163: ISAKMP:(0): processing vendor id payload
*Dec 6 15:27:16.163: ISAKMP:(0): vendor ID is Unity
*Dec 6 15:27:16.163: ISAKMP:(0): Authentication by xauth preshared
*Dec 6 15:27:16.167: ISAKMP:(0):Checking ISAKMP transform 1 against priority 10 policy
*Dec 6 15:27:16.167: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.167: ISAKMP: hash SHA
*Dec 6 15:27:16.167: ISAKMP: default group 2
*Dec 6 15:27:16.167: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.167: ISAKMP: life type in seconds
*Dec 6 15:27:16.167: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.167: ISAKMP: keylength of 256
*Dec 6 15:27:16.167: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:27:16.167: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.167: ISAKMP:(0):Checking ISAKMP transform 2 against priority 10 policy
*Dec 6 15:27:16.167: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.167: ISAKMP: hash MD5
*Dec 6 15:27:16.167: ISAKMP: default group 2
*Dec 6 15:27:16.167: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.167: ISAKMP: life type in seconds
*Dec 6 15:27:16.167: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.167: ISAKMP: keylength of 256
*Dec 6 15:27:16.167: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:27:16.167: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.167: ISAKMP:(0):Checking ISAKMP transform 3 against priority 10 policy
*Dec 6 15:27:16.167: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.167: ISAKMP: hash SHA
*Dec 6 15:27:16.167: ISAKMP: default group 2
*Dec 6 15:27:16.167: ISAKMP: auth pre-share
*Dec 6 15:27:16.167: ISAKMP: life type in seconds
*Dec 6 15:27:16.167: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.167: ISAKMP: keylength of 256
*Dec 6 15:27:16.167: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:27:16.167: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.167: ISAKMP:(0):Checking ISAKMP transform 4 against priority 10 policy
*Dec 6 15:27:16.171: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.171: ISAKMP: hash MD5
*Dec 6 15:27:16.171: ISAKMP: default group 2
*Dec 6 15:27:16.171: ISAKMP: auth pre-share
*Dec 6 15:27:16.171: ISAKMP: life type in seconds
*Dec 6 15:27:16.171: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.171: ISAKMP: keylength of 256
*Dec 6 15:27:16.171: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:27:16.171: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.171: ISAKMP:(0):Checking ISAKMP transform 5 against priority 10 policy
*Dec 6 15:27:16.171: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.171: ISAKMP: hash SHA
*Dec 6 15:27:16.171: ISAKMP: default group 2
*Dec 6 15:27:16.171: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.171: ISAKMP: life type in seconds
*Dec 6 15:27:16.171: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.171: ISAKMP: keylength of 128
*Dec 6 15:27:16.171: ISAKMP:(0):Diffie-Hellman group offered does not match policy!
*Dec 6 15:27:16.171: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.171: ISAKMP:(0):Checking ISAKMP transform 6 against priority 10 policy
*Dec 6 15:27:16.171: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.171: ISAKMP: hash MD5
*Dec 6 15:27:16.171: ISAKMP: default group 2
*Dec 6 15:27:16.171: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.171: ISAKMP: life type in seconds
*Dec 6 15:27:16.171: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.171: ISAKMP: keylength of 128
*Dec 6 15:27:16.171: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:27:16.171: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.171: ISAKMP:(0):Checking ISAKMP transform 7 against priority 10 policy
*Dec 6 15:27:16.171: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.171: ISAKMP: hash SHA
*Dec 6 15:27:16.171: ISAKMP: default group 2
*Dec 6 15:27:16.171: ISAKMP: auth pre-share
*Dec 6 15:27:16.171: ISAKMP: life type in seconds
*Dec 6 15:27:16.171: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.171: ISAKMP: keylength of 128
*Dec 6 15:27:16.175: ISAKMP:(0):Diffie-Hellman group offered does not match policy!
*Dec 6 15:27:16.175: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.175: ISAKMP:(0):Checking ISAKMP transform 8 against priority 10 policy
*Dec 6 15:27:16.175: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.175: ISAKMP: hash MD5
*Dec 6 15:27:16.175: ISAKMP: default group 2
*Dec 6 15:27:16.175: ISAKMP: auth pre-share
*Dec 6 15:27:16.175: ISAKMP: life type in seconds
*Dec 6 15:27:16.175: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.175: ISAKMP: keylength of 128
*Dec 6 15:27:16.175: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:27:16.175: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.175: ISAKMP:(0):Checking ISAKMP transform 9 against priority 10 policy
*Dec 6 15:27:16.175: ISAKMP: encryption 3DES-CBC
*Dec 6 15:27:16.175: ISAKMP: hash SHA
*Dec 6 15:27:16.175: ISAKMP: default group 2
*Dec 6 15:27:16.175: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.175: ISAKMP: life type in seconds
*Dec 6 15:27:16.175: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.175: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:27:16.175: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.175: ISAKMP:(0):Checking ISAKMP transform 10 against priority 10 policy
*Dec 6 15:27:16.175: ISAKMP: encryption 3DES-CBC
*Dec 6 15:27:16.175: ISAKMP: hash MD5
*Dec 6 15:27:16.175: ISAKMP: default group 2
*Dec 6 15:27:16.175: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.175: ISAKMP: life type in seconds
*Dec 6 15:27:16.175: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.175: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:27:16.175: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.175: ISAKMP:(0):Checking ISAKMP transform 11 against priority 10 policy
*Dec 6 15:27:16.175: ISAKMP: encryption 3DES-CBC
*Dec 6 15:27:16.175: ISAKMP: hash SHA
*Dec 6 15:27:16.175: ISAKMP: default group 2
*Dec 6 15:27:16.175: ISAKMP: auth pre-share
*Dec 6 15:27:16.175: ISAKMP: life type in seconds
*Dec 6 15:27:16.175: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.175: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:27:16.175: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.175: ISAKMP:(0):Checking ISAKMP transform 12 against priority 10 policy
*Dec 6 15:27:16.175: ISAKMP: encryption 3DES-CBC
*Dec 6 15:27:16.175: ISAKMP: hash MD5
*Dec 6 15:27:16.175: ISAKMP: default group 2
*Dec 6 15:27:16.175: ISAKMP: auth pre-share
*Dec 6 15:27:16.175: ISAKMP: life type in seconds
*Dec 6 15:27:16.175: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.179: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:27:16.179: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.179: ISAKMP:(0):Checking ISAKMP transform 13 against priority 10 policy
*Dec 6 15:27:16.179: ISAKMP: encryption DES-CBC
*Dec 6 15:27:16.179: ISAKMP: hash MD5
*Dec 6 15:27:16.179: ISAKMP: default group 2
*Dec 6 15:27:16.179: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.179: ISAKMP: life type in seconds
*Dec 6 15:27:16.179: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.179: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:27:16.179: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.179: ISAKMP:(0):Checking ISAKMP transform 14 against priority 10 policy
*Dec 6 15:27:16.179: ISAKMP: encryption DES-CBC
*Dec 6 15:27:16.179: ISAKMP: hash MD5
*Dec 6 15:27:16.179: ISAKMP: default group 2
*Dec 6 15:27:16.179: ISAKMP: auth pre-share
*Dec 6 15:27:16.179: ISAKMP: life type in seconds
*Dec 6 15:27:16.179: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.179: ISAKMP:(0):Encryption algorithm offered does not match policy!
*Dec 6 15:27:16.179: ISAKMP:(0):atts are not acceptable. Next payload is 0
*Dec 6 15:27:16.179: ISAKMP:(0):Checking ISAKMP transform 1 against priority 20 policy
*Dec 6 15:27:16.179: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.179: ISAKMP: hash SHA
*Dec 6 15:27:16.179: ISAKMP: default group 2
*Dec 6 15:27:16.179: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.179: ISAKMP: life type in seconds
*Dec 6 15:27:16.179: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.179: ISAKMP: keylength of 256
*Dec 6 15:27:16.179: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:27:16.179: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.179: ISAKMP:(0):Checking ISAKMP transform 2 against priority 20 policy
*Dec 6 15:27:16.179: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.179: ISAKMP: hash MD5
*Dec 6 15:27:16.179: ISAKMP: default group 2
*Dec 6 15:27:16.179: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.179: ISAKMP: life type in seconds
*Dec 6 15:27:16.179: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.179: ISAKMP: keylength of 256
*Dec 6 15:27:16.179: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:27:16.179: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.179: ISAKMP:(0):Checking ISAKMP transform 3 against priority 20 policy
*Dec 6 15:27:16.179: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.179: ISAKMP: hash SHA
*Dec 6 15:27:16.183: ISAKMP: default group 2
*Dec 6 15:27:16.183: ISAKMP: auth pre-share
*Dec 6 15:27:16.183: ISAKMP: life type in seconds
*Dec 6 15:27:16.183: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.183: ISAKMP: keylength of 256
*Dec 6 15:27:16.183: ISAKMP:(0):Proposed key length does not match policy
*Dec 6 15:27:16.183: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.183: ISAKMP:(0):Checking ISAKMP transform 4 against priority 20 policy
*Dec 6 15:27:16.183: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.183: ISAKMP: hash MD5
*Dec 6 15:27:16.183: ISAKMP: default group 2
*Dec 6 15:27:16.183: ISAKMP: auth pre-share
*Dec 6 15:27:16.183: ISAKMP: life type in seconds
*Dec 6 15:27:16.183: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.183: ISAKMP: keylength of 256
*Dec 6 15:27:16.183: ISAKMP:(0):Hash algorithm offered does not match policy!
*Dec 6 15:27:16.183: ISAKMP:(0):atts are not acceptable. Next payload is 3
*Dec 6 15:27:16.183: ISAKMP:(0):Checking ISAKMP transform 5 against priority 20 policy
*Dec 6 15:27:16.183: ISAKMP: encryption AES-CBC
*Dec 6 15:27:16.183: ISAKMP: hash SHA
*Dec 6 15:27:16.183: ISAKMP: default group 2
*Dec 6 15:27:16.183: ISAKMP: auth XAUTHInitPreShared
*Dec 6 15:27:16.183: ISAKMP: life type in seconds
*Dec 6 15:27:16.183: ISAKMP: life duration (VPI) of 0x0 0x20 0xC4 0x9B
*Dec 6 15:27:16.183: ISAKMP: keylength of 128
*Dec 6 15:27:16.183: ISAKMP:(0):atts are acceptable. Next payload is 3
*Dec 6 15:27:16.183: ISAKMP:(0):Acceptable atts:actual life: 86400
*Dec 6 15:27:16.183: ISAKMP:(0):Acceptable atts:life: 0
*Dec 6 15:27:16.183: ISAKMP:(0):Fill atts in sa vpi_length:4
*Dec 6 15:27:16.183: ISAKMP:(0):Fill atts in sa life_in_seconds:2147483
*Dec 6 15:27:16.183: ISAKMP:(0):Returning Actual lifetime: 86400
*Dec 6 15:27:16.183: ISAKMP:(0)::Started lifetime timer: 86400.
*Dec 6 15:27:16.183: ISAKMP:(0): processing KE payload. message ID = 0
*Dec 6 15:27:16.259: ISAKMP:(0): processing NONCE payload. message ID = 0
*Dec 6 15:27:16.259: ISAKMP:(0): vendor ID is NAT-T v2
*Dec 6 15:27:16.259: ISAKMP:(0):ISAKMP/tunnel: setting up tunnel cn=VPN,o=NXXI pw request
*Dec 6 15:27:16.259: ISAKMP:(0):ISAKMP/tunnel: Tunnel cn=VPN,o=NXXI PW Request successfully sent to AAA
*Dec 6 15:27:16.259: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Dec 6 15:27:16.259: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_AM_AAA_AWAIT
*Dec 6 15:27:16.259: AAA SRV(00000025): process author req
*Dec 6 15:27:16.259: AAA SRV(00000025): Author method=LOCAL
*Dec 6 15:27:16.259: AAA SRV(00000025): protocol reply PASS for Authorization
*Dec 6 15:27:16.263: AAA SRV(00000025): Return Authorization status=PASS
*Dec 6 15:27:16.263: ISAKMP:(0):ISAKMP/tunnel: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
AAA/AUTHOR/IKE: Processing AV wins-servers
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Dec 6 15:27:16.263: ISAKMP/tunnel: received tunnel atts
*Dec 6 15:27:16.263: ISAKMP:(1013): constructed NAT-T vendor-02 ID
*Dec 6 15:27:16.263: ISAKMP:(1013):SA is doing pre-shared key authentication plus XAUTH using id type ID_IPV4_ADDR
*Dec 6 15:27:16.263: ISAKMP (1013): ID payload
next-payload : 10
type : 1
address : 10.55.5.150
protocol : 0
port : 0
length : 12
*Dec 6 15:27:16.263: ISAKMP:(1013):Total payload length: 12
*Dec 6 15:27:16.263: ISAKMP:(1013): sending packet to 10.55.5.19 my_port 500 peer_port 2341 (R) AG_INIT_EXCH
*Dec 6 15:27:16.263: ISAKMP:(1013):Sending an IKE IPv4 Packet.
*Dec 6 15:27:16.267: ISAKMP:(1013):Input = IKE_MESG_FROM_AAA, PRESHARED_KEY_REPLY
*Dec 6 15:27:16.267: ISAKMP:(1013):Old State = IKE_R_AM_AAA_AWAIT New State = IKE_R_AM2
*Dec 6 15:27:16.303: ISAKMP (1013): received packet from 10.55.5.19 dport 500 sport 2341 Global (R) AG_INIT_EXCH
*Dec 6 15:27:16.303: ISAKMP:(1013): processing HASH payload. message ID = 0
*Dec 6 15:27:16.303: ISAKMP:(1013): processing NOTIFY INITIAL_CONTACT protocol 1
spi 0, message ID = 0, sa = 0x67131DCC
*Dec 6 15:27:16.303: ISAKMP:received payload type 20
*Dec 6 15:27:16.303: ISAKMP (1013): His hash no match - this node outside NAT
*Dec 6 15:27:16.307: ISAKMP:received payload type 20
*Dec 6 15:27:16.307: ISAKMP (1013): No NAT Found for self or peer
*Dec 6 15:27:16.307: ISAKMP:(1013):SA authentication status:
authenticated
*Dec 6 15:27:16.307: ISAKMP:(1013):SA has been authenticated with 10.55.5.19
*Dec 6 15:27:16.307: ISAKMP:(1013):SA authentication status:
authenticated
*Dec 6 15:27:16.307: ISAKMP:(1013): Process initial contact,
bring down existing phase 1 and 2 SA's with local 10.55.5.150 remote 10.55.5.19 remote port 2341
*Dec 6 15:27:16.307: ISAKMP:(1013):returning IP addr to the address pool
*Dec 6 15:27:16.307: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Dec 6 15:27:16.307: ISAKMP:(0):AAA: Nas Port ID set to 10.55.5.150.
*Dec 6 15:27:16.307: ISAKMP: Trying to insert a peer 10.55.5.150/10.55.5.19/2341/, and inserted successfully 67195BFC.
*Dec 6 15:27:16.307: ISAKMP:(1013):Returning Actual lifetime: 86400
*Dec 6 15:27:16.307: ISAKMP: set new node 1729657672 to CONF_XAUTH
*Dec 6 15:27:16.307: ISAKMP:(1013):Sending NOTIFY RESPONDER_LIFETIME protocol 1
spi 1719026824, message ID = 1729657672
*Dec 6 15:27:16.311: ISAKMP:(1013): sending packet to 10.55.5.19 my_port 500 peer_port 2341 (R) QM_IDLE
*Dec 6 15:27:16.311: ISAKMP:(1013):Sending an IKE IPv4 Packet.
*Dec 6 15:27:16.311: ISAKMP:(1013):purging node 1729657672
*Dec 6 15:27:16.311: ISAKMP: Sending phase 1 responder lifetime 86400
*Dec 6 15:27:16.311: ISAKMP AAA: Accounting is not enabled
*Dec 6 15:27:16.311: ISAKMP:(1013):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Dec 6 15:27:16.311: ISAKMP:(1013):Old State = IKE_R_AM2 New State = IKE_P1_COMPLETE
*Dec 6 15:27:16.315: ISAKMP:(1013):Need XAUTH
*Dec 6 15:27:16.315: ISAKMP: set new node 63828614 to CONF_XAUTH
*Dec 6 15:27:16.315: ISAKMP/xauth: request attribute XAUTH_USER_NAME_V2
*Dec 6 15:27:16.315: ISAKMP/xauth: request attribute XAUTH_USER_PASSWORD_V2
*Dec 6 15:27:16.315: ISAKMP:(1013): initiating peer config to 10.55.5.19. ID = 63828614
*Dec 6 15:27:16.315: ISAKMP:(1013): sending packet to 10.55.5.19 my_port 500 peer_port 2341 (R) CONF_XAUTH
*Dec 6 15:27:16.315: ISAKMP:(1013):Sending an IKE IPv4 Packet.
*Dec 6 15:27:16.315: ISAKMP:(1013):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:27:16.315: ISAKMP:(1013):Old State = IKE_P1_COMPLETE New State = IKE_XAUTH_REQ_SENT
*Dec 6 15:27:20.147: ISAKMP (1013): received packet from 10.55.5.19 dport 500 sport 2341 Global (R) CONF_XAUTH
*Dec 6 15:27:20.147: ISAKMP:(1013):processing transaction payload from 10.55.5.19. message ID = 63828614
*Dec 6 15:27:20.147: ISAKMP: Config payload REPLY
*Dec 6 15:27:20.147: ISAKMP/xauth: reply attribute XAUTH_USER_NAME_V2
*Dec 6 15:27:20.147: ISAKMP/xauth: reply attribute XAUTH_USER_PASSWORD_V2
*Dec 6 15:27:20.147: ISAKMP AAA: NAS Port Id is already set to 10.55.5.150
*Dec 6 15:27:20.147: ISAKMP:(1013):AAA Authen: setting up authen_request
*Dec 6 15:27:20.147: ISAKMP:(1013):AAA Authen: Successfully sent authen info to AAA
*Dec 6 15:27:20.147: ISAKMP:(1013):deleting node 63828614 error FALSE reason "Done with xauth request/reply exchange"
*Dec 6 15:27:20.147: ISAKMP:(1013):Input = IKE_MESG_FROM_PEER, IKE_CFG_REPLY
*Dec 6 15:27:20.147: ISAKMP:(1013):Old State = IKE_XAUTH_REQ_SENT New State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT
*Dec 6 15:27:20.147: AAA SRV(00000026): process authen req
*Dec 6 15:27:20.147: AAA SRV(00000026): Authen method=SERVER_GROUP Novell
*Dec 6 15:27:20.147: LDAP: LDAP: Queuing AAA request 38 for processing
*Dec 6 15:27:20.147: LDAP: Received queue event, new AAA request
*Dec 6 15:27:20.147: LDAP: LDAP authentication request
*Dec 6 15:27:20.151: LDAP: Attempting first next available LDAP server
*Dec 6 15:27:20.151: LDAP: Got next LDAP server :nw650
*Dec 6 15:27:20.151: LDAP: First Task: Send search req
*Dec 6 15:27:20.151: LDAP: Dynamic map configured
*Dec 6 15:27:20.151: LDAP: Check the default map for aaa type=username
*Dec 6 15:27:20.151: LDAP: Ldap Search Req sent
ld 1730517904
base dn o=NXXI
scope 2
filter (&(objectclass=User)(cn=u2))ldap_req_encode
put_filter "(&(objectclass=User)(cn=u2))"
put_filter: AND
put_filter_list "(objectclass=User)(cn=u2)"
put_filter "(objectclass=User)"
put_filter: simple
put_filter "(cn=u2)"
put_filter: simple
Doing socket write
*Dec 6 15:27:20.151: LDAP: LDAP search request sent successfully (reqid:25)
*Dec 6 15:27:20.151: LDAP: Sent the LDAP request to server
*Dec 6 15:27:20.159: LDAP: Received socket event
*Dec 6 15:27:20.159: LDAP: Checking the conn status
*Dec 6 15:27:20.159: LDAP: Socket read event socket=0
*Dec 6 15:27:20.159: LDAP: Found socket ctx
*Dec 6 15:27:20.159: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Dec 6 15:27:20.159: LDAP: Passing the client ctx=67259B90ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x670416CC
Doing socket read
LDAP-TCP:Bytes read = 260
ldap_match_request succeeded for msgid 25 h 0
*Dec 6 15:27:20.159: LDAP: LDAP Messages to be processed: 1
*Dec 6 15:27:20.159: LDAP: LDAP Message type: 100
*Dec 6 15:27:20.159: LDAP: Got ldap transaction context from reqid 25
*Dec 6 15:27:20.159: LDAP: Attribute Length Valueldap_get_dn
*Dec 6 15:27:20.159: LDAP: dn 12 cn=U2,o=NXXI
*Dec 6 15:27:20.159: LDAP: Dynamic map configured
*Dec 6 15:27:20.159: LDAP: Check the default map for aaa type=password
*Dec 6 15:27:20.163: LDAP: uid 2 U2
*Dec 6 15:27:20.163: LDAP: sn 2 U2
*Dec 6 15:27:20.163: LDAP: objectClass 13 inetOrgPerson
*Dec 6 15:27:20.163: LDAP: objectClass 20 organizationalPerson
*Dec 6 15:27:20.163: LDAP: objectClass 6 Person
*Dec 6 15:27:20.163: LDAP: objectClass 18 ndsLoginProperties
*Dec 6 15:27:20.163: LDAP: objectClass 3 Top
*Dec 6 15:27:20.163: LDAP: loginMaximumSimultaneous 1 2
*Dec 6 15:27:20.163: LDAP: groupMembership 16 cn=G1,o=Albacomp
*Dec 6 15:27:20.163: LDAP: groupMembership 22 cn=G2X,ou=X,o=Albacomp
*Dec 6 15:27:20.163: LDAP: cn 2 U2
*Dec 6 15:27:20.163: LDAP: Received a Search Response entryldap_get_dn
*Dec 6 15:27:20.163: LDAP: LDAP: GOT ENTRY: DN => cn=U2,o=NXXI
*Dec 6 15:27:20.163: LDAP: Dynamic map configured
*Dec 6 15:27:20.163: LDAP: Check the default map for aaa type=password
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(uid)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(sn)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(objectClass)
*Dec 6 15:27:20.163: LDAP: Attr-Map:No map for ldap attr(loginMaximumSimultaneous)
*Dec 6 15:27:20.167: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Dec 6 15:27:20.167: LDAP: Attr-Map:No map for ldap attr(groupMembership)
*Dec 6 15:27:20.167: LDAP: Attr-Map:ldap=cn ,aaa=username
*Dec 6 15:27:20.167: LDAP: Retrieved an entry from search response
*Dec 6 15:27:20.167: LDAP: Waiting for search result. . .ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_read_activity lc 0x670416CC
ldap_match_request succeeded for msgid 25 h 0
changing lr 0x66C7FEC4 to COMPLETE as no continuations
removing request 0x66C7FEC4 from list as lm 0x671E4B80 all 0
ldap_msgfree
ldap_msgfree
*Dec 6 15:27:20.167: LDAP: LDAP Messages to be processed: 1
*Dec 6 15:27:20.167: LDAP: LDAP Message type: 101
*Dec 6 15:27:20.167: LDAP: Got ldap transaction context from reqid 25ldap_parse_result
*Dec 6 15:27:20.167: LDAP: resultCode: 0 (Success)
*Dec 6 15:27:20.167: LDAP: Received Search Response resultldap_parse_result
*Dec 6 15:27:20.167: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Dec 6 15:27:20.167: LDAP: * LDAP SEARCH DONE *
*Dec 6 15:27:20.167: LDAP: Next Task: Send bind req
*Dec 6 15:27:20.167: LDAP: Transaction context removed from list [ldap reqid=25]
*Dec 6 15:27:20.167: LDAP: Bind: User-DN=cn=U2,o=NXXIldap_req_encode
Doing socket write
*Dec 6 15:27:20.171: LDAP: LDAP bind request sent successfully (reqid=26)ldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Dec 6 15:27:20.171: LDAP: Finished processing ldap msg, Result:Success
*Dec 6 15:27:20.171: LDAP: Received socket event
*Dec 6 15:27:20.175: LDAP: Checking the conn status
*Dec 6 15:27:20.175: LDAP: Socket read event socket=0
*Dec 6 15:27:20.175: LDAP: Found socket ctx
*Dec 6 15:27:20.175: LDAP: Receive event: read=1, errno=9 (Bad file number)
*Dec 6 15:27:20.175: LDAP: Passing the client ctx=67259B90ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_read_activity lc 0x670416CC
Doing socket read
LDAP-TCP:Bytes read = 14
ldap_match_request succeeded for msgid 26 h 0
changing lr 0x66C7FEC4 to COMPLETE as no continuations
removing request 0x66C7FEC4 from list as lm 0x671E4B80 all 0
ldap_msgfree
ldap_msgfree
*Dec 6 15:27:20.175: LDAP: LDAP Messages to be processed: 1
*Dec 6 15:27:20.175: LDAP: LDAP Message type: 97
*Dec 6 15:27:20.175: LDAP: Got ldap transaction context from reqid 26ldap_parse_result
*Dec 6 15:27:20.175: LDAP: resultCode: 0 (Success)
*Dec 6 15:27:20.175: LDAP: Received Bind Responseldap_parse_result
*Dec 6 15:27:20.175: LDAP: Ldap Result Msg: SUCCESS, Result code =0
*Dec 6 15:27:20.175: LDAP: LDAP Bind successful for DN:cn=U2,o=NXXI
*Dec 6 15:27:20.175: LDAP: * LDAP PASSWORD VERIFY DONE *
*Dec 6 15:27:20.175: LDAP: Next Task: All authentication task completed
*Dec 6 15:27:20.175: LDAP: Transaction context removed from list [ldap reqid=26]
*Dec 6 15:27:20.175: LDAP: * * AUTHENTICATION COMPLETED SUCCESSFULLY * *
*Dec 6 15:27:20.175: LDAP: Notifying AAA: REQUEST SUCCESS
*Dec 6 15:27:20.179: AAA SRV(00000026): protocol reply PASS for Authentication
*Dec 6 15:27:20.179: AAA SRV(00000026): Return Authentication status=PASSldap_msgfree
ldap_result
wait4msg (timeout 0 sec, 1 usec)
ldap_select_fd_wait (select)
ldap_err2string
*Dec 6 15:27:20.179: LDAP: Finished processing ldap msg, Result:Success
*Dec 6 15:27:20.179: ISAKMP:(1013):ISAKMP/author: No Class attributes
*Dec 6 15:27:20.179: ISAKMP:(1013):AAA Authen: No group atts added
*Dec 6 15:27:20.179: ISAKMP:(1013):AAA Authen: Set accounting session id 0x1C
*Dec 6 15:27:20.179: ISAKMP: set new node 2019195218 to CONF_XAUTH
*Dec 6 15:27:20.179: ISAKMP:(1013): initiating peer config to 10.55.5.19. ID = 2019195218
*Dec 6 15:27:20.179: ISAKMP:(1013): sending packet to 10.55.5.19 my_port 500 peer_port 2341 (R) CONF_XAUTH
*Dec 6 15:27:20.179: ISAKMP:(1013):Sending an IKE IPv4 Packet.
*Dec 6 15:27:20.179: ISAKMP:(1013):Input = IKE_MESG_FROM_AAA, IKE_AAA_CONT_LOGIN
*Dec 6 15:27:20.183: ISAKMP:(1013):Old State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT New State = IKE_XAUTH_SET_SENT
*Dec 6 15:27:20.183: LDAP: Received socket event
*Dec 6 15:27:20.183: ISAKMP (1013): received packet from 10.55.5.19 dport 500 sport 2341 Global (R) CONF_XAUTH
*Dec 6 15:27:20.183: ISAKMP:(1013):processing transaction payload from 10.55.5.19. message ID = 2019195218
*Dec 6 15:27:20.183: ISAKMP: Config payload ACK
*Dec 6 15:27:20.183: ISAKMP:(1013): (blank) XAUTH ACK Processed
*Dec 6 15:27:20.183: ISAKMP:(1013):deleting node 2019195218 error FALSE reason "Transaction mode done"
*Dec 6 15:27:20.187: ISAKMP:(1013):Talking to a Unity Client
*Dec 6 15:27:20.187: ISAKMP:(1013):Input = IKE_MESG_FROM_PEER, IKE_CFG_ACK
*Dec 6 15:27:20.187: ISAKMP:(1013):Old State = IKE_XAUTH_SET_SENT New State = IKE_P1_COMPLETE
*Dec 6 15:27:20.187: ISAKMP:(1013):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:27:20.187: ISAKMP:(1013):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
*Dec 6 15:27:20.199: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down
*Dec 6 15:27:20.203: ISAKMP:(1013):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:27:20.203: ISAKMP:(1013):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
*Dec 6 15:27:21.223: ISAKMP (1013): received packet from 10.55.5.19 dport 500 sport 2341 Global (R) QM_IDLE
*Dec 6 15:27:21.227: ISAKMP: set new node -2081952537 to QM_IDLE
*Dec 6 15:27:21.227: ISAKMP:(1013):processing transaction payload from 10.55.5.19. message ID = -2081952537
*Dec 6 15:27:21.227: ISAKMP: Config payload REQUEST
*Dec 6 15:27:21.227: ISAKMP:(1013):checking request:
*Dec 6 15:27:21.227: ISAKMP: IP4_ADDRESS
*Dec 6 15:27:21.227: ISAKMP: IP4_NETMASK
*Dec 6 15:27:21.227: ISAKMP: IP4_DNS
*Dec 6 15:27:21.227: ISAKMP: IP4_NBNS
*Dec 6 15:27:21.227: ISAKMP: ADDRESS_EXPIRY
*Dec 6 15:27:21.227: ISAKMP: MODECFG_BANNER
*Dec 6 15:27:21.227: ISAKMP: MODECFG_SAVEPWD
*Dec 6 15:27:21.227: ISAKMP: DEFAULT_DOMAIN
*Dec 6 15:27:21.227: ISAKMP: SPLIT_INCLUDE
*Dec 6 15:27:21.227: ISAKMP: SPLIT_DNS
*Dec 6 15:27:21.227: ISAKMP: PFS
*Dec 6 15:27:21.227: ISAKMP: MODECFG_BROWSER_PROXY
*Dec 6 15:27:21.227: ISAKMP: BACKUP_SERVER
*Dec 6 15:27:21.227: ISAKMP: MODECFG_SMARTCARD_REMOVAL_DISCONNECT
*Dec 6 15:27:21.227: ISAKMP: APPLICATION_VERSION
*Dec 6 15:27:21.227: ISAKMP: Client Version is : Cisco Systems VPN Client 5.0.07.0290:WinNTp
*Dec 6 15:27:21.227: ISAKMP: FW_RECORD
*Dec 6 15:27:21.227: ISAKMP: MODECFG_HOSTNAME
*Dec 6 15:27:21.227: ISAKMP: CONFIG_MODE_UNKNOWN Unknown Attr: 0x7005
*Dec 6 15:27:21.227: ISAKMP:(1013):ISAKMP/author: setting up the authorization request for cn=VPN,o=NXXI
*Dec 6 15:27:21.231: ISAKMP/author: Author request for group cn=VPN,o=NXXIsuccessfully sent to AAA
*Dec 6 15:27:21.231: ISAKMP:(1013):Input = IKE_MESG_FROM_PEER, IKE_CFG_REQUEST
*Dec 6 15:27:21.231: ISAKMP:(1013):Old State = IKE_P1_COMPLETE New State = IKE_CONFIG_AUTHOR_AAA_AWAIT
*Dec 6 15:27:21.231: AAA SRV(00000026): process author req
*Dec 6 15:27:21.231: AAA SRV(00000026): Author method=LOCAL
*Dec 6 15:27:21.231: AAA SRV(00000026): protocol reply PASS for Authorization
*Dec 6 15:27:21.231: AAA SRV(00000026): Return Authorization status=PASS
*Dec 6 15:27:21.231: ISAKMP:(0):ISAKMP/author: received callback from AAA
AAA/AUTHOR/IKE: Processing AV tunnel-password
AAA/AUTHOR/IKE: Processing AV default-domain
AAA/AUTHOR/IKE: Processing AV inacl
AAA/AUTHOR/IKE: Processing AV dns-servers
*Dec 6 15:27:21.231:
AAA/AUTHOR/IKE: no DNS addresses
AAA/AUTHOR/IKE: Processing AV wins-servers
*Dec 6 15:27:21.231:
AAA/AUTHOR/IKE: no WINS addresses
AAA/AUTHOR/IKE: Processing AV route-metric
AAA/AUTHOR/IKE: Processing AV netmask
*Dec 6 15:27:21.235: ISAKMP:(1013):ISAKMP/author: No Class attributes
*Dec 6 15:27:21.235: ISAKMP:(1013):attributes sent in message:
*Dec 6 15:27:21.235: Address: 0.2.0.0
*Dec 6 15:27:21.235: ISAKMP:(1013):No IP address pool defined for ISAKMP!
*Dec 6 15:27:21.235: ISAKMP:(1013):peer does not do paranoid keepalives.
*Dec 6 15:27:21.235: ISAKMP:(1013):peer does not do paranoid keepalives.
*Dec 6 15:27:21.235: ISAKMP:(1013):deleting SA reason "Fail to allocate ip address" state (R) CONF_ADDR (peer 10.55.5.19)
*Dec 6 15:27:21.235: ISAKMP: Sending subnet mask: 255.255.255.0
*Dec 6 15:27:21.235: ISAKMP: Sending ADDRESS_EXPIRY seconds left to use the address: 86394
*Dec 6 15:27:21.235: ISAKMP: Sending save password reply value 0
*Dec 6 15:27:21.235: ISAKMP: Sending DEFAULT_DOMAIN default domain name: nxx.hu
*Dec 6 15:27:21.235: ISAKMP: Sending split include name EZsplit network 10.54.0.0 mask 255.254.0.0 protocol 0, src port 0, dst port 0
*Dec 6 15:27:21.235: ISAKMP: Sending smartcard_removal_disconnect reply
value 0
*Dec 6 15:27:21.235: ISAKMP: Sending APPLICATION_VERSION string: Cisco IOS Software, 2801 Software (C2801-ADVSECURITYK9-M), Version 15.1(2)T1, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2010 by Cisco Systems, Inc.
Compiled Wed 11-Aug-10 13:13 by prod_rel_team
*Dec 6 15:27:21.235: ISAKMP (1013): Unknown Attr: MODECFG_HOSTNAME (0x700A)
*Dec 6 15:27:21.235: ISAKMP (1013): Unknown Attr: CONFIG_MODE_UNKNOWN (0x7005)
*Dec 6 15:27:21.235: ISAKMP:(1013): responding to peer config from 10.55.5.19. ID = -2081952537
*Dec 6 15:27:21.235: ISAKMP: Marking node -2081952537 for late deletion
*Dec 6 15:27:21.235: ISAKMP:(1013): sending packet to 10.55.5.19 my_port 500 peer_port 2341 (R) CONF_ADDR
*Dec 6 15:27:21.235: ISAKMP:(1013):Sending an IKE IPv4 Packet.
*Dec 6 15:27:21.239: ISAKMP:(1013):Talking to a Unity Client
*Dec 6 15:27:21.239: ISAKMP:(1013):Input = IKE_MESG_FROM_AAA, IKE_AAA_GROUP_ATTR
*Dec 6 15:27:21.239: ISAKMP:(1013):Old State = IKE_CONFIG_AUTHOR_AAA_AWAIT New State = IKE_P1_COMPLETE
*Dec 6 15:27:21.239: ISAKMP:FSM error - Message from AAA grp/user.
*Dec 6 15:27:21.239: ISAKMP: set new node 49472981 to QM_IDLE
*Dec 6 15:27:21.239: ISAKMP:(1013): sending packet to 10.55.5.19 my_port 500 peer_port 2341 (R) QM_IDLE
*Dec 6 15:27:21.239: ISAKMP:(1013):Sending an IKE IPv4 Packet.
*Dec 6 15:27:21.243: ISAKMP:(1013):purging node 49472981
*Dec 6 15:27:21.243: ISAKMP:(1013):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
*Dec 6 15:27:21.243: ISAKMP:(1013):Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA
*Dec 6 15:27:21.243: ISAKMP (1013): received packet from 10.55.5.19 dport 500 sport 2341 Global (R) QM_IDLE
*Dec 6 15:27:21.243: ISAKMP:(1013):deleting SA reason "No reason" state (R) QM_IDLE (peer 10.55.5.19)
*Dec 6 15:27:21.243: ISAKMP:(0):Can't decrement IKE Call Admission Control stat incoming_active since it's already 0.
*Dec 6 15:27:21.243: ISAKMP: Unlocking peer struct 0x67195BFC for isadb_mark_sa_deleted(), count 0
*Dec 6 15:27:21.243: ISAKMP: Deleting peer node by peer_reap for 10.55.5.19: 67195BFC
*Dec 6 15:27:21.247: ISAKMP:(1013):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Dec 6 15:27:21.247: ISAKMP:(1013):Old State = IKE_DEST_SA New State = IKE_DEST_SA
*Dec 6 15:27:21.255: ISAKMP:(1013):deleting SA reason "Fail to allocate ip address" state (R) MM_NO_STATE (peer 10.55.5.19)
*Dec 6 15:27:21.255: ISAKMP:(0):Can't decrement IKE Call Admission Control stat incoming_negotiating since it's already 0.
*Dec 6 15:27:21.255: ISAKMP:(1013):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Dec 6 15:27:21.255: ISAKMP:(1013):Old State = IKE_DEST_SA New State = IKE_DEST_SA
*Dec 6 15:27:23.787: ISAKMP:(1012):purging node 1250875168
It seems this LDAP server does not send a Password attribute which could be checked on the router. That’s why user password authentication requires a bind operation with U1 to the LDAP server which affects the search operation for the next connecting user. It seems the admin bind is overridden by the user bind (maybe an IOS bug) which makes life hard if rights of U1 are not sufficient to see the other user objects. In that case, the LDAP server returns no results to the search operation and the next user is unable to authenticate. I’m not finished with the investigation yet, but here are the key log lines:
filter (&(objectclass=*)(cn=u1)
*Oct 29 14:58:52.991: LDAP: dn 12 cn=U1,o=NXXI
*Oct 29 14:58:53.007: LDAP: LDAP Bind successful for DN:cn=U1,o=NXXI
filter (&(objectclass=*)(cn=u2)
*Oct 29 15:00:01.499: LDAP: Failed to get any search entries ldap_msgfree
The full config:
The full config:
version 15.1
no service pad
service tcp-keepalives-in
service tcp-keepalives-out
service timestamps debug datetime msec
service timestamps log datetime msec
service password-encryption
!
hostname Router_NXX
!
boot-start-marker
boot-end-marker
!
!
security authentication failure rate 3 log
security passwords min-length 6
logging buffered 51200 warnings
enable secret 5 $1$kiTr$cd/nW3Qr75Qpdrv6Nz8aU1
!
aaa new-model
!
!
aaa group server ldap Novell
server nw650
!
aaa authentication login default local
aaa authentication login local_authen local
aaa authentication login eDir group Novell local
aaa authentication login eDircli group Novell local
aaa authentication enable default enable
aaa authorization exec default group Novell local
aaa authorization exec local_author local
aaa authorization network eDir-author group Novell local
aaa authorization network loc-author local
!
!
!
!
!
aaa session-id common
!
clock timezone PCTime 1 0
clock summer-time PCTime date Mar 30 2003 2:00 Oct 26 2003 3:00
dot11 syslog
no ip source-route
!
!
no ip dhcp conflict logging
!
ip dhcp pool outside
network 1.2.136.0 255.255.255.248
!
!
!
ip cef
no ip bootp server
ip domain name nxx.hu
ip name-server 193.6.238.2
!
multilink bundle-name authenticated
!
crypto pki token default removal timeout 0
!
crypto pki trustpoint TP-self-signed-2035867573
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-2035867573
revocation-check none
rsakeypair TP-self-signed-2035867573
!
!
crypto pki certificate chain TP-self-signed-2035867573
certificate self-signed 01
30820249 308201B2 A0030201 02020101 300D0609 2A864886 F70D0101 04050030
31312F30 2D060355 04031326 494F532D 53656C66 2D536967 6E65642D 43657274
69666963 6174652D 32303335 38363735 3733301E 170D3038 30323134 31353530
31395A17 0D323030 31303130 30303030 305A3031 312F302D 06035504 03132649
4F532D53 656C662D 5369676E 65642D43 65727469 66696361 74652D32 30333538
36373537 3330819F 300D0609 2A864886 F70D0101 01050003 818D0030 81890281
8100C6CF 25230CAA 51D23E3D B5484828 5325B6F1 9BDE9661 801A93C3 112B6611
20933DD9 A15D0260 95C680E8 1BAB1AB7 A9D426B0 E12A28D9 EBD1EF8F 396EA3ED
BFD7353F B4BDCBC3 D01EDA4C 50BAA432 FD920E7F 7FED459B E22B09C2 25886E51
5BFC4E5E 8140BF65 C4FAFFB8 AFF73432 A3A76FA7 F6C57522 EBBD28A0 53BB2F0F
DD150203 010001A3 71306F30 0F060355 1D130101 FF040530 030101FF 301C0603
551D1104 15301382 11526F75 7465725F 4E4B412E 6E6B612E 6875301F 0603551D
23041830 16801426 870A60D7 970E9DC1 C7FC0BFF 8F867820 90D3BB30 1D060355
1D0E0416 04142687 0A60D797 0E9DC1C7 FC0BFF8F 86782090 D3BB300D 06092A86
4886F70D 01010405 00038181 008322CF 52F518D3 DFF0B8E4 F44F4CF0 2E15A785
0DD92E6C 1CAF600C F912A54A 46162E8C B0CBE282 0093AD91 7609D41E 1E9E7401
FB9BBAEC 44B9C9F5 90E40169 6C2A3FE4 87F3457A 36F271F9 B298ED39 84F69194
A043FFE5 F87F8AA6 D8AC79E7 FE916F40 F35B460B 557CF97E A7E4E08C D3E61AC6
6C2C59EA E740156A 04DDD061 8F
quit
!
!
license udi pid CISCO2801 sn FCZ1046xxxx
archive
log config
hidekeys
username userloc secret 5 $1$MJIG$up4X8gIhTvDJoYhFFjMqe/
!
redundancy
!
!
ip tcp synwait-time 10
!
!
crypto isakmp policy 10
encr aes
authentication pre-share
group 5
!
crypto isakmp policy 20
encr aes
authentication pre-share
group 2
!
crypto isakmp client configuration group RNXX-EZVPN
key pw1
domain nxx.hu
pool RNXX_Loopback1
acl EZsplit
netmask 255.255.255.0
banner ^C
HELLO
^C
!
crypto isakmp client configuration group cn=G1,o=AXX
key pw1
domain nxx.hu
pool RNXX_Loopback1
acl EZsplit
netmask 255.255.255.0
crypto isakmp client configuration group cn=VPN,o=NXXI
key pw1
domain nxx.hu
acl EZsplit
netmask 255.255.255.0
crypto isakmp profile EZVPN
match identity group cn=VPN,o=NXXI
match identity group RNXX-EZVPN
match identity group cn=UG,o=AXX
match identity group cn=G1,o=AXX
client authentication list eDir
isakmp authorization list loc-author
client configuration address respond
virtual-template 5
!
!
crypto ipsec transform-set RA esp-3des esp-md5-hmac
!
crypto ipsec profile EZ
set transform-set RA
set isakmp-profile EZVPN
!
!
!
!
!
!
interface Loopback1
ip address 192.168.102.1 255.255.255.0
!
interface Null0
no ip unreachables
!
interface FastEthernet0/0
description inside
ip address 10.55.5.150 255.255.255.0
no ip redirects
no ip unreachables
no ip proxy-arp
ip flow ingress
ip nat inside
ip virtual-reassembly in
duplex auto
speed auto
no mop enabled
!
interface FastEthernet0/1
description outside
ip address 1.2.136.2 255.255.255.248
no ip redirects
no ip unreachables
no ip proxy-arp
ip flow ingress
ip nat outside
ip virtual-reassembly in
duplex auto
speed auto
no mop enabled
!
interface Serial0/1/0
no ip address
no ip redirects
no ip unreachables
no ip proxy-arp
ip flow ingress
encapsulation frame-relay
shutdown
clock rate 2000000
!
interface Virtual-Template5 type tunnel
ip unnumbered Loopback1
tunnel mode ipsec ipv4
tunnel protection ipsec profile EZ
!
ip local pool RNXX_Loopback1 192.168.102.11 192.168.102.19
ip forward-protocol nd
!
!
ip http server
ip http authentication local
ip http secure-server
ip http timeout-policy idle 600 life 86400 requests 10000
ip nat inside source list 111 interface FastEthernet0/1 overload
ip route 0.0.0.0 0.0.0.0 1.2.136.1
!
ip access-list extended EZsplit
permit ip 10.54.0.0 0.1.255.255 any
!
logging esm config
logging trap debugging
access-list 1 remark HTTP Access-class list
access-list 1 remark SDM_ACL Category=1
access-list 1 deny any
access-list 100 remark VTY Access-class list
access-list 100 remark SDM_ACL Category=1
access-list 100 deny ip any any
no cdp run
!
!
!
!
!
ldap attribute-map map1
map type groupMembership user-vpn-group
!
ldap server nw650
ipv4 10.55.5.223
attribute map map1
bind authenticate root-dn cn=admin,o=AXX password xxx
base-dn o=AXX
search-filter user-object-type User
!
!
control-plane
!
alias exec r sh run
alias exec n sh ip nat tra
alias exec i sh ip route
banner login ^CAuthorized access only!
Disconnect IMMEDIATELY if you are not an authorized user!^C
!
line con 0
login authentication local_authen
transport output telnet
line aux 0
login authentication local_authen
transport output telnet
line vty 0 4
exec-timeout 1200 0
privilege level 15
authorization exec local_author
login authentication local_authen
transport input telnet ssh
line vty 5 15
access-class 100 in
authorization exec local_author
login authentication local_authen
transport input all
!
scheduler allocate 20000 1000
end
Versions:
IOS c2801-advsecurityk9-mz.151-2.T1.bin
Cisco VPN client 5.0.07.0290 on XP
Novell Netware 6.50
eDirectory
