Cisco ISR L2TP VPN local vs radius authentication problem

Question

I currently have a cisco 1841 router configured to authenticate users against a Windows NPS server. The strange thing is that when using local authentication the VPN connects first time every time. I then move the authentication from local to radius but then I am unable to login to the VPN.

When looking at the security logs on the Windows NPS server I can clearly see that the router is querying the server and that the server responds back saying the login is valid but the router never finishes the VPN login with radius.

If I change ppp authentication ms-chap-v2 remote-access for ppp authentication ms-chap-v2 then it will use local usernames and work fine.

aaa new-model
!
aaa group server radius radius-servers
 server-private <ommitted ip> key 7 <ommitted secret>
!
aaa authentication login default local
aaa authentication ppp remote-access group radius-servers
!
vpdn enable
!
vpdn-group L2TP
 ! Default L2TP VPDN group
 accept-dialin
  protocol l2tp
  virtual-template 1
 lcp renegotiation always
 no l2tp tunnel authentication
!
!
 crypto isakmp policy 1
 encr aes 256
 authentication pre-share
 group 2
 lifetime 3600
crypto isakmp key <omitted secret> address 0.0.0.0 0.0.0.0
crypto isakmp keepalive 3600
!
!
crypto ipsec transform-set remote-access-set esp-aes 256 esp-sha-hmac 
 mode transport
!
crypto dynamic-map remote-access-map 10
 set transform-set remote-access-set 
!
!
crypto map dynmap 65535 ipsec-isakmp dynamic remote-access-map 
!
interface Virtual-Template1
 ip unnumbered FastEthernet0/0.1
 peer default ip address pool remote-access-pool
 ppp mtu adaptive
 ppp authentication ms-chap-v2 remote-access

L2TP Debug:

