Buy or Renew
Buy or Renew
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
2597
Views
0
Helpful
6
Replies

L2TP/IPSEC with ms-chap-v2 on 871 not workling

ps0000000
Level 1
Level 1

‎06-24-2019 05:17 AM

Hello all, I am really going mad configuring remote access for users with L2TP/IPSEC. When I am using PAP or CHAP authentication everything goes smooth and well. But when I switch to MS-CHAP-V2 I got an error. I have already read similar post with no success. So please help me figure out where I am wrong.

My config as follows:

version 15.1
no service pad
service timestamps debug datetime msec
service timestamps log datetime msec localtime show-timezone
no service password-encryption
!
hostname Home871
!
boot-start-marker
boot-end-marker
!
logging buffered 10000
enable secret 5 $1$rTHJ$UvXLIa0azKQpv7m1VSsmA0
!
aaa new-model
!
aaa authentication ppp VPDN_AUTH local
!
aaa session-id common
crypto pki token default removal timeout 0
!
dot11 syslog
ip source-route
ip dhcp excluded-address 192.168.10.1 192.168.10.10
ip dhcp excluded-address 192.168.10.240 192.168.10.254
!
ip dhcp pool 192.168.10
 network 192.168.10.0 255.255.255.0
 default-router 192.168.10.1
 dns-server 192.168.1.1 192.168.5.1
!
ip cef
no ip domain lookup
!
vpdn enable
!
vpdn-group L2TP
 ! Default L2TP VPDN group
 accept-dialin
  protocol l2tp
  virtual-template 1
 no l2tp tunnel authentication
!
archive
 log config
  hidekeys
username admin privilege 15 password 0 111111
username vpn password 0 222222
username vpn1 secret 5 $1$KK0M$8y0gNfbwkaXk9JX4cWCC9.
!
track 11 ip sla 1 reachability
!
track 22 ip sla 2 reachability
!
crypto isakmp policy 1
 encr 3des
 authentication pre-share
 group 2
crypto isakmp key Cisco123 address 0.0.0.0 0.0.0.0
!
crypto ipsec transform-set L2TP-Set2 esp-3des esp-sha-hmac
 mode transport
!
crypto dynamic-map dyn-map 10
 set nat demux
 set transform-set L2TP-Set2
!
crypto map outside_map 65535 ipsec-isakmp dynamic dyn-map
!
interface Loopback201
 description loopback for IPsec-pool
 ip address 10.153.201.254 255.255.255.255
!
interface FastEthernet0
 switchport access vlan 100
 no ip address
!
interface FastEthernet1
 switchport access vlan 5
 no ip address
!
interface FastEthernet2
 no ip address
!
interface FastEthernet3
 no ip address
!
interface FastEthernet4
 ip address 192.168.1.9 255.255.255.0
 ip nat outside
 ip virtual-reassembly in
 duplex auto
 speed auto
 crypto map outside_map
!
interface Virtual-Template1
 ip unnumbered Loopback201
 peer default ip address pool l2tp-pool
 ppp authentication ms-chap-v2 VPDN_AUTH
!
interface Vlan1
 no ip address
!
interface Vlan5
 ip address 192.168.5.9 255.255.255.0
 ip nat outside
 ip virtual-reassembly in
!
interface Vlan100
 description LocalLAN
 ip address 192.168.10.1 255.255.255.0
 ip nat inside
 ip virtual-reassembly in
!
ip local pool l2tp-pool 10.153.201.100 10.153.201.200
ip forward-protocol nd
ip http server
ip http authentication local
ip http secure-server
!
ip nat inside source route-map ISP2 interface Vlan5 overload
ip nat inside source route-map ISP1 interface FastEthernet4 overload
ip nat inside source static udp 192.168.10.9 17566 192.168.1.9 17566 extendable
ip nat inside source static udp 192.168.10.9 17566 192.168.5.9 17566 extendable
ip route 0.0.0.0 0.0.0.0 192.168.5.1 track 11
ip route 0.0.0.0 0.0.0.0 192.168.1.1 171
ip route 8.8.4.4 255.255.255.255 192.168.5.1
ip route 192.168.99.0 255.255.255.0 192.168.5.1
!
ip sla 1
 icmp-echo 8.8.4.4 source-interface Vlan5
 frequency 10
 timeout 10000
 threshold 10000
ip sla schedule 1 life forever start-time now
ip sla 2
 icmp-echo 8.8.8.8 source-interface FastEthernet4
 frequency 10
 timeout 10000
 threshold 10000
ip sla schedule 2 life forever start-time now
logging esm config
logging trap notifications
logging facility local3
logging source-interface Vlan100
access-list 20 permit 10.153.70.0 0.0.0.255
access-list 20 permit 10.153.70.0 0.0.0.63
access-list 20 permit 10.129.122.0 0.0.0.128
access-list 20 permit 10.10.117.0 0.0.0.255
access-list 20 permit 10.129.122.0 0.0.0.255
access-list 30 permit 192.168.10.0 0.0.0.255
access-list 69 permit 10.153.70.20
access-list 69 permit 10.153.70.9
access-list 80 permit 10.153.70.0 0.0.0.255
access-list 80 permit 10.153.200.0 0.0.0.255
access-list 80 permit 109.252.0.0 0.0.127.255
access-list 80 permit 31.173.0.0 0.0.255.255
access-list 80 permit 10.129.122.0 0.0.0.255
!
!
!
route-map ISP1 permit 10
 match ip address 30
 match interface FastEthernet4
!
route-map ISP2 permit 10
 match ip address 30
 match interface Vlan5
!
!
!
!
control-plane
!
!
line con 0
 no modem enable
line aux 0
line vty 0 4
 privilege level 15
 transport input ssh
!
scheduler max-task-time 5000
scheduler allocate 20000 1000
end

And got following debug log:

Jun 24 11:46:47.848: ISAKMP (0): received packet from 192.168.1.26 dport 500 sport 500 Global (N) NEW SA
Jun 24 11:46:47.848: ISAKMP: Created a peer struct for 192.168.1.26, peer port 500
Jun 24 11:46:47.848: ISAKMP: New peer created peer = 0x85BC8B58 peer_handle = 0x8000002E
Jun 24 11:46:47.848: ISAKMP: Locking peer struct 0x85BC8B58, refcount 1 for crypto_isakmp_process_block
Jun 24 11:46:47.848: ISAKMP: local port 500, remote port 500
Jun 24 11:46:47.848: ISAKMP:(0):insert sa successfully sa = 83A10C50
Jun 24 11:46:47.848: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jun 24 11:46:47.852: ISAKMP:(0):Old State = IKE_READY  New State = IKE_R_MM1

