Remote access vpn with avaya ip phone

Unanswered Question
Aug 16th, 2010

i have cisco 1841 router and i configured a remote access vpn on it to support both laptops and avaya ip phones.

the laptops are working without problem on the vpn and connected.

but when the ip phone try to connect i get error connecting to the vpn and i get these debugs from my router:

-================================================================================


*Aug 16 11:24:36.525: ISAKMP (0:0): received packet from 41.178.127.178 dport 500 sport 500 Global (N) NEW SA
*Aug 16 11:24:36.525: ISAKMP: Created a peer struct for 41.178.127.178, peer port 500
*Aug 16 11:24:36.525: ISAKMP: New peer created peer = 0x639906A0 peer_handle = 0x80000055
*Aug 16 11:24:36.525: ISAKMP: Locking peer struct 0x639906A0, IKE refcount 1 for crypto_isakmp_process_block
*Aug 16 11:24:36.525: ISAKMP:(0:0:N/A:0):Setting client config settings 6385BEAC
*Aug 16 11:24:36.525: ISAKMP:(0:0:N/A:0):(Re)Setting client xauth list  and state
*Aug 16 11:24:36.525: ISAKMP/xauth: initializing AAA request
*Aug 16 11:24:36.529: ISAKMP: local port 500, remote port 500
*Aug 16 11:24:36.529: insert sa successfully sa = 637BC888
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0): processing SA payload. message ID = 0
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0): processing ID payload. message ID = 0
*Aug 16 11:24:36.529: ISAKMP (0:0): ID payload
    next-payload : 13
    type         : 11
    group id     : VPN
    protocol     : 0
    port         : 0
    length       : 18
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0):: peer matches *none* of the profiles
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0): processing vendor id payload
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0): vendor ID seems Unity/DPD but major 253 mismatch
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0): vendor ID is XAUTH
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0): Authentication by xauth preshared
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0):Checking ISAKMP transform 1 against priority 1 policy
*Aug 16 11:24:36.529: ISAKMP:      encryption 3DES-CBC
*Aug 16 11:24:36.529: ISAKMP:      hash SHA
*Aug 16 11:24:36.529: ISAKMP:      default group 2
*Aug 16 11:24:36.529: ISAKMP:      auth XAUTHInitPreShared
*Aug 16 11:24:36.529: ISAKMP:      life type in seconds
*Aug 16 11:24:36.529: ISAKMP:      life duration (basic) of 1
*Aug 16 11:24:36.529: ISAKMP:(0:0:N/A:0):atts are acceptable. Next payload is 0
*Aug 16 11:24:36.589: ISAKMP:(0:31:SW:1): processing KE payload. message ID = 0
*Aug 16 11:24:36.661: ISAKMP:(0:31:SW:1): processing NONCE payload. message ID = 0
*Aug 16 11:24:36.661: ISAKMP:(0:31:SW:1): processing vendor id payload
*Aug 16 11:24:36.661: ISAKMP:(0:31:SW:1): vendor ID seems Unity/DPD but major 253 mismatch
*Aug 16 11:24:36.665: ISAKMP:(0:31:SW:1): vendor ID is XAUTH
*Aug 16 11:24:36.665: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Aug 16 11:24:36.665: ISAKMP:(0:31:SW:1):Old State = IKE_READY  New State = IKE_R_AM_AAA_AWAIT

*Aug 16 11:24:36.669: ISAKMP:(0:31:SW:1):SKEYID state generated
*Aug 16 11:24:36.669: ISAKMP:(0:31:SW:1):SA is doing pre-shared key authentication plus XAUTH using id type ID_IPV4_ADDR
*Aug 16 11:24:36.669: ISAKMP (0:134217759): ID payload
    next-payload : 10
    type         : 1
    address      : 82.201.136.45
    protocol     : 0
    port         : 0
    length       : 12
*Aug 16 11:24:36.669: ISAKMP:(0:31:SW:1):Total payload length: 12
*Aug 16 11:24:36.669: ISAKMP:(0:31:SW:1): sending packet to 41.178.127.178 my_port 500 peer_port 500 (R) AG_INIT_EXCH
*Aug 16 11:24:36.669: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_AAA, PRESHARED_KEY_REPLY
*Aug 16 11:24:36.669: ISAKMP:(0:31:SW:1):Old State = IKE_R_AM_AAA_AWAIT  New State = IKE_R_AM2