*Oct 12 06:49:23.270: L2TP       _____:________: I SCCRQ, flg TLS, ver 2, len 69
*Oct 12 06:49:23.270: L2TP       _____:________:  IETF v2:
*Oct 12 06:49:23.270: L2TP       _____:________:   Protocol Version  1, Revision 0
*Oct 12 06:49:23.274: L2TP       _____:________:   Framing Cap       both(0x3)
*Oct 12 06:49:23.274: L2TP       _____:________:   Hostname           "thanatos..."
*Oct 12 06:49:23.274: L2TP       _____:________:   Assigned Tunnel I 0x00000079 (121)
*Oct 12 06:49:23.274: L2TP       _____:________:   Rx Window Size    4
*Oct 12 06:49:23.274: L2TP       _____:________:  
*Oct 12 06:49:23.274: L2X  tnl   08023:________: Create logical tunnel
*Oct 12 06:49:23.274: L2TP tnl   08023:________: Create tunnel
*Oct 12 06:49:23.274: L2TP tnl   08023:________:     version set to V2
*Oct 12 06:49:23.274: L2TP tnl   08023:________:     remote ip set to <remote IP>
*Oct 12 06:49:23.274: L2TP tnl   08023:________:     local ip set to <external IP>
*Oct 12 06:49:23.274: L2TP tnl   08023:00007D8D: FSM-CC ev Rx-SCCRQ
*Oct 12 06:49:23.274: L2TP tnl   08023:00007D8D: FSM-CC    Idle->Proc-SCCRQ
*Oct 12 06:49:23.274: L2TP tnl   08023:00007D8D: FSM-CC do Rx-SCCRQ
*Oct 12 06:49:23.278: L2X        _____:________: Tunnel author started for thanatos
*Oct 12 06:49:23.282: L2X        _____:________: Tunnel author found
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D: Author reply, data source: "L2TP"
*Oct 12 06:49:23.282: L2X        _____:________: class [AAA author, group "L2TP"]
*Oct 12 06:49:23.282: L2X        _____:________:   created
*Oct 12 06:49:23.282: L2X        _____:________: class [AAA author, group "L2TP"]
*Oct 12 06:49:23.282: L2X        _____:________:   App locked 0->1
*Oct 12 06:49:23.282: L2X        _____:________: class [AAA author, group "L2TP"]
*Oct 12 06:49:23.282: L2X        _____:________:   Protocol locked 0->1
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D:     class name AAA author, group "L2TP"
*Oct 12 06:49:23.282: L2X        _____:________: class [AAA author, group "L2TP"]
*Oct 12 06:49:23.282: L2X        _____:________:   App unlocked 1->0
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D:     peer cap async set
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D:     peer cap sync set
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D: FSM-CC ev SCCRQ-OK
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D: FSM-CC    Proc-SCCRQ->Wt-SCCCN
*Oct 12 06:49:23.282: L2TP tnl   08023:00007D8D: FSM-CC do Tx-SCCRP
*Oct 12 06:49:23.282: L2X        _____:________: l2x_open_socket: is called
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D: Open sock <external IP>:1701-><remote IP>:52700
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D: FSM-CC ev Sock-Ready
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D: FSM-CC    in Wt-SCCCN
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D: FSM-CC do Ignore-Sock-Up
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D: O SCCRP to thanatos tnl 121
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:  IETF v2:
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:   Protocol Version  1, Revision 0
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:   Framing Cap       none(0x0)
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:   Firmware Ver      0x1130
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:   Hostname           "rtr1"
*Oct 12 06:49:23.286: L2TP tnl   08023:00007D8D:   Vendor Name       
*Oct 12 06:49:23.290: L2TP tnl   08023:00007D8D:      "Cisco Systems, Inc."
*Oct 12 06:49:23.290: L2TP tnl   08023:00007D8D:   Assigned Tunnel I 0x00007D8D (32141)
*Oct 12 06:49:23.290: L2TP tnl   08023:00007D8D:   Rx Window Size    1024
*Oct 12 06:49:23.290: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D: Drain unsentQ, cur/max resendQ sz 0/4, unsentQ 0
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D: I SCCCN, flg TLS, ver 2, len 20
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D: FSM-CC ev Rx-SCCCN
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D: FSM-CC    Wt-SCCCN->Proc-SCCCN
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D: FSM-CC do Rx-SCCCN
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D: O ZLB ACK to thanatos tnl 121
*Oct 12 06:49:23.342: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D: FSM-CC ev SCCCN-OK
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D: FSM-CC    Proc-SCCCN->established
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D: FSM-CC do Established
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D: Control channel up
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D:   <external IP><-><remote IP>
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D: I ICRQ, flg TLS, ver 2, len 38
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D:  IETF v2:
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D:   Assigned Call ID  0x00000E8B (3723)
*Oct 12 06:49:23.346: L2TP tnl   08023:00007D8D:   Serial Number     1
*Oct 12 06:49:23.350: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.350: L2X  _____:_____:________: Create logical session
*Oct 12 06:49:23.350: L2TP _____:_____:________: Create session
*Oct 12 06:49:23.350: L2TP _____:_____:________:   Using ICRQ FSM
*Oct 12 06:49:23.350: L2TP _____:_____:________: FSM-Sn ev created
*Oct 12 06:49:23.350: L2TP _____:_____:________: FSM-Sn    Init->Idle
*Oct 12 06:49:23.350: L2TP _____:_____:________: FSM-Sn do none
*Oct 12 06:49:23.350: L2TP _____:_____:________:     remote ip set to <remote IP>
*Oct 12 06:49:23.350: L2TP _____:_____:________:     local ip set to <external IP>
*Oct 12 06:49:23.350: L2TP tnl   08023:00007D8D: FSM-CC ev Session-Conn
*Oct 12 06:49:23.350: L2TP tnl   08023:00007D8D: FSM-CC    in established
*Oct 12 06:49:23.350: L2TP tnl   08023:00007D8D: FSM-CC do Session-Conn-Est
*Oct 12 06:49:23.350: L2TP tnl   08023:00007D8D:   Session count now 1
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: FSM-Sn ev CC-Up
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: FSM-Sn    in Idle
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: FSM-Sn do CC-Up-Ignore0-1
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: Session attached
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: FSM-Sn ev Rx-ICRQ
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: FSM-Sn    Idle->Proc-ICRQ
*Oct 12 06:49:23.350: L2TP _____:08023:00008D28: FSM-Sn do Rx-ICRQ
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28:   Chose application VPDN
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28:   App type set to VPDN
*Oct 12 06:49:23.354: L2TP tnl   08023:00007D8D:   VPDN Session count now 1
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28: VPDN: process AVPs
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28: Set HA epoch to 0
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28: Local AC is now UP
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28: Remote AC is now UP
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28:  
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28: APP<-L2TP: Incoming
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28:            sock 00000000
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28:            serv 00008022
*Oct 12 06:49:23.354: L2TP _____:08023:00008D28:  
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28: L2TUN: add sock 00001022
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28:  
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28: APP->L2TP: Accept [6],
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28:            sock 00001022
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28:            serv 00008022
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28:            data 68660C28[136]
*Oct 12 06:49:23.358: L2TP _____:08023:00008D28:            replied on new socket
*Oct 12 06:49:23.362: L2TP _____:08023:00008D28:  
*Oct 12 06:49:23.362: L2TP _____:08023:00008D28:   App type set to VPDN
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28:   UDP checksum ignore is enabled
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28:   Sequencing default tx disabled
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28:   Sequencing default rx disabled
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28:   Framing set to sync
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28:   Bearer set to none
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: no cookies enabled
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn ev ICRQ-OK
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn    Proc-ICRQ->Wt-Tx-ICRP
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn do Tx-ICRP-Local-Check
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn ev Local-Cont
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn    Wt-Tx-ICRP->Wt-Rx-ICCN
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn do Tx-ICRP
*Oct 12 06:49:23.362: L2X        _____:________: l2x_open_socket: is called
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: Open sock <external IP>:1701-><remote IP>:52700
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn ev Sock-Ready
*Oct 12 06:49:23.362: L2TP 00023:08023:00008D28: FSM-Sn    in Wt-Rx-ICCN
*Oct 12 06:49:23.366: L2TP 00023:08023:00008D28: FSM-Sn do Ignore-Sock-Up
*Oct 12 06:49:23.366: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.366: L2TP 00023:08023:00008D28: O ICRP to thanatos 121/3723
*Oct 12 06:49:23.366: L2TP 00023:08023:00008D28:  IETF v2:
*Oct 12 06:49:23.366: L2TP 00023:08023:00008D28:   Assigned Call ID  0x00008D28 (36136)
*Oct 12 06:49:23.366: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28: APP->L2TP: Setup dataplane [15],
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28:            data 684D0DCC[20]
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28:            replied on same socket
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28: FSM-Sn ev DP-Setup
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28: FSM-Sn    in Wt-Rx-ICCN
*Oct 12 06:49:23.370: L2TP 00023:08023:00008D28: FSM-Sn do Ignore-DP-Setup
*Oct 12 06:49:23.422: L2TP tnl   08023:00007D8D: Drain unsentQ, cur/max resendQ sz 0/4, unsentQ 0
*Oct 12 06:49:23.422: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:23.422: L2TP 00023:08023:00008D28: I ICCN, flg TLS, ver 2, len 40
*Oct 12 06:49:23.422: L2TP 00023:08023:00008D28:  IETF v2:
*Oct 12 06:49:23.422: L2TP 00023:08023:00008D28:   Framing Type      both(3)
*Oct 12 06:49:23.422: L2TP 00023:08023:00008D28:   Connect Speed     1000000
*Oct 12 06:49:23.422: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.422: L2TP 00023:08023:00008D28: O ZLB ACK to thanatos 121/3723
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28: FSM-Sn ev Rx-ICCN
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28: FSM-Sn    Wt-Rx-ICCN->Proc-ICCN
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28: FSM-Sn do Rx-ICCN
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28:   MTU is 65535
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28: Session data plane UP
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28: VPDN: process AVPs
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28: APP<-L2TP: Connected
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:23.426: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:23.430: L2TP 00023:08023:00008D28: FSM-Sn ev ICCN-OK
*Oct 12 06:49:23.430: L2TP 00023:08023:00008D28: FSM-Sn    Proc-ICCN->established
*Oct 12 06:49:23.430: L2TP 00023:08023:00008D28: FSM-Sn do Established
*Oct 12 06:49:23.430: L2TP 00023:08023:00008D28: Session up
*Oct 12 06:49:23.430: L2TP 00023:08023:00008D28:   <external IP><-><remote IP>
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28: APP->L2TP: Session updated [12],
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:            data 684874F8[98]
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:            replied on same socket
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:   App type set to VPDN
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:   Sequencing default tx disabled
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:   Sequencing default rx disabled
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:   Framing set to sync
*Oct 12 06:49:26.582: L2TP 00023:08023:00008D28:   Bearer set to none
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28: APP<-L2TP: Dataplane up
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28: FSM-Sn ev DP-Up
*Oct 12 06:49:26.586: L2TP 00023:08023:00008D28: FSM-Sn    in established
*Oct 12 06:49:26.590: L2TP 00023:08023:00008D28: FSM-Sn do Ignore-DP-UP
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28: APP->L2TP: Session updated [12],
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:            data 68488A7C[111]
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:            replied on same socket
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:   App type set to VPDN
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:   Sequencing default tx disabled
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:   Sequencing default rx disabled
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:   Framing set to sync
*Oct 12 06:49:26.594: L2TP 00023:08023:00008D28:   Bearer set to none
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28: APP->L2TP: Session updated [12],
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:            data 683515A8[66]
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:            replied on same socket
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:   App type set to VPDN
*Oct 12 06:49:26.598: L2TP 00023:08023:00008D28:   Sequencing default tx disabled
*Oct 12 06:49:26.602: L2TP 00023:08023:00008D28:   Sequencing default rx disabled
*Oct 12 06:49:26.602: L2TP 00023:08023:00008D28:   Framing set to sync
*Oct 12 06:49:26.602: L2TP 00023:08023:00008D28:   Bearer set to none
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28: APP->L2TP: local circuit status [21],
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28:            data 684C65C8[41]
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28:            replied on same socket
*Oct 12 06:49:26.654: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28: I CDN, flg TLS, ver 2, len 42
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:  IETF v2:
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:   Result Code       
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:     Reserved(768)
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:     Error code
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:       No error(0)
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:     Optional msg
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:        "<00><03><00><00>"
*Oct 12 06:49:26.682: L2TP 00023:08023:00008D28:   Assigned Call ID  0x00000E8B (3723)
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28: O ZLB ACK to thanatos 121/3723
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28: FSM-Sn ev Rx-CDN
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28: FSM-Sn    established->Idle
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28: FSM-Sn do Rx-CDN
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28: VPDN: process AVPs
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28: Shutting down session
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28:   Result Code
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28:     Reserved (0)
*Oct 12 06:49:26.686: L2TP 00023:08023:00008D28:   Error Code
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:     No error (0)
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:   Vendor Error
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:     None (0)
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: FSM-Sn ev Shut
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: FSM-Sn    Idle->Dead
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: FSM-Sn do Destroy
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: APP<-L2TP: Disconnect
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:            sock 00001022
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:            serv 00008022
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:  
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: Session down
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28:   <external IP><-><remote IP>
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: Destroying session
*Oct 12 06:49:26.690: L2TP 00023:08023:00008D28: Request teardown data plane
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: FSM-CC ev Session-Disc
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: FSM-CC    in established
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: FSM-CC do Session-Disc-Est
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D:   Session count now 0
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D:   VPDN Session count now 0
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: FSM-CC ev No-Users
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: FSM-CC    established->Est-No-User
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: FSM-CC do No-Users
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: No more cc users, shutdown (likely) in 10 secs
*Oct 12 06:49:26.694: L2TP 00023:_____:________: Session detached
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: StopCCN: skip authen, no nonce yet
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D: I StopCCN, flg TLS, ver 2, len 42
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D:  IETF v2:
*Oct 12 06:49:26.694: L2TP tnl   08023:00007D8D:   Result Code       
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:     No error(256)
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:     Error code
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:       No error(0)
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:     Optional msg
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:        "<00><03><00><00>"
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:   Assigned Tunnel I 0x00000079 (121)
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D: O ZLB ACK to thanatos tnl 121
*Oct 12 06:49:26.698: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC ev Rx-StopCCN
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC    in Est-No-User
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC do Rx-StopCCN
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: Shutting down tunnel
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:   Result Code
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:     No error
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:   Error Code
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:     No error
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:   Vendor Error
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:     None
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:  
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC ev Shut-Now
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC    Est-No-User->Wt-STOPACK
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC do Shutnow
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC ev Shut-Comp
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC    Wt-STOPACK->Dead
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: FSM-CC do Shutdown-Completed
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D: Control channel down
*Oct 12 06:49:26.702: L2TP tnl   08023:00007D8D:   <external IP><-><remote IP>
*Oct 12 06:49:26.706: L2TP tnl   08023:00007D8D: Destroying tunnel
*Oct 12 06:49:26.706: L2TP: Removing per-cc stats db entry, tun-id 32141
*Oct 12 06:49:26.706: L2X  tnl   08023:________: Destroying logical tunnel
*Oct 12 06:49:26.706: L2X        _____:________: class [AAA author, group "L2TP"]
*Oct 12 06:49:26.706: L2X        _____:________:   Protocol unlocked 1->0
*Oct 12 06:49:26.706: L2X        _____:________: class[AAA author, group "L2TP"]
*Oct 12 06:49:26.706: L2X        _____:________:   no more locks
*Oct 12 06:49:26.706: L2X        _____:________: class [AAA author, group "L2TP"]
*Oct 12 06:49:26.706: L2X        _____:________:   deleted
*Oct 12 06:49:26.714: L2X  00023:_____:________:  
*Oct 12 06:49:26.714: L2X  00023:_____:________: APP->L2TP: Destroy [11],
*Oct 12 06:49:26.714: L2X  00023:_____:________:            sock 00001022
*Oct 12 06:49:26.714: L2X  00023:_____:________:            serv 00008022
*Oct 12 06:49:26.714: L2X  00023:_____:________:            data 684889D4[277]
*Oct 12 06:49:26.714: L2X  00023:_____:________:            replied on same socket
*Oct 12 06:49:26.714: L2X  00023:_____:________:  
*Oct 12 06:49:26.714: L2X  00023:_____:________: L2TUN: remove sock 00001022
*Oct 12 06:49:26.714: L2X  00023:_____:________: Destroying logical session