Jun 24 11:46:47.852: ISAKMP:(0): processing SA payload. message ID = 0
Jun 24 11:46:47.852: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0): processing IKE frag vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0):Support for IKE Fragmentation not enabled
Jun 24 11:46:47.852: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0): processing IKE frag vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0):Support for IKE Fragmentation not enabled
Jun 24 11:46:47.852: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Jun 24 11:46:47.852: ISAKMP (0): vendor ID is NAT-T RFC 3947
Jun 24 11:46:47.852: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Jun 24 11:46:47.852: ISAKMP:(0): vendor ID is NAT-T v2
Jun 24 11:46:47.852: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0): vendor ID seems Unity/DPD but major 194 mismatch
Jun 24 11:46:47.852: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.852: ISAKMP:(0): vendor ID seems Unity/DPD but major 241 mismatch
Jun 24 11:46:47.856: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.856: ISAKMP:(0): vendor ID seems Unity/DPD but major 184 mismatch
Jun 24 11:46:47.856: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.856: ISAKMP:(0): vendor ID seems Unity/DPD but major 134 mismatch
Jun 24 11:46:47.856: ISAKMP:(0):found peer pre-shared key matching 192.168.1.26
Jun 24 11:46:47.856: ISAKMP:(0): local preshared key found
Jun 24 11:46:47.856: ISAKMP : Scanning profiles for xauth ...
Jun 24 11:46:47.856: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy
Jun 24 11:46:47.856: ISAKMP:      encryption AES-CBC
Jun 24 11:46:47.856: ISAKMP:      keylength of 256
Jun 24 11:46:47.856: ISAKMP:      hash SHA
Jun 24 11:46:47.856: ISAKMP:      default group 20
Jun 24 11:46:47.856: ISAKMP:      auth pre-share
Jun 24 11:46:47.856: ISAKMP:      life type in seconds
Jun 24 11:46:47.856: ISAKMP:      life duration (VPI) of  0x0 0x0 0x70 0x80
Jun 24 11:46:47.856: ISAKMP:(0):Encryption algorithm offered does not match policy!
Jun 24 11:46:47.856: ISAKMP:(0):atts are not acceptable. Next payload is 3
Jun 24 11:46:47.856: ISAKMP:(0):Checking ISAKMP transform 2 against priority 1 policy
Jun 24 11:46:47.856: ISAKMP:      encryption AES-CBC
Jun 24 11:46:47.856: ISAKMP:      keylength of 128
Jun 24 11:46:47.856: ISAKMP:      hash SHA
Jun 24 11:46:47.856: ISAKMP:      default group 19
Jun 24 11:46:47.856: ISAKMP:      auth pre-share
Jun 24 11:46:47.856: ISAKMP:      life type in seconds
Jun 24 11:46:47.860: ISAKMP:      life duration (VPI) of  0x0 0x0 0x70 0x80
Jun 24 11:46:47.860: ISAKMP:(0):Encryption algorithm offered does not match policy!
Jun 24 11:46:47.860: ISAKMP:(0):atts are not acceptable. Next payload is 3
Jun 24 11:46:47.860: ISAKMP:(0):Checking ISAKMP transform 3 against priority 1 policy
Jun 24 11:46:47.860: ISAKMP:      encryption AES-CBC
Jun 24 11:46:47.860: ISAKMP:      keylength of 256
Jun 24 11:46:47.860: ISAKMP:      hash SHA
Jun 24 11:46:47.860: ISAKMP:      default group 14
Jun 24 11:46:47.860: ISAKMP:      auth pre-share
Jun 24 11:46:47.860: ISAKMP:      life type in seconds
Jun 24 11:46:47.860: ISAKMP:      life duration (VPI) of  0x0 0x0 0x70 0x80
Jun 24 11:46:47.860: ISAKMP:(0):Encryption algorithm offered does not match policy!
Jun 24 11:46:47.860: ISAKMP:(0):atts are not acceptable. Next payload is 3
Jun 24 11:46:47.860: ISAKMP:(0):Checking ISAKMP transform 4 against priority 1 policy
Jun 24 11:46:47.860: ISAKMP:      encryption 3DES-CBC
Jun 24 11:46:47.860: ISAKMP:      hash SHA
Jun 24 11:46:47.860: ISAKMP:      default group 14
Jun 24 11:46:47.860: ISAKMP:      auth pre-share
Jun 24 11:46:47.860: ISAKMP:      life type in seconds
Jun 24 11:46:47.860: ISAKMP:      life duration (VPI) of  0x0 0x0 0x70 0x80
Jun 24 11:46:47.860: ISAKMP:(0):Diffie-Hellman group offered does not match policy!
Jun 24 11:46:47.860: ISAKMP:(0):atts are not acceptable. Next payload is 3
Jun 24 11:46:47.860: ISAKMP:(0):Checking ISAKMP transform 5 against priority 1 policy
Jun 24 11:46:47.864: ISAKMP:      encryption 3DES-CBC
Jun 24 11:46:47.864: ISAKMP:      hash SHA
Jun 24 11:46:47.864: ISAKMP:      default group 2
Jun 24 11:46:47.864: ISAKMP:      auth pre-share
Jun 24 11:46:47.864: ISAKMP:      life type in seconds
Jun 24 11:46:47.864: ISAKMP:      life duration (VPI) of  0x0 0x0 0x70 0x80
Jun 24 11:46:47.864: ISAKMP:(0):atts are acceptable. Next payload is 0
Jun 24 11:46:47.864: ISAKMP:(0):Acceptable atts:actual life: 0
Jun 24 11:46:47.864: ISAKMP:(0):Acceptable atts:life: 0
Jun 24 11:46:47.864: ISAKMP:(0):Fill atts in sa vpi_length:4
Jun 24 11:46:47.864: ISAKMP:(0):Fill atts in sa life_in_seconds:28800
Jun 24 11:46:47.864: ISAKMP:(0):Returning Actual lifetime: 28800
Jun 24 11:46:47.864: ISAKMP:(0)::Started lifetime timer: 28800.