*Aug 16 11:24:37.165: ISAKMP (0:134217759): received packet from 41.178.127.178 dport 500 sport 500 Global (R) AG_INIT_EXCH
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1): processing HASH payload. message ID = 0
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1): processing NOTIFY INITIAL_CONTACT protocol 1
    spi 0, message ID = 0, sa = 637BC888
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1):SA authentication status:
    authenticated
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1): Process initial contact,
bring down existing phase 1 and 2 SA's with local 82.201.136.45 remote 41.178.127.178 remote port 500
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1):returning IP addr to the address pool
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1):SA authentication status:
    authenticated
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1):SA has been authenticated with 41.178.127.178
*Aug 16 11:24:37.169: ISAKMP: Trying to insert a peer 82.201.136.45/41.178.127.178/500/,  and inserted successfully 639906A0.
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
*Aug 16 11:24:37.169: ISAKMP:(0:31:SW:1):Old State = IKE_R_AM2  New State = IKE_P1_COMPLETE

*Aug 16 11:24:37.173: IPSEC(key_engine): got a queue event with 1 kei messages
*Aug 16 11:24:37.173: ISAKMP:(0:31:SW:1):Need XAUTH
*Aug 16 11:24:37.173: ISAKMP: set new node -863844432 to CONF_XAUTH  
*Aug 16 11:24:37.173: ISAKMP/xauth: request attribute XAUTH_USER_NAME_V2
*Aug 16 11:24:37.173: ISAKMP/xauth: request attribute XAUTH_USER_PASSWORD_V2
*Aug 16 11:24:37.173: ISAKMP:(0:31:SW:1): initiating peer config to 41.178.127.178. ID = -863844432
*Aug 16 11:24:37.177: ISAKMP:(0:31:SW:1): sending packet to 41.178.127.178 my_port 500 peer_port 500 (R) CONF_XAUTH  
*Aug 16 11:24:37.177: ISAKMP:(0:31:SW:1):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Aug 16 11:24:37.177: ISAKMP:(0:31:SW:1):Old State = IKE_P1_COMPLETE  New State = IKE_XAUTH_REQ_SENT

*Aug 16 11:24:37.193: ISAKMP (0:134217759): received packet from 41.178.127.178 dport 500 sport 500 Global (R) CONF_XAUTH  
*Aug 16 11:24:37.193: ISAKMP:(0:31:SW:1):processing transaction payload from 41.178.127.178. message ID = -863844432
*Aug 16 11:24:37.193: ISAKMP: Config payload REPLY
*Aug 16 11:24:37.193: ISAKMP/xauth: reply attribute XAUTH_USER_NAME_V2
*Aug 16 11:24:37.197: ISAKMP/xauth: reply attribute XAUTH_USER_PASSWORD_V2
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1):deleting node -863844432 error FALSE reason "Done with xauth request/reply exchange"
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_PEER, IKE_CFG_REPLY
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1):Old State = IKE_XAUTH_REQ_SENT  New State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT

*Aug 16 11:24:37.197: ISAKMP: set new node -901224261 to CONF_XAUTH  
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1): initiating peer config to 41.178.127.178. ID = -901224261
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1): sending packet to 41.178.127.178 my_port 500 peer_port 500 (R) CONF_XAUTH  
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_AAA, IKE_AAA_CONT_LOGIN
*Aug 16 11:24:37.197: ISAKMP:(0:31:SW:1):Old State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT  New State = IKE_XAUTH_SET_SENT

*Aug 16 11:24:37.213: ISAKMP (0:134217759): received packet from 41.178.127.178 dport 500 sport 500 Global (R) CONF_XAUTH  
*Aug 16 11:24:37.213: ISAKMP:(0:31:SW:1):processing transaction payload from 41.178.127.178. message ID = -901224261
*Aug 16 11:24:37.213: ISAKMP: Config payload ACK
*Aug 16 11:24:37.213: ISAKMP:(0:31:SW:1):       XAUTH ACK Processed
*Aug 16 11:24:37.213: ISAKMP:(0:31:SW:1):deleting node -901224261 error FALSE reason "Transaction mode done"
*Aug 16 11:24:37.213: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_PEER, IKE_CFG_ACK
*Aug 16 11:24:37.213: ISAKMP:(0:31:SW:1):Old State = IKE_XAUTH_SET_SENT  New State = IKE_P1_COMPLETE