Enable debug radius, debug aaa authentication, debug aaa authorization, debug ppp authentication, debug ppp authorization, debug ppp negotiation and try to connect, see if that provides any clue. — hertitu, Commented Oct 11, 2016 at 18:44
The client (iPhone) just shows auth failed which is what I find odd if I take it at face value. The chit chat between the router and the NPS server seems to get through because NPS is approving the login request. The output of debug looks very similar to when using local auth. I will try and check the debug output again in case I am overlooking something. — pieterk, Commented Oct 11, 2016 at 19:01
Ok, if you want us to have a look, please edit your question and add the debug output. debug l2tp error or maybe debug l2tp all might be helpful too, although I would expect the PPP debugs to be most helpful. If you do find the solution yourself please post an answer here! — hertitu, Commented Oct 11, 2016 at 19:06

pieterk · Accepted Answer · 2016-10-12 15:30:11Z

2

I found the problem. I did not think this would be it so I overlooked it multiple times but after trying it, it worked. I feel so silly now.

On the virtual template 1 I changed

ppp authentication ms-chap-v2 remote-access

To this

ppp authentication ms-chap ms-chap-v2 remote-access

VPN connects and all is working.

answered Oct 12, 2016 at 15:30

pieterk

1817 bronze badges

Add a comment |

Stack Exchange Network

Cisco ISR L2TP VPN local vs radius authentication problem

1 Answer 1

Your Answer

Not the answer you're looking for? Browse other questions tagged
cisco
vpn
radius
cisco-isr
l2tp
or ask your own question.

Hot Network Questions

Cisco ISR L2TP VPN local vs radius authentication problem

1 Answer 1

Your Answer

Sign up or log in

Post as a guest

Not the answer you're looking for? Browse other questions tagged ciscovpnradiuscisco-isrl2tp or ask your own question.

Related

Hot Network Questions

Not the answer you're looking for? Browse other questions tagged
cisco
vpn
radius
cisco-isr
l2tp
or ask your own question.