Jun 24 11:46:47.864: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.864: ISAKMP:(0): processing IKE frag vendor id payload
Jun 24 11:46:47.864: ISAKMP:(0):Support for IKE Fragmentation not enabled
Jun 24 11:46:47.864: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.864: ISAKMP:(0): processing IKE frag vendor id payload
Jun 24 11:46:47.864: ISAKMP:(0):Support for IKE Fragmentation not enabled
Jun 24 11:46:47.864: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.864: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Jun 24 11:46:47.864: ISAKMP (0): vendor ID is NAT-T RFC 3947
Jun 24 11:46:47.864: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.864: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Jun 24 11:46:47.868: ISAKMP:(0): vendor ID is NAT-T v2
Jun 24 11:46:47.868: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.868: ISAKMP:(0): vendor ID seems Unity/DPD but major 194 mismatch
Jun 24 11:46:47.868: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.868: ISAKMP:(0): vendor ID seems Unity/DPD but major 241 mismatch
Jun 24 11:46:47.868: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.868: ISAKMP:(0): vendor ID seems Unity/DPD but major 184 mismatch
Jun 24 11:46:47.868: ISAKMP:(0): processing vendor id payload
Jun 24 11:46:47.868: ISAKMP:(0): vendor ID seems Unity/DPD but major 134 mismatch
Jun 24 11:46:47.868: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jun 24 11:46:47.868: ISAKMP:(0):Old State = IKE_R_MM1  New State = IKE_R_MM1

Jun 24 11:46:47.868: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID
Jun 24 11:46:47.868: ISAKMP:(0): sending packet to 192.168.1.26 my_port 500 peer_port 500 (R) MM_SA_SETUP
Jun 24 11:46:47.868: ISAKMP:(0):Sending an IKE IPv4 Packet.
Jun 24 11:46:47.872: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jun 24 11:46:47.872: ISAKMP:(0):Old State = IKE_R_MM1  New State = IKE_R_MM2

Jun 24 11:46:47.872: ISAKMP (0): received packet from 192.168.1.26 dport 500 sport 500 Global (R) MM_SA_SETUP
Jun 24 11:46:47.876: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jun 24 11:46:47.876: ISAKMP:(0):Old State = IKE_R_MM2  New State = IKE_R_MM3

Jun 24 11:46:47.876: ISAKMP:(0): processing KE payload. message ID = 0
Jun 24 11:46:47.920: ISAKMP:(0): processing NONCE payload. message ID = 0
Jun 24 11:46:47.920: ISAKMP:(0):found peer pre-shared key matching 192.168.1.26
Jun 24 11:46:47.924: ISAKMP:received payload type 20
Jun 24 11:46:47.924: ISAKMP (2050): His hash no match - this node outside NAT
Jun 24 11:46:47.924: ISAKMP:received payload type 20
Jun 24 11:46:47.924: ISAKMP (2050): No NAT Found for self or peer
Jun 24 11:46:47.924: ISAKMP:(2050):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jun 24 11:46:47.924: ISAKMP:(2050):Old State = IKE_R_MM3  New State = IKE_R_MM3

Jun 24 11:46:47.924: ISAKMP:(2050): sending packet to 192.168.1.26 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Jun 24 11:46:47.924: ISAKMP:(2050):Sending an IKE IPv4 Packet.
Jun 24 11:46:47.924: ISAKMP:(2050):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jun 24 11:46:47.924: ISAKMP:(2050):Old State = IKE_R_MM3  New State = IKE_R_MM4

Jun 24 11:46:47.932: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) MM_KEY_EXCH
Jun 24 11:46:47.932: ISAKMP:(2050):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jun 24 11:46:47.932: ISAKMP:(2050):Old State = IKE_R_MM4  New State = IKE_R_MM5

Jun 24 11:46:47.932: ISAKMP:(2050): processing ID payload. message ID = 0
Jun 24 11:46:47.932: ISAKMP (2050): ID payload
        next-payload : 8
        type         : 1
        address      : 192.168.1.26
        protocol     : 0
        port         : 0
        length       : 12
Jun 24 11:46:47.932: ISAKMP:(0):: peer matches *none* of the profiles
Jun 24 11:46:47.932: ISAKMP:(2050): processing HASH payload. message ID = 0
Jun 24 11:46:47.932: ISAKMP:(2050):SA authentication status:
        authenticated
Jun 24 11:46:47.936: ISAKMP:(2050):SA has been authenticated with 192.168.1.26
Jun 24 11:46:47.936: ISAKMP: Trying to insert a peer 192.168.1.9/192.168.1.26/500/,  and inserted successfully 85BC8B58.
Jun 24 11:46:47.936: ISAKMP AAA: Accounting is not enabled
Jun 24 11:46:47.936: ISAKMP:(2050):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
Jun 24 11:46:47.936: ISAKMP:(2050):Old State = IKE_R_MM5  New State = IKE_R_MM5

Jun 24 11:46:47.936: ISAKMP:(2050):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
Jun 24 11:46:47.936: ISAKMP (2050): ID payload
        next-payload : 8
        type         : 1
        address      : 192.168.1.9
        protocol     : 17
        port         : 500
        length       : 12
Jun 24 11:46:47.936: ISAKMP:(2050):Total payload length: 12
Jun 24 11:46:47.940: ISAKMP:(2050): sending packet to 192.168.1.26 my_port 500 peer_port 500 (R) MM_KEY_EXCH
Jun 24 11:46:47.940: ISAKMP:(2050):Sending an IKE IPv4 Packet.
Jun 24 11:46:47.940: ISAKMP:(2050):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
Jun 24 11:46:47.940: ISAKMP:(2050):Old State = IKE_R_MM5  New State = IKE_P1_COMPLETE

Jun 24 11:46:47.940: ISAKMP:(2050):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
Jun 24 11:46:47.940: ISAKMP:(2050):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

Jun 24 11:46:47.944: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) QM_IDLE
Jun 24 11:46:47.944: ISAKMP: set new node 1 to QM_IDLE
Jun 24 11:46:47.944: ISAKMP:(2050): processing HASH payload. message ID = 1
Jun 24 11:46:47.944: ISAKMP:(2050): processing SA payload. message ID = 1
Jun 24 11:46:47.944: ISAKMP:(2050):Checking IPSec proposal 1
Jun 24 11:46:47.944: ISAKMP: transform 1, ESP_AES
Jun 24 11:46:47.948: ISAKMP:   attributes in transform:
Jun 24 11:46:47.948: ISAKMP:      encaps is 2 (Transport)
Jun 24 11:46:47.948: ISAKMP:      key length is 128
Jun 24 11:46:47.948: ISAKMP:      authenticator is HMAC-SHA
Jun 24 11:46:47.948: ISAKMP:      SA life type in seconds
Jun 24 11:46:47.948: ISAKMP:      SA life duration (VPI) of  0x0 0x0 0xE 0x10
Jun 24 11:46:47.948: ISAKMP:      SA life type in kilobytes
Jun 24 11:46:47.948: ISAKMP:      SA life duration (VPI) of  0x0 0x3 0xD0 0x90
Jun 24 11:46:47.948: ISAKMP:(2050):atts are acceptable.
Jun 24 11:46:47.948: IPSEC(validate_proposal_request): proposal part #1
Jun 24 11:46:47.948: IPSEC(validate_proposal_request): proposal part #1,
  (key eng. msg.) INBOUND local= 192.168.1.9:0, remote= 192.168.1.26:0,
    local_proxy= 192.168.1.9/255.255.255.255/17/1701 (type=1),
    remote_proxy= 192.168.1.26/255.255.255.255/17/1701 (type=1),
    protocol= ESP, transform= NONE  (Transport),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 128, flags= 0x0