*Aug 16 11:24:37.217: ISAKMP:(0:31:SW:1):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Aug 16 11:24:37.217: ISAKMP:(0:31:SW:1):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

*Aug 16 11:24:37.233: ISAKMP (0:134217759): received packet from 41.178.127.178 dport 500 sport 500 Global (R) QM_IDLE     
*Aug 16 11:24:37.233: ISAKMP: set new node -255047405 to QM_IDLE     
*Aug 16 11:24:37.233: ISAKMP:(0:31:SW:1):processing transaction payload from 41.178.127.178. message ID = -255047405
*Aug 16 11:24:37.237: ISAKMP: Config payload REQUEST
*Aug 16 11:24:37.237: ISAKMP:(0:31:SW:1):checking request:
*Aug 16 11:24:37.237: ISAKMP:    IP4_ADDRESS
*Aug 16 11:24:37.237: ISAKMP:    IP4_NETMASK
*Aug 16 11:24:37.237: ISAKMP:    IP4_DNS
*Aug 16 11:24:37.237: ISAKMP:    IP4_NBNS
*Aug 16 11:24:37.237: ISAKMP:    ADDRESS_EXPIRY
*Aug 16 11:24:37.237: ISAKMP:    IP4_DHCP
*Aug 16 11:24:37.237: ISAKMP:    APPLICATION_VERSION
*Aug 16 11:24:37.237: ISAKMP:    UNKNOWN Unknown Attr: 0x7000
*Aug 16 11:24:37.237: ISAKMP:    MODECFG_SAVEPWD
*Aug 16 11:24:37.237: ISAKMP:    DEFAULT_DOMAIN
*Aug 16 11:24:37.237: ISAKMP:    SPLIT_DNS
*Aug 16 11:24:37.237: ISAKMP:    SPLIT_INCLUDE
*Aug 16 11:24:37.237: ISAKMP:    PFS
*Aug 16 11:24:37.237: ISAKMP:    BACKUP_SERVER
*Aug 16 11:24:37.237: ISAKMP:    UNKNOWN Unknown Attr: 0x700A
*Aug 16 11:24:37.237: ISAKMP/author: Author request for group KiriaziVPNsuccessfully sent to AAA
*Aug 16 11:24:37.237: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_PEER, IKE_CFG_REQUEST
*Aug 16 11:24:37.237: ISAKMP:(0:31:SW:1):Old State = IKE_P1_COMPLETE  New State = IKE_CONFIG_AUTHOR_AAA_AWAIT

*Aug 16 11:24:37.241: ISAKMP:(0:31:SW:1):attributes sent in message:
*Aug 16 11:24:37.241:         Address: 0.0.0.0
*Aug 16 11:24:37.241: ISAKMP:(0:31:SW:1):allocating address 10.2.3.19
*Aug 16 11:24:37.241: ISAKMP: Sending private address: 10.2.3.19
*Aug 16 11:24:37.241: ISAKMP: Sending subnet mask: 255.255.255.0
*Aug 16 11:24:37.241: ISAKMP: Sending ADDRESS_EXPIRY seconds left to use the address: 0
*Aug 16 11:24:37.241: ISAKMP (0/134217759): Unknown Attr: IP4_DHCP (0x6)
*Aug 16 11:24:37.241: ISAKMP: Sending APPLICATION_VERSION string: Cisco IOS Software, 1841 Software (C1841-ADVSECURITYK9-M), Version 12.4(25a), RELEASE SOFTWARE (fc2)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2009 by Cisco Systems, Inc.
Compiled Fri 22-May-09 20:52 by prod_rel_team
*Aug 16 11:24:37.241: ISAKMP (0/134217759): Unknown Attr: UNKNOWN (0x7000)
*Aug 16 11:24:37.241: ISAKMP: Sending save password reply value 0
*Aug 16 11:24:37.241: ISAKMP: Sending split include name 101 network 10.1.20.0 mask 255.255.255.0 protocol 0, src port 0, dst port 0

*Aug 16 11:24:37.241: ISAKMP: Sending split include name 101 network 10.2.2.0 mask 255.255.255.0 protocol 0, src port 0, dst port 0

*Aug 16 11:24:37.241: ISAKMP: Sending split include name 101 network 10.1.1.0 mask 255.255.255.0 protocol 0, src port 0, dst port 0