Jun 24 11:46:47.948: IPSEC(ipsec_process_proposal): transform proposal not supported for identity:
    {esp-aes esp-sha-hmac }
Jun 24 11:46:47.948: ISAKMP:(2050): IPSec policy invalidated proposal with error 256
Jun 24 11:46:47.948: ISAKMP:(2050):Checking IPSec proposal 2
Jun 24 11:46:47.948: ISAKMP: transform 1, ESP_3DES
Jun 24 11:46:47.948: ISAKMP:   attributes in transform:
Jun 24 11:46:47.948: ISAKMP:      encaps is 2 (Transport)
Jun 24 11:46:47.948: ISAKMP:      authenticator is HMAC-SHA
Jun 24 11:46:47.948: ISAKMP:      SA life type in seconds
Jun 24 11:46:47.948: ISAKMP:      SA life duration (VPI) of  0x0 0x0 0xE 0x10
Jun 24 11:46:47.952: ISAKMP:      SA life type in kilobytes
Jun 24 11:46:47.952: ISAKMP:      SA life duration (VPI) of  0x0 0x3 0xD0 0x90
Jun 24 11:46:47.952: ISAKMP:(2050):atts are acceptable.
Jun 24 11:46:47.952: IPSEC(validate_proposal_request): proposal part #1
Jun 24 11:46:47.952: IPSEC(validate_proposal_request): proposal part #1,
  (key eng. msg.) INBOUND local= 192.168.1.9:0, remote= 192.168.1.26:0,
    local_proxy= 192.168.1.9/255.255.255.255/17/1701 (type=1),
    remote_proxy= 192.168.1.26/255.255.255.255/17/1701 (type=1),
    protocol= ESP, transform= NONE  (Transport),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x0
Jun 24 11:46:47.952: ISAKMP:(2050): processing NONCE payload. message ID = 1
Jun 24 11:46:47.952: ISAKMP:(2050): processing ID payload. message ID = 1
Jun 24 11:46:47.952: ISAKMP:(2050): processing ID payload. message ID = 1
Jun 24 11:46:47.952: ISAKMP:(2050):QM Responder gets spi
Jun 24 11:46:47.952: ISAKMP:(2050):Node 1, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
Jun 24 11:46:47.952: ISAKMP:(2050):Old State = IKE_QM_READY  New State = IKE_QM_SPI_STARVE
Jun 24 11:46:47.956: ISAKMP:(2050): Creating IPSec SAs
Jun 24 11:46:47.956:         inbound SA from 192.168.1.26 to 192.168.1.9 (f/i)  0/ 0
        (proxy 192.168.1.26 to 192.168.1.9)
Jun 24 11:46:47.956:         has spi 0xE8B55DD9 and conn_id 0
Jun 24 11:46:47.956:         lifetime of 3600 seconds
Jun 24 11:46:47.956:         lifetime of 250000 kilobytes
Jun 24 11:46:47.956:         outbound SA from 192.168.1.9 to 192.168.1.26 (f/i) 0/0
        (proxy 192.168.1.9 to 192.168.1.26)
Jun 24 11:46:47.956:         has spi  0xB2007C28 and conn_id 0
Jun 24 11:46:47.956:         lifetime of 3600 seconds
Jun 24 11:46:47.956:         lifetime of 250000 kilobytes
Jun 24 11:46:47.956: ISAKMP:(2050): sending packet to 192.168.1.26 my_port 500 peer_port 500 (R) QM_IDLE
Jun 24 11:46:47.956: ISAKMP:(2050):Sending an IKE IPv4 Packet.
Jun 24 11:46:47.956: ISAKMP:(2050):Node 1, Input = IKE_MESG_INTERNAL, IKE_GOT_SPI
Jun 24 11:46:47.956: ISAKMP:(2050):Old State = IKE_QM_SPI_STARVE  New State = IKE_QM_R_QM2
Jun 24 11:46:47.960: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Jun 24 11:46:47.960: IPSEC(policy_db_add_ident): src 192.168.1.9, dest 192.168.1.26, dest_port 1701

Jun 24 11:46:47.960: IPSEC(create_sa): sa created,
  (sa) sa_dest= 192.168.1.9, sa_proto= 50,
    sa_spi= 0xE8B55DD9(3904200153),
    sa_trans= esp-3des esp-sha-hmac , sa_conn_id= 23
    sa_lifetime(k/sec)= (239854/3600)
Jun 24 11:46:47.960: IPSEC(create_sa): sa created,
  (sa) sa_dest= 192.168.1.26, sa_proto= 50,
    sa_spi= 0xB2007C28(2986376232),
    sa_trans= esp-3des esp-sha-hmac , sa_conn_id= 24
    sa_lifetime(k/sec)= (239854/3600)
Jun 24 11:46:48.944: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) QM_IDLE
Jun 24 11:46:48.948: ISAKMP:(2050): phase 2 packet is a duplicate of a previous packet.
Jun 24 11:46:48.948: ISAKMP:(2050): retransmission skipped for phase 2 (time since last transmission 993)
Jun 24 11:46:49.956: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) QM_IDLE
Jun 24 11:46:49.956: ISAKMP:(2050): phase 2 packet is a duplicate of a previous packet.
Jun 24 11:46:49.956: ISAKMP:(2050): retransmitting due to retransmit phase 2
Jun 24 11:46:49.956: ISAKMP:(2050): retransmitting phase 2 QM_IDLE       1 ...
Jun 24 11:46:50.456: ISAKMP:(2050): retransmitting phase 2 QM_IDLE       1 ...
Jun 24 11:46:50.456: ISAKMP (2050): incrementing error counter on node, attempt 1 of 5: retransmit phase 2
Jun 24 11:46:50.456: ISAKMP (2050): incrementing error counter on sa, attempt 1 of 5: retransmit phase 2
Jun 24 11:46:50.456: ISAKMP:(2050): retransmitting phase 2 1 QM_IDLE
Jun 24 11:46:50.456: ISAKMP:(2050): sending packet to 192.168.1.26 my_port 500 peer_port 500 (R) QM_IDLE
Jun 24 11:46:50.456: ISAKMP:(2050):Sending an IKE IPv4 Packet.
Jun 24 11:46:50.460: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) QM_IDLE
Jun 24 11:46:50.460: ISAKMP:(2050):deleting node 1 error FALSE reason "QM done (await)"
Jun 24 11:46:50.460: ISAKMP:(2050):Node 1, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
Jun 24 11:46:50.464: ISAKMP:(2050):Old State = IKE_QM_R_QM2  New State = IKE_QM_PHASE2_COMPLETE
Jun 24 11:46:50.464: L2X  tnl   0802D:________: Create logical tunnel
Jun 24 11:46:50.464: L2TP tnl   0802D:________: Create tunnel
Jun 24 11:46:50.464: L2TP tnl   0802D:________:     version set to V2
Jun 24 11:46:50.464: L2TP tnl   0802D:________:     remote ip set to 192.168.1.26
Jun 24 11:46:50.464: L2TP tnl   0802D:________:     local ip set to 192.168.1.9
Jun 24 11:46:50.464: L2TP tnl   0802D:00008608: FSM-CC ev Rx-SCCRQ
Jun 24 11:46:50.464: L2TP tnl   0802D:00008608: FSM-CC    Idle->Proc-SCCRQ
Jun 24 11:46:50.464: L2TP tnl   0802D:00008608: FSM-CC do Rx-SCCRQ
Jun 24 11:46:50.468: L2X        _____:________: Tunnel author started for mos04
Jun 24 11:46:50.468: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Jun 24 11:46:50.468: IPSEC(key_engine_enable_outbound): rec'd enable notify from ISAKMP
Jun 24 11:46:50.468: IPSEC(key_engine_enable_outbound): enable SA with spi 2986376232/50
Jun 24 11:46:50.468: IPSEC(update_current_outbound_sa): get enable SA peer 192.168.1.26 current outbound sa to SPI B2007C28
Jun 24 11:46:50.468: IPSEC(update_current_outbound_sa): updated peer 192.168.1.26 current outbound sa to SPI B2007C28
Jun 24 11:46:50.468: L2X        _____:________: Tunnel author found
Jun 24 11:46:50.468: L2TP tnl   0802D:00008608: Author reply, data source: "L2TP"
Jun 24 11:46:50.468: L2X        _____:________: class [AAA author, group "L2TP"]
Jun 24 11:46:50.472: L2X        _____:________:   created
Jun 24 11:46:50.472: L2X        _____:________: class [AAA author, group "L2TP"]
Jun 24 11:46:50.472: L2X        _____:________:   App locked 0->1
Jun 24 11:46:50.472: L2X        _____:________: class [AAA author, group "L2TP"]
Jun 24 11:46:50.472: L2X        _____:________:   Protocol locked 0->1
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608:     class name AAA author, group "L2TP"
Jun 24 11:46:50.472: L2X        _____:________: class [AAA author, group "L2TP"]
Jun 24 11:46:50.472: L2X        _____:________:   App unlocked 1->0
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608:     peer cap sync set
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608: FSM-CC ev SCCRQ-OK
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608: FSM-CC    Proc-SCCRQ->Wt-SCCCN
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608: FSM-CC do Tx-SCCRP
Jun 24 11:46:50.472: L2X        _____:________: l2x_open_socket: is called
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608: Open sock 192.168.1.9:1701->192.168.1.26:1701
Jun 24 11:46:50.472: L2TP tnl   0802D:00008608: FSM-CC ev Sock-Ready
Jun 24 11:46:50.476: L2TP tnl   0802D:00008608: FSM-CC    in Wt-SCCCN
Jun 24 11:46:50.476: L2TP tnl   0802D:00008608: FSM-CC do Ignore-Sock-Up
Jun 24 11:46:50.480: L2TP tnl   0802D:00008608: FSM-CC ev Rx-SCCCN
Jun 24 11:46:50.480: L2TP tnl   0802D:00008608: FSM-CC    Wt-SCCCN->Proc-SCCCN
Jun 24 11:46:50.480: L2TP tnl   0802D:00008608: FSM-CC do Rx-SCCCN
Jun 24 11:46:50.480: L2TP tnl   0802D:00008608: FSM-CC ev SCCCN-OK
Jun 24 11:46:50.480: L2TP tnl   0802D:00008608: FSM-CC    Proc-SCCCN->established
Jun 24 11:46:50.480: L2TP tnl   0802D:00008608: FSM-CC do Established
Jun 24 11:46:50.484: L2TP tnl   0802D:00008608: Control channel up
Jun 24 11:46:50.484: L2TP tnl   0802D:00008608:   192.168.1.9<->192.168.1.26
Jun 24 11:46:50.484: L2TP       _____:________: ERROR: ICRQ AVP 1, vendor 311: unknown
Jun 24 11:46:50.484: L2TP tnl   0802D:00008608: Unknown Vendor 311 AVP 1 in CM ICRQ
Jun 24 11:46:50.484: L2X  _____:_____:________: Create logical session
Jun 24 11:46:50.484: L2TP _____:_____:________: Create session
Jun 24 11:46:50.484: L2TP _____:_____:________:   Using ICRQ FSM
Jun 24 11:46:50.484: L2TP _____:_____:________: FSM-Sn ev created
Jun 24 11:46:50.484: L2TP _____:_____:________: FSM-Sn    Init->Idle
Jun 24 11:46:50.484: L2TP _____:_____:________: FSM-Sn do none
Jun 24 11:46:50.484: L2TP _____:_____:________:     remote ip set to 192.168.1.26
Jun 24 11:46:50.484: L2TP _____:_____:________:     local ip set to 192.168.1.9
Jun 24 11:46:50.484: L2TP tnl   0802D:00008608: FSM-CC ev Session-Conn
Jun 24 11:46:50.484: L2TP tnl   0802D:00008608: FSM-CC    in established
Jun 24 11:46:50.488: L2TP tnl   0802D:00008608: FSM-CC do Session-Conn-Est
Jun 24 11:46:50.488: L2TP tnl   0802D:00008608:   Session count now 1
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: FSM-Sn ev CC-Up
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: FSM-Sn    in Idle
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: FSM-Sn do CC-Up-Ignore0-1
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: Session attached
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: FSM-Sn ev Rx-ICRQ
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: FSM-Sn    Idle->Proc-ICRQ
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: FSM-Sn do Rx-ICRQ
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366:   Chose application VPDN
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366:   App type set to VPDN
Jun 24 11:46:50.488: L2TP tnl   0802D:00008608:   VPDN Session count now 1
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: VPDN: process AVPs
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: Set HA epoch to 0
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: Local AC is now UP
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366: Remote AC is now UP
Jun 24 11:46:50.488: L2TP _____:0802D:0000D366:
Jun 24 11:46:50.492: VPDN Received L2TUN socket message <xCRQ - Session Incoming>
Jun 24 11:46:50.492: VPDN uid:46 L2TUN socket session accept requested
Jun 24 11:46:50.496: VPDN uid:46 Setting up dataplane for L2-L2, no idb
Jun 24 11:46:50.496: L2TP _____:0802D:0000D366:   App type set to VPDN
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366:   UDP checksum ignore is enabled
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366:   Sequencing default tx disabled
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366:   Sequencing default rx disabled
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366:   Framing set to sync
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366:   Bearer set to none
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366: no cookies enabled
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366: FSM-Sn ev ICRQ-OK
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366: FSM-Sn    Proc-ICRQ->Wt-Tx-ICRP
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366: FSM-Sn do Tx-ICRP-Local-Check
Jun 24 11:46:50.496: L2TP 0002E:0802D:0000D366: FSM-Sn ev Local-Cont
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn    Wt-Tx-ICRP->Wt-Rx-ICCN
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn do Tx-ICRP
Jun 24 11:46:50.500: L2X        _____:________: l2x_open_socket: is called
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: Open sock 192.168.1.9:1701->192.168.1.26:1701
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn ev Sock-Ready
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn    in Wt-Rx-ICCN
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn do Ignore-Sock-Up
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366:
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn ev DP-Setup
Jun 24 11:46:50.500: L2TP 0002E:0802D:0000D366: FSM-Sn    in Wt-Rx-ICCN
Jun 24 11:46:50.504: L2TP 0002E:0802D:0000D366: FSM-Sn do Ignore-DP-Setup
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: FSM-Sn ev Rx-ICCN
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: FSM-Sn    Wt-Rx-ICCN->Proc-ICCN
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: FSM-Sn do Rx-ICCN
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366:   MTU is 65535
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: Session data plane UP
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: VPDN: process AVPs
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366:
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: FSM-Sn ev ICCN-OK
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: FSM-Sn    Proc-ICCN->established
Jun 24 11:46:50.508: L2TP 0002E:0802D:0000D366: FSM-Sn do Established
Jun 24 11:46:50.512: L2TP 0002E:0802D:0000D366: Session up
Jun 24 11:46:50.512: L2TP 0002E:0802D:0000D366:   192.168.1.9<->192.168.1.26
Jun 24 11:46:50.512: L2TP:(Tnl34312:Sn54118)L2X setup sss switching
Jun 24 11:46:50.512: L2X:Session DB (Tnl/Sn: 34312/54118): Stored the switching session in the session DB
Jun 24 11:46:50.512: L2TP:(Tnl34312:Sn54118)L2X s/w switching session provisioned
Jun 24 11:46:50.512: VPDN Received L2TUN socket message <xCCN - Session Connected>
Jun 24 11:46:50.516: VPDN uid:46 VPDN session up
Jun 24 11:46:50.520: ppp46 PPP: Using vpn set call direction
Jun 24 11:46:50.520: ppp46 PPP: Treating connection as a callin
Jun 24 11:46:50.520: ppp46 PPP: Session handle[C400002E] Session id[46]
Jun 24 11:46:52.541: ppp46 MS-CHAP-V2: O CHALLENGE id 1 len 28 from "Home871"
Jun 24 11:46:52.545: ppp46 MS-CHAP-V2: I RESPONSE id 1 len 57 from "vpn"
Jun 24 11:46:52.549: ppp46 PPP: Sent MSCHAP_V2 LOGIN Request
Jun 24 11:46:52.557: ppp46 PPP: Received LOGIN Response FAIL
Jun 24 11:46:52.557: ppp46 MS-CHAP-V2: O FAILURE id 1 len 13 msg is "E=691 R=0"
Jun 24 11:46:52.561: VPDN uid:46 disconnect (AAA) IETF: 17/user-error Ascend: 26/PPP CHAP Fail
Jun 24 11:46:52.565: VPDN uid:46 vpdn shutdown session, result=2, error=6, vendor_err=0, syslog_error_code=8, syslog_key_type=1
Jun 24 11:46:52.565: VPDN uid:46 VPDN/AAA: accounting stop sent
Jun 24 11:46:52.565: L2TUN APP: uid:46handle/4141shutdown app session
Jun 24 11:46:52.565: L2TUN APP: uid:46handle/4141Stopping service selection
Jun 24 11:46:52.565: L2TP 0002E:0802D:0000D366:
Jun 24 11:46:52.565: L2TP 0002E:0802D:0000D366: Shutting down session
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:   Result Code
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:     Call disconnected, refer to error msg (2)
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:   Error Code
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:     Vendor specific (6)
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:   Vendor Error
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:     None (0)
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:   Optional Message
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:     "Locally generated disconnect"
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366:
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366: FSM-Sn ev App-Disc
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366: FSM-Sn    in established
Jun 24 11:46:52.569: L2TP 0002E:0802D:0000D366: FSM-Sn do App-Disc-Active
Jun 24 11:46:52.573: L2TP 0002E:0802D:0000D366: Session down
Jun 24 11:46:52.573: L2TP 0002E:0802D:0000D366:   192.168.1.9<->192.168.1.26
Jun 24 11:46:52.573: L2TP 0002E:0802D:0000D366: Destroying session
Jun 24 11:46:52.573: L2TP 0002E:0802D:0000D366: Request teardown data plane
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: FSM-CC ev Session-Disc
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: FSM-CC    in established
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: FSM-CC do Session-Disc-Est
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608:   Session count now 0
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608:   VPDN Session count now 0
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: FSM-CC ev No-Users
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: FSM-CC    established->Est-No-User
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: FSM-CC do No-Users
Jun 24 11:46:52.573: L2TP tnl   0802D:00008608: No more cc users, shutdown (likely) in 10 secs
Jun 24 11:46:52.573: L2TP 0002E:_____:________: Session detached
Jun 24 11:46:52.573: L2X  0002E:_____:________: Destroying logical session
Jun 24 11:46:52.577: L2TP:(Tnl34312:Sn54118)L2X s/w switching session unprovisioned
Jun 24 11:46:52.577: L2X:Session DB (Tnl/Sn: 34312/54118): Removed the switching session from the session DB
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608: FSM-CC ev Rx-StopCCN
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608: FSM-CC    in Est-No-User
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608: FSM-CC do Rx-StopCCN
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608:
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608: Shutting down tunnel
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608:   Result Code
Jun 24 11:46:52.581: L2TP tnl   0802D:00008608:     Requestor is being shut down
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:   Error Code
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:     No error
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:   Vendor Error
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:     None
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:   Optional Message
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:     "No disconnect reason given"
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: FSM-CC ev Shut-Now
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: FSM-CC    Est-No-User->Wt-STOPACK
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: FSM-CC do Shutnow
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: FSM-CC ev Shut-Comp
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: FSM-CC    Wt-STOPACK->Dead
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: FSM-CC do Shutdown-Completed
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: Control channel down
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608:   192.168.1.9<->192.168.1.26
Jun 24 11:46:52.585: L2TP tnl   0802D:00008608: Destroying tunnel
Jun 24 11:46:52.585: L2TP: Removing per-cc stats db entry, tun-id 34312
Jun 24 11:46:52.589: L2X  tnl   0802D:________: Destroying logical tunnel
Jun 24 11:46:52.589: L2X        _____:________: class [AAA author, group "L2TP"]
Jun 24 11:46:52.589: L2X        _____:________:   Protocol unlocked 1->0
Jun 24 11:46:52.589: L2X        _____:________: class[AAA author, group "L2TP"]
Jun 24 11:46:52.589: L2X        _____:________:   no more locks
Jun 24 11:46:52.589: L2X        _____:________: class [AAA author, group "L2TP"]
Jun 24 11:46:52.589: L2X        _____:________:   deleted
Jun 24 11:46:52.601: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) QM_IDLE
Jun 24 11:46:52.601: ISAKMP: set new node 1020407130 to QM_IDLE
Jun 24 11:46:52.601: ISAKMP:(2050): processing HASH payload. message ID = 1020407130
Jun 24 11:46:52.601: ISAKMP:(2050): processing DELETE payload. message ID = 1020407130
Jun 24 11:46:52.601: ISAKMP:(2050):peer does not do paranoid keepalives.