*Aug 16 11:24:37.241: ISAKMP: Sending split include name 101 network 10.1.2.0 mask 255.255.255.0 protocol 0, src port 0, dst port 0

*Aug 16 11:24:37.241: ISAKMP: Sending split include name 101 network 10.1.10.0 mask 255.255.255.0 protocol 0, src port 0, dst port 0

*Aug 16 11:24:37.241: ISAKMP (0/134217759): Unknown Attr: UNKNOWN (0x700A)
*Aug 16 11:24:37.241: ISAKMP:(0:31:SW:1): responding to peer config from 41.178.127.178. ID = -255047405
*Aug 16 11:24:37.241: ISAKMP:(0:31:SW:1): sending packet to 41.178.127.178 my_port 500 peer_port 500 (R) CONF_ADDR   
*Aug 16 11:24:37.245: ISAKMP:(0:31:SW:1):deleting node -255047405 error FALSE reason "No Error"
*Aug 16 11:24:37.245: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_AAA, IKE_AAA_GROUP_ATTR
*Aug 16 11:24:37.245: ISAKMP:(0:31:SW:1):Old State = IKE_CONFIG_AUTHOR_AAA_AWAIT  New State = IKE_P1_COMPLETE

*Aug 16 11:24:37.245: ISAKMP:(0:31:SW:1):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
*Aug 16 11:24:37.245: ISAKMP:(0:31:SW:1):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1):peer does not do paranoid keepalives.

*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1):deleting SA reason "IKE SA Lifetime Exceeded" state (R) QM_IDLE       (peer 41.178.127.178)
*Aug 16 11:24:37.529: ISAKMP: set new node -2071744717 to QM_IDLE     
*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1): sending packet to 41.178.127.178 my_port 500 peer_port 500 (R) QM_IDLE     
*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1):purging node -2071744717
*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1):Old State = IKE_P1_COMPLETE  New State = IKE_DEST_SA

*Aug 16 11:24:37.533: ISAKMP:(0:31:SW:1):deleting SA reason "No reason" state (R) QM_IDLE       (peer 41.178.127.178)
*Aug 16 11:24:37.533: ISAKMP:(0:0:N/A:0):Can't decrement IKE Call Admisstion Control stat incoming_active since it's already 0.
*Aug 16 11:24:37.533: ISAKMP (0:134217759): returning address 10.2.3.19 to pool
*Aug 16 11:24:37.533: ISAKMP: Unlocking IKE struct 0x639906A0 for isadb_mark_sa_deleted(), count 0
*Aug 16 11:24:37.533: ISAKMP: returning address 10.2.3.19 to pool
*Aug 16 11:24:37.533: ISAKMP: Deleting peer node by peer_reap for 41.178.127.178: 639906A0
*Aug 16 11:24:37.533: ISAKMP: returning address 10.2.3.19 to pool
*Aug 16 11:24:37.533: ISAKMP:(0:31:SW:1):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
*Aug 16 11:24:37.533: ISAKMP:(0:31:SW:1):Old State = IKE_DEST_SA  New State = IKE_DEST_SA

*Aug 16 11:24:37.537: IPSEC(key_engine): got a queue event with 1 kei messages

==========================================================

please advise

I have this problem too.
0 votes
  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.
praprama Mon, 08/16/2010 - 05:33

Hi,

The Phase 1 policy negotiated between the client and the router is as below:

*Aug 16 11:24:36.529: ISAKMP:      encryption 3DES-CBC
*Aug 16  11:24:36.529: ISAKMP:      hash SHA
*Aug 16 11:24:36.529:  ISAKMP:      default group 2
*Aug 16 11:24:36.529: ISAKMP:      auth  XAUTHInitPreShared
*Aug 16 11:24:36.529: ISAKMP:      life type in  seconds
*Aug 16 11:24:36.529: ISAKMP:      life duration (basic) of 1
*Aug  16 11:24:36.529: ISAKMP:(0:0:N/A:0):atts are acceptable.

So the lifetime negotiated is 1 second and this is exactly the reason why exactly a second after the above messages, we see the below message:

*Aug 16 11:24:37.529: ISAKMP:(0:31:SW:1):deleting SA reason "IKE SA  Lifetime Exceeded" state (R) QM_IDLE       (peer 41.178.127.178)

Please do attach the current configuration from the router (or the output of show crypto isakmp policy) and we can see why exactly the above is happening.

All the best!!

Regards,

Prapanch

Actions

This Discussion