Jun 24 11:46:52.601: ISAKMP:(2050):deleting node 1020407130 error FALSE reason "Informational (in) state 1"
Jun 24 11:46:52.601: ISAKMP (2050): received packet from 192.168.1.26 dport 500 sport 500 Global (R) QM_IDLE
Jun 24 11:46:52.601: ISAKMP: set new node 1146569105 to QM_IDLE
Jun 24 11:46:52.601: ISAKMP:(2050): processing HASH payload. message ID = 1146569105
Jun 24 11:46:52.601: ISAKMP:(2050): processing DELETE payload. message ID = 1146569105
Jun 24 11:46:52.601: ISAKMP:(2050):peer does not do paranoid keepalives.

Jun 24 11:46:52.601: ISAKMP:(2050):deleting SA reason "No reason" state (R) QM_IDLE       (peer 192.168.1.26)
Jun 24 11:46:52.605: ISAKMP:(2050):deleting node 1146569105 error FALSE reason "Informational (in) state 1"
Jun 24 11:46:52.605: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Jun 24 11:46:52.605: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Jun 24 11:46:52.605: IPSEC(key_engine_delete_sas): delete SA with spi 0xB2007C28 proto 50 for 192.168.1.26
Jun 24 11:46:52.605: IPSEC(delete_sa): deleting SA,
  (sa) sa_dest= 192.168.1.9, sa_proto= 50,
    sa_spi= 0xE8B55DD9(3904200153),
    sa_trans= esp-3des esp-sha-hmac , sa_conn_id= 23
    sa_lifetime(k/sec)= (239854/3600),
  (identity) local= 192.168.1.9:0, remote= 192.168.1.26:0,
    local_proxy= 192.168.1.9/255.255.255.255/17/1701 (type=1),
    remote_proxy= 192.168.1.26/255.255.255.255/17/1701 (type=1)
Jun 24 11:46:52.605: IPSEC(update_current_outbound_sa): updated peer 192.168.1.26 current outbound sa to SPI 0
Jun 24 11:46:52.605: IPSEC(delete_sa): deleting SA,
  (sa) sa_dest= 192.168.1.26, sa_proto= 50,
    sa_spi= 0xB2007C28(2986376232),
    sa_trans= esp-3des esp-sha-hmac , sa_conn_id= 24
    sa_lifetime(k/sec)= (239854/3600),
  (identity) local= 192.168.1.9:0, remote= 192.168.1.26:0,
    local_proxy= 192.168.1.9/255.255.255.255/17/1701 (type=1),
    remote_proxy= 192.168.1.26/255.255.255.255/17/1701 (type=1)
Jun 24 11:46:52.609: ISAKMP: set new node 2134342841 to QM_IDLE
Jun 24 11:46:52.609: ISAKMP:(2050): sending packet to 192.168.1.26 my_port 500 peer_port 500 (R) QM_IDLE
Jun 24 11:46:52.609: ISAKMP:(2050):Sending an IKE IPv4 Packet.
Jun 24 11:46:52.609: ISAKMP:(2050):purging node 2134342841
Jun 24 11:46:52.609: ISAKMP:(2050):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Jun 24 11:46:52.609: ISAKMP:(2050):Old State = IKE_P1_COMPLETE  New State = IKE_DEST_SA

Jun 24 11:46:52.613: ISAKMP:(2050):deleting SA reason "No reason" state (R) QM_IDLE       (peer 192.168.1.26)
Jun 24 11:46:52.613: ISAKMP: Unlocking peer struct 0x85BC8B58 for isadb_mark_sa_deleted(), count 0
Jun 24 11:46:52.613: ISAKMP: Deleting peer node by peer_reap for 192.168.1.26: 85BC8B58
Jun 24 11:46:52.613: ISAKMP:(2050):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Jun 24 11:46:52.613: ISAKMP:(2050):Old State = IKE_DEST_SA  New State = IKE_DEST_SA

Jun 24 11:46:52.613: IPSEC(key_engine): got a queue event with 1 KMI message(s)

Your help will be hightly appreciated!

Labels:
0 Helpful
6 Replies 6

Giuseppe Larosa
Hall of Fame
Hall of Fame

‎06-24-2019 09:14 AM - edited ‎06-24-2019 09:39 AM

Hello ps000000,

can you provide in separate attachment files the following:

1)configuration using authentication chap

2) debug output showing successful setup of IPSec / L2TP in this case

3) configuration using authentication ms-chap

4) the debug output showing failure in setup of IPSec / L2TP in this second case

 

The best way to understand what is going wrong with ms-chap is to compare the two debug outputs but for better readability you should provide them as attachment files.

 

Edit:

the configuration looks like correct.

The key command here is the set nat demux inside the crypto map configuration as described in the following document

https://www.cisco.com/c/en/us/td/docs/ios-xml/ios/sec_conn_vpnips/configuration/15-mt/sec-sec-for-vpns-w-ipsec-15-mt-book/l2tp-ipsec-sup-nat-pat-win-clients.pdf?dtid=osscdc000283

 

However, be aware that there are several SW bugs related to the command set nat demux.

For example the following

CSCux97076

 

L2TP/IPSEC from non-patted environment fails with set nat demux
CSCux97076
 
Symptom:
L2TP/IPSEC fails to establish a connection.
L2TP/IPSEC can be established when a client connects from behind a pat device.

-----------------------
Direct access fails
Router ----------------- Windows 7

If a client is behind a pat device, L2TP/IPSEC succeeds
Router ----- (Internet) ----- PAT device ----- Windows 7
-----------------------

Conditions:
set nat demux command is configured

Workaround:
n/a
 
Known Affected Releases:
(2)
15.2(4)M6
15.3(3)M4
 

 

Hope to help

Giuseppe

 

0 Helpful

ps0000000
Level 1
Level 1
In response to Giuseppe Larosa

‎06-25-2019 03:19 AM - edited ‎06-25-2019 03:23 AM

Hi @Giuseppe Larosa

thank you for the answer. As far as PC client and router are on the same network there is no NAT or PAT used.

As for logs I have compared files and find nothing new - just that user is not authenticated without specifying reason why.

 

: ppp2 MS-CHAP-V2: O CHALLENGE id 1 len 28 from "Home871"
: ppp2 LCP: State is Open
: ppp2 MS-CHAP-V2: I RESPONSE id 1 len 57 from "vpn"
: ppp2 PPP: Phase is FORWARDING, Attempting Forward
: ppp2 PPP: Phase is AUTHENTICATING, Unauthenticated User
: AAA/AUTHEN/PPP (0000000E): Pick method list 'VPDN_AUTH'
: ppp2 PPP: Sent MSCHAP_V2 LOGIN Request
: ppp2 PPP: Received LOGIN Response FAIL
: ppp2 MS-CHAP-V2: O FAILURE id 1 len 13 msg is "E=691 R=0"

 

what is on debug log

General OS:
  AAA Authentication debugging is on
PPP:
  PPP authentication debugging is on
  PPP protocol errors debugging is on
  PPP protocol negotiation debugging is on
VPN:
  L2TP/PPTP protocol events debugging is on
  L2TP/PPTP protocol errors debugging is on
  VPDN events debugging is on
  VPDN errors debugging is on
Cryptographic Subsystem:
  Crypto ISAKMP debugging is on
  Crypto ISAKMP Error debugging is on
  Crypto ISAKMP AAA debugging is on
  Crypto IPSEC debugging is on
  Crypto IPSEC Error debugging is on
  Crypto Key Management Interface debugging is on

Anyway sending files requested.

Thanks in advance

Preview file
7 KB
Preview file
27 KB
Preview file
7 KB
Preview file
31 KB
0 Helpful

Giuseppe Larosa
Hall of Fame
Hall of Fame
In response to ps0000000

‎06-25-2019 04:32 AM - edited ‎06-25-2019 04:58 AM

Hello,

the error code that is provided is 691

possible reasons for error code 691 with MS CHAP version 2 are described in the following link.

 

https://appuals.com/vpn-error-691-on-windows-78-and-10/

 

When using a PC with os Win7, Win8 or Win10 the VPN client configuration for MS CHAP version 2 may have checked the flag "Include Windows logon domain " in VPN option.

If this is the case the PC presents itself with additional unneeded information.

Follow the link above to uncheck this flag in the PC VPN config window.

If you have already disabled this option as we see the remote user as "vpn" also in MS CHAP version 2 debug logs, the failure means that the calculated Challenge sent to the router does not match, = like the password on the PC is wrong.

So or you fix unchecking the sending of the windows domain name, or you have an interoperability issue.

In this last case using CHAP instead of MS CHAP v2 may be acceptable for you.

 

Hope to help

Giuseppe

 

 

0 Helpful

Georg Pauwen
VIP
VIP

‎06-25-2019 04:15 AM

Hello,

 

just a thought, but what do the L2TP Properties on your client (Windows 10 ?) look like ? Do you have MS-CHAP v2 enabled ?

 

Also, since (I assume) you have been using the document linked below as a template, make sure that the key 'Cisco123' matches what you have configured on the client (the document below use 'cisco123' with small caps)...

 

crypto isakmp key Cisco123 address 0.0.0.0 0.0.0.0

 

https://community.cisco.com/t5/security-documents/l2tp-over-ipsec-on-cisco-ios-router-using-windows-8/ta-p/3142831

0 Helpful

ps0000000
Level 1
Level 1
In response to Georg Pauwen

‎06-25-2019 07:29 AM

Thank you all for the answers. I have checked solutions proposed.

1. make sure that the key 'Cisco123' matches - I checked it and as far as it is working with chap then I assume that psk as well as username/password are all correct. But I copy-paste it one more time.

2. MS-CHAP v2 enabled - yes when switching from chap to ms-chap-v2 cisco configuration I also change settings of Win10 VPN security settings as well.

3. possible reasons for error code 691 with MS CHAP version 2 are described in the following link - I follow instructions completely with one exception - there is no "Include Windows logon domain" option in win10:

https://strongvpn.com/assets/img/tutorials/autoconnect_windows_pptp/autoconnect_windows_10_pptp_step_03.png

no success at all.

4. n this last case using CHAP instead of MS CHAP v2 may be acceptable for you - I am afraid that this is the only option so far.

 

Anyway thank you all for help.

0 Helpful

Giuseppe Larosa
Hall of Fame
Hall of Fame
In response to ps0000000

‎06-25-2019 08:13 AM

Hello,

 at this point using CHAP authentication can be a wise decision as it works well.

note: the link you have provided is for a PPTP VPN not L2TP. I don't remember if L2TPv2 is a superset that includes PPTP or not.

 

Hope to help

Giuseppe

 

0 Helpful
Customers Also Viewed These Support Documents