PPTP Client from Cisco 1700 router to Microsoft VPN server

bsvorinic · ‎08-26-2012

Hi,

I'm trying to configure 1700 K9 router to act as PPTP client and connect to Microsoft VPN server (in order to enable all clients on LAN to seamlessly access host on remote location). After searching the net I found this post http://rizzitech.blogspot.com/2008/09/configuring-cisco-adsl-router-acting-as.html.

I'm using GMS3 to test everything in lab environment. I managed to connect to Microsoft VPN server but the connection drops immediately. Below is debug info from router R1 (router R2 just simulates host on LAN) and configurations for both routers. The only clue I got from debug is that immediately before closing connection there's a message "CCP: Failed to negotiate with peer"...

Can someone point me in the right direction and explain what is going on?

Thanks in advance,

Bruno

R1#sh debug

PPP:

PPP detailed event debugging is on

MPPE Packet Details debugging is on

PPP protocol negotiation debugging is on

PPP forwarding events debugging is on

R1#

Aug 26 14:47:46.352: Vi1 PPP: Phase is DOWN, Setup

Aug 26 14:47:46.748: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up

Aug 26 14:47:46.752: Vi1 PPP: Using dialer call direction

Aug 26 14:47:46.756: Vi1 PPP: Treating connection as a callout

Aug 26 14:47:46.756: Vi1 PPP: Phase is ESTABLISHING, Active Open

Aug 26 14:47:46.756: Vi1 PPP: No remote authentication for call-out

Aug 26 14:47:46.760: Vi1 LCP: O CONFREQ [Closed] id 1 len 12

Aug 26 14:47:46.760: Vi1 LCP: MagicNumber 0x0020A6CA (0x05060020A6CA)

Aug 26 14:47:46.764: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.836: Vi1 LCP: I CONFREQ [REQsent] id 0 len 52

Aug 26 14:47:46.836: Vi1 LCP: MRU 1400 (0x01040578)

Aug 26 14:47:46.840: Vi1 LCP: AuthProto EAP (0x0304C227)

Aug 26 14:47:46.840: Vi1 LCP: MagicNumber 0x49822249 (0x050649822249)

Aug 26 14:47:46.840: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.844: Vi1 LCP: ACFC (0x0802)

Aug 26 14:47:46.844: Vi1 LCP: Callback 6 (0x0D0306)

Aug 26 14:47:46.844: Vi1 LCP: MRRU 1614 (0x1104064E)

Aug 26 14:47:46.848: Vi1 LCP: EndpointDisc 1 Local

Aug 26 14:47:46.848: Vi1 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

Aug 26 14:47:46.848: Vi1 LCP: (0xCC281200000000)

Aug 26 14:47:46.852: Vi1 LCP: O CONFREJ [REQsent] id 0 len 11

Aug 26 14:47:46.852: Vi1 LCP: Callback 6 (0x0D0306)

Aug 26 14:47:46.856: Vi1 LCP: MRRU 1614 (0x1104064E)

Aug 26 14:47:46.856: Vi1 LCP: I CONFACK [REQsent] id 1 len 12

Aug 26 14:47:46.860: Vi1 LCP: MagicNumber 0x0020A6CA (0x05060020A6CA)

Aug 26 14:47:46.860: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.872: Vi1 LCP: I CONFREQ [ACKrcvd] id 1 len 45

Aug 26 14:47:46.876: Vi1 LCP: MRU 1400 (0x01040578)

Aug 26 14:47:46.876: Vi1 LCP: AuthProto EAP (0x0304C227)

Aug 26 14:47:46.876: Vi1 LCP: MagicNumber 0x49822249 (0x050649822249)

Aug 26 14:47:46.880: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.880: Vi1 LCP: ACFC (0x0802)

Aug 26 14:47:46.880: Vi1 LCP: EndpointDisc 1 Local

Aug 26 14:47:46.884: Vi1 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

Aug 26 14:47:46.884: Vi1 LCP: (0xCC281200000000)

Aug 26 14:47:46.888: Vi1 LCP: O CONFNAK [ACKrcvd] id 1 len 13

Aug 26 14:47:46.888: Vi1 LCP: MRU 1500 (0x010405DC)

Aug 26 14:47:46.888: Vi1 LCP: AuthProto CHAP (0x0305C22305)

Aug 26 14:47:46.932: Vi1 LCP: I CONFREQ [ACKrcvd] id 2 len 46

Aug 26 14:47:46.932: Vi1 LCP: MRU 1400 (0x01040578)

Aug 26 14:47:46.932: Vi1 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Aug 26 14:47:46.932: Vi1 LCP: MagicNumber 0x49822249 (0x050649822249)

Aug 26 14:47:46.932: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.932: Vi1 LCP: ACFC (0x0802)

Aug 26 14:47:46.932: Vi1 LCP: EndpointDisc 1 Local

Aug 26 14:47:46.932: Vi1 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

Aug 26 14:47:46.932: Vi1 LCP: (0xCC281200000000)

Aug 26 14:47:46.932: Vi1 LCP: O CONFNAK [ACKrcvd] id 2 len 8

Aug 26 14:47:46.936: Vi1 LCP: MRU 1500 (0x010405DC)

Aug 26 14:47:46.968: Vi1 LCP: I CONFREQ [ACKrcvd] id 3 len 46

Aug 26 14:47:46.968: Vi1 LCP: MRU 1500 (0x010405DC)

Aug 26 14:47:46.972: Vi1 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Aug 26 14:47:46.972: Vi1 LCP: MagicNumber 0x49822249 (0x050649822249)

Aug 26 14:47:46.972: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.976: Vi1 LCP: ACFC (0x0802)

Aug 26 14:47:46.976: Vi1 LCP: EndpointDisc 1 Local

Aug 26 14:47:46.976: Vi1 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

Aug 26 14:47:46.976: Vi1 LCP: (0xCC281200000000)

Aug 26 14:47:46.976: Vi1 LCP: O CONFACK [ACKrcvd] id 3 len 46

Aug 26 14:47:46.976: Vi1 LCP: MRU 1500 (0x010405DC)

Aug 26 14:47:46.976: Vi1 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Aug 26 14:47:46.976: Vi1 LCP: MagicNumber 0x49822249 (0x050649822249)

Aug 26 14:47:46.976: Vi1 LCP: PFC (0x0702)

Aug 26 14:47:46.976: Vi1 LCP: ACFC (0x0802)

Aug 26 14:47:46.976: Vi1 LCP: EndpointDisc 1 Local

Aug 26 14:47:46.976: Vi1 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

Aug 26 14:47:46.976: Vi1 LCP: (0xCC281200000000)

Aug 26 14:47:46.976: Vi1 LCP: State is Open

Aug 26 14:47:46.976: Vi1 PPP: Phase is AUTHENTICATING, by the peer

Aug 26 14:47:47.016: Vi1 MS-CHAP-V2: I CHALLENGE id 0 len 24 from "VPN"

Aug 26 14:47:47.028: Vi1 MS CHAP V2: Using hostname from interface CHAP

Aug 26 14:47:47.032: Vi1 MS CHAP V2: Using password from interface CHAP

Aug 26 14:47:47.032: Vi1 MS-CHAP-V2: O RESPONSE id 0 len 57 from "mit"

Aug 26 14:47:47.128: Vi1 MS-CHAP-V2: I SUCCESS id 0 len 46 msg is "S=66347AC794BD18F542545B77550CBE7D28FB22F7"

Aug 26 14:47:47.128: Vi1 MS CHAP V2 No Password found for : VPN

Aug 26 14:47:47.132: Vi1 MS CHAP V2 No Password found for : VPN

Aug 26 14:47:47.136: Vi1 MS CHAP V2 Check AuthenticatorResponse Success for : mit

Aug 26 14:47:47.136: Vi1 PPP: Phase is FORWARDING, Attempting Forward

Aug 26 14:47:47.140: Vi1 PPP: Queue CCP code[1] id[5]

Aug 26 14:47:47.140: Vi1 PPP: Queue IPCP code[1] id[6]

Aug 26 14:47:47.144: Vi1 PPP SSS: forwarding request

Aug 26 14:47:47.148: Vi1 PPP SSS: Receive SSS-Mgr Connect-Local

Aug 26 14:47:47.152: Vi1 PPP: Phase is ESTABLISHING, Finish LCP

Aug 26 14:47:47.156: Vi1 PPP: Phase is UP

Aug 26 14:47:47.160: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10

Aug 26 14:47:47.160: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)

Aug 26 14:47:47.164: Vi1 CCP: O CONFREQ [Closed] id 1 len 4

Aug 26 14:47:47.164: Vi1 PPP: Process pending packets

Aug 26 14:47:47.164: Vi1 IPCP: Redirect packet to Vi1

Aug 26 14:47:47.168: Vi1 IPCP: I CONFREQ [REQsent] id 6 len 10

Aug 26 14:47:47.168: Vi1 IPCP: Address 10.0.1.59 (0x03060A00013B)

Aug 26 14:47:47.172: Vi1 IPCP: O CONFACK [REQsent] id 6 len 10

Aug 26 14:47:47.172: Vi1 IPCP: Address 10.0.1.59 (0x03060A00013B)

Aug 26 14:47:47.172: Vi1 CCP: Redirect packet to Vi1

Aug 26 14:47:47.176: Vi1 CCP: I CONFREQ [REQsent] id 5 len 10

Aug 26 14:47:47.176: Vi1 CCP: MS-PPC supported bits 0x01000041 (0x120601000041)

Aug 26 14:47:47.180: Vi1 CCP: O CONFNAK [REQsent] id 5 len 10

Aug 26 14:47:47.180: Vi1 CCP: MS-PPC supported bits 0x01000040 (0x120601000040)

Aug 26 14:47:47.240: Vi1 IPCP: I CONFNAK [ACKsent] id 1 len 10

Aug 26 14:47:47.244: Vi1 IPCP: Address 10.0.1.3 (0x03060A000103)

Aug 26 14:47:47.244: Vi1 IPCP: O CONFREQ [ACKsent] id 2 len 10

Aug 26 14:47:47.248: Vi1 IPCP: Address 10.0.1.3 (0x03060A000103)

Aug 26 14:47:47.248: Vi1 CCP: I CONFNAK [REQsent] id 1 len 10

Aug 26 14:47:47.252: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.252: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.252: Vi1 CCP: O CONFREQ [REQsent] id 2 len 4

Aug 26 14:47:47.260: Vi1 CCP: I CONFREQ [REQsent] id 7 len 10

Aug 26 14:47:47.260: Vi1 CCP: MS-PPC supported bits 0x01000040 (0x120601000040)

Aug 26 14:47:47.260: Vi1 CCP: O CONFACK [REQsent] id 7 len 10

Aug 26 14:47:47.260: Vi1 CCP: MS-PPC supported bits 0x01000040 (0x120601000040)

Aug 26 14:47:47.284: Vi1 IPCP: I CONFACK [ACKsent] id 2 len 10

Aug 26 14:47:47.288: Vi1 IPCP: Address 10.0.1.3 (0x03060A000103)

Aug 26 14:47:47.288: Vi1 IPCP: State is Open

Aug 26 14:47:47.292: Di4 IPCP: Install negotiated IP interface address 10.0.1.3

Aug 26 14:47:47.308: Di4 IPCP: Install route to 10.0.1.59

Aug 26 14:47:47.312: Vi1 IPCP: Add link info for cef entry 10.0.1.59

Aug 26 14:47:47.312: Vi1 CCP: I CONFNAK [ACKsent] id 2 len 10

Aug 26 14:47:47.316: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.316: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.320: Vi1 CCP: O CONFREQ [ACKsent] id 3 len 4

Aug 26 14:47:47.504: Vi1 CCP: I CONFNAK [ACKsent] id 3 len 10

Aug 26 14:47:47.504: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.504: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.508: Vi1 CCP: O CONFREQ [ACKsent] id 4 len 4

Aug 26 14:47:47.564: Vi1 CCP: I CONFNAK [ACKsent] id 4 len 10

Aug 26 14:47:47.564: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.564: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.564: Vi1 CCP: O CONFREQ [ACKsent] id 5 len 4

Aug 26 14:47:47.608: Vi1 CCP: I CONFNAK [ACKsent] id 5 len 10

Aug 26 14:47:47.608: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.608: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.608: Vi1 CCP: O CONFREQ [ACKsent] id 6 len 4

Aug 26 14:47:47.632: Vi1 CCP: I CONFNAK [ACKsent] id 6 len 10

Aug 26 14:47:47.632: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.632: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.636: Vi1 CCP: O CONFREQ [ACKsent] id 7 len 4

Aug 26 14:47:47.676: Vi1 CCP: I CONFNAK [ACKsent] id 7 len 10

Aug 26 14:47:47.680: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.680: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.680: Vi1 CCP: O CONFREQ [ACKsent] id 8 len 4

Aug 26 14:47:47.764: Vi1 CCP: I CONFNAK [ACKsent] id 8 len 10

Aug 26 14:47:47.768: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.768: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.772: Vi1 CCP: O CONFREQ [ACKsent] id 9 len 4

Aug 26 14:47:47.804: Vi1 CCP: I CONFNAK [ACKsent] id 9 len 10

Aug 26 14:47:47.804: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.808: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.808: Vi1 CCP: O CONFREQ [ACKsent] id 10 len 4

Aug 26 14:47:47.848: Vi1 CCP: I CONFNAK [ACKsent] id 10 len 10

Aug 26 14:47:47.848: Vi1 CCP: MS-PPC supported bits 0x00000000 (0x120600000000)

Aug 26 14:47:47.852: Vi1 CCP: Ignoring unrequested options

Aug 26 14:47:47.852: Vi1 CCP: Failed to negotiate with peer

Aug 26 14:47:47.852: Vi1 CCP: O TERMREQ [ACKsent] id 11 len 4

Aug 26 14:47:47.900: Vi1 CCP: I TERMACK [TERMsent] id 11 len 4

Aug 26 14:47:47.900: Vi1 CCP: State is Closed

Aug 26 14:47:47.904: Vi1 LCP: I TERMREQ [Open] id 8 len 16 (0x49822249003CCD74000002E6)

Aug 26 14:47:47.908: Vi1 LCP: O TERMACK [Open] id 8 len 4

Aug 26 14:47:47.908: Vi1 PPP: Sending Acct Event[Down] id[4]

Aug 26 14:47:47.912: Vi1 PPP: Phase is TERMINATING

Aug 26 14:47:48.012: Vi1 PPP: Block vaccess from being freed [0x15]

Aug 26 14:47:48.012: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to down

Aug 26 14:47:48.020: Vi1 LCP: State is Closed

Aug 26 14:47:48.020: Vi1 PPP: Phase is DOWN

Aug 26 14:47:48.024: Vi1 IPCP: Remove link info for cef entry 10.0.1.59

Aug 26 14:47:48.024: Vi1 PPP: Unlocked by [0x4] Still Locked by [0x13]

Aug 26 14:47:48.028: Vi1 IPCP: State is Closed

Aug 26 14:47:48.028: Vi1 PPP SSS: Send DISCONNECT to mgr_hdl[C8000004]

Aug 26 14:47:48.032: Vi1 PPP: Unlocked by [0x10] Still Locked by [0x3]

Aug 26 14:47:48.032: Vi1 PPP: Unlocked by [0x2] Still Locked by [0x1]

Aug 26 14:47:48.152: Di4 IPCP: Remove route to 10.0.1.59

Aug 26 14:47:48.152: Vi1 PPP: Unlocked by [0x1] Still Locked by [0x0]

Aug 26 14:47:48.156: Vi1 PPP: Free previously blocked vaccess

Aug 26 14:47:50.361: Vi1 PPP: Phase is DOWN, Setup

R1#sh run

Building configuration...

Current configuration : 2070 bytes

!

! Last configuration change at 14:45:30 UTC Sun Aug 26 2012

! NVRAM config last updated at 14:45:36 UTC Sun Aug 26 2012

!

version 12.2

service timestamps debug datetime msec

service timestamps log datetime msec

no service password-encryption

service internal

!

hostname R1

!

logging queue-limit 100

!

memory-size iomem 15

ip subnet-zero

!

ip domain name lab.local

ip name-server 192.168.99.1

!

ip audit notify log

ip audit po max-events 100

vpdn enable

!

vpdn-group 4

request-dialin

protocol pptp

rotary-group 4

initiate-to ip A.B.C.D

!

no ftp-server write-enable

!

interface Ethernet0

ip address 192.168.10.2 255.255.255.0

ip nat inside

half-duplex

!

interface Ethernet1

no ip address

shutdown

half-duplex

!

interface FastEthernet0

ip address 192.168.0.2 255.255.255.0

ip nat outside

speed auto

!

interface Dialer4

description $VPN-JGL$

ip address negotiated

ip nat outside

encapsulation ppp

dialer in-band

dialer idle-timeout 0

dialer string 123

dialer vpdn

dialer-group 4

no cdp enable

ppp pfc local request

ppp pfc remote apply

ppp encrypt mppe auto

ppp authentication ms-chap ms-chap-v2 callin

ppp eap refuse

ppp chap hostname username_removed

ppp chap password 0 password_removed

!

ip nat inside source route-map R2NAT interface FastEthernet0 overload

ip nat inside source route-map VPN interface Dialer4 overload

ip classless

ip route 0.0.0.0 0.0.0.0 192.168.0.1

ip route 10.0.0.0 255.255.252.0 Dialer4

ip route A.B.C.D 255.255.255.255 192.168.0.1

no ip http server

no ip http secure-server

!

access-list 10 permit 192.168.99.0 0.0.0.255

access-list 11 permit 192.168.10.0 0.0.0.255

dialer-list 4 protocol ip permit

!

route-map R2NAT permit 10

match ip address 11

match interface FastEthernet0

!

route-map VPN permit 10

match ip address 10

match interface Dialer4

!

line con 0

exec-timeout 0 0

privilege level 15

logging synchronous

line aux 0

exec-timeout 0 0

privilege level 15

logging synchronous

line vty 0 4

login

!

no scheduler allocate

ntp clock-period 17180187

ntp server 161.53.123.5

!

end

R2#sh run

Building configuration...

Current configuration : 849 bytes

!

version 12.2

service timestamps debug datetime msec

service timestamps log datetime msec

no service password-encryption

!

hostname R2

!

logging queue-limit 100

!

memory-size iomem 15

ip subnet-zero

!

no ip domain lookup

ip domain name lab.local

ip name-server 192.168.99.1

!

ip audit notify log

ip audit po max-events 100

no ftp-server write-enable

!

interface Ethernet0

ip address 192.168.10.1 255.255.255.0

half-duplex

!

interface FastEthernet0

no ip address

shutdown

speed auto

!

ip classless

ip route 0.0.0.0 0.0.0.0 Ethernet0

no ip http server

no ip http secure-server

!

line con 0

exec-timeout 0 0

privilege level 15

logging synchronous

line aux 0

exec-timeout 0 0

privilege level 15

logging synchronous

line vty 0 4

login

!

no scheduler allocate

ntp clock-period 17179854

ntp server 161.53.123.5

!

end

.

bsvorinic · ‎08-27-2012

I made one change in configuration of Dialer4 (added compress mppc) and got one step further (I believe):

!

interface Dialer4

description $VPN-JGL$

ip address negotiated

ip nat outside

encapsulation ppp

dialer in-band

dialer idle-timeout 0

dialer string 123

dialer vpdn

dialer-group 4

compress mppc

no cdp enable

ppp pfc local request

ppp pfc remote apply

ppp encrypt mppe auto

ppp authentication ms-chap ms-chap-v2 callin

ppp eap refuse

ppp chap hostname mit

ppp chap password 0 Kreso!123

!

Now the error causing disconnect is "MPPE: AAA authorization not enabled.". I've searched the web, Cisco documentation and so forth but could not find what could be causing this error and how to fix it.

Here's the new log if anyone can help:

R1#sh debug

VPN:

L2X protocol events debugging is on

L2X data packets debugging is on

L2X protocol errors debugging is on

VPDN SSS events debugging is on

VPDN SSS errors debugging is on

VPDN SSS FSM debugging is on

VPDN scal test debugging is on

VPDN message debugging is on

VPDN errors debugging is on

VPDN packet debugging is on

L2TP data sequencing debugging is on

PPP:

PPP detailed event debugging is on

MPPE Events debugging is on

MPPE Packets debugging is on

MPPE Packet Details debugging is on

PPP protocol negotiation debugging is on

PPP Callback Control Protocol debugging is on

R1#

*Mar 1 00:09:20.828: Vi2 MCB: Initialize

*Mar 1 00:09:20.832: Vi2 MCB: Initialize

*Mar 1 00:09:20.844: Vi2 PPP: Phase is DOWN, Setup

*Mar 1 00:09:20.848: VPN AUTHOR: Error - handle 8232A998 has bad magic, informational traceback below:

*Mar 1 00:09:20.852: -Traceback= 80CC33A8 80CC3688 80CBF9CC 80CC032C 80CC0128 801FAAD0

*Mar 1 00:09:20.856: VPDN MGR: Received message, client voluntary request

*Mar 1 00:09:20.856: Tnl 5 PPTP: Tunnel created; we initiated

*Mar 1 00:09:20.860: Tnl/Sn 5/5 PPTP: Created PNS voluntary session

*Mar 1 00:09:20.864: Tnl 5 PPTP: new-sess -> state change idle to wt-cnnct

R1#

*Mar 1 00:09:20.864: Tnl 5 PPTP: TCP active opening to 213.202.103.45

*Mar 1 00:09:20.976: Tnl 5 PPTP: tcp-conn -> state change wt-cnnct to wt-sccrp

*Mar 1 00:09:21.248: Tnl 5 PPTP: I SCCRP from

*Mar 1 00:09:21.248: Tnl 5 PPTP: protocol version 100

*Mar 1 00:09:21.248: Tnl 5 PPTP: result code 1

*Mar 1 00:09:21.248: Tnl 5 PPTP: error code 0

*Mar 1 00:09:21.248: Tnl 5 PPTP: framing caps 2

*Mar 1 00:09:21.248: Tnl 5 PPTP: bearer caps 3

*Mar 1 00:09:21.248: Tnl 5 PPTP: max channels 0

*Mar 1 00:09:21.248: Tnl 5 PPTP: firmware rev 0

*Mar 1 00:09:21.248: Tnl 5 PPTP: hostname ""

*Mar 1 00:09:21.248: Tnl 5 PPTP: vendor "Microsoft"

*Mar 1 00:09:21.248: Tnl 5 PPTP: SCCRP-ok -> state change wt-sccrp to estabd

*Mar 1 00:09:21.248: Vi2 Tnl/Sn 5/5 PPTP: tnl-up -> state change wt-tun to wt-ocrp

*Mar 1 00:09:21.316: Vi2 Tnl/Sn 5/5 PPTP: OCRP-ok -> state change wt-ocrp to estabd

*Mar 1 00:09:21.320: VPDN CALL [3]: Received client message client connect ok

*Mar 1 00:09:21.324: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up

*Mar 1 00:09:21.328: Vi2 PPP: Using dialer call direction

*Mar 1 00:09:21.332: Vi2 PPP: Treating connection as a callout

*Mar 1 00:09:21.332: Vi2 PPP: Phase is ESTABLISHING, Active Open

*Mar 1 00:09:21.332: Vi2 PPP: No remote authentication for call-out

*Mar 1 00:09:21.336: Vi2 LCP: O CONFREQ [Closed] id 1 len 12

*Mar 1 00:09:21.336: Vi2 LCP: MagicNumber 0x0015D0E0 (0x05060015D0E0)

*Mar 1 00:09:21.340: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.340: Vi2 VPDN FS Network to tunnel: Punted 52 byte pak to l2x process queue

*Mar 1 00:09:21.344: Vi2 VPDN PROCESS Into tunnel: Sending 52 byte pak

*Mar 1 00:09:21.348: L2X: IP socket write 66 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.504: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.504: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 72, seq 0, ack 1

*Mar 1 00:09:21.508: Vi2 VPDN PROCESS From tunnel: Queue 56 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.508: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.508: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.508: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 28, seq 1

*Mar 1 00:09:21.508: Vi2 VPDN PROCESS From tunnel: Queue 16 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.508: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.508: Vi2 LCP: I CONFREQ [REQsent] id 0 len 52

*Mar 1 00:09:21.508: Vi2 LCP: MRU 1400 (0x01040578)

*Mar 1 00:09:21.508: Vi2 LCP: AuthProto EAP (0x0304C227)

*Mar 1 00:09:21.508: Vi2 LCP: MagicNumber 0x01B01546 (0x050601B01546)

*Mar 1 00:09:21.508: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.508: Vi2 LCP: ACFC (0x0802)

*Mar 1 00:09:21.508: Vi2 LCP: Callback 6 (0x0D0306)

*Mar 1 00:09:21.508: Vi2 LCP: MRRU 1614 (0x1104064E)

*Mar 1 00:09:21.508: Vi2 LCP: EndpointDisc 1 Local

*Mar 1 00:09:21.508: Vi2 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

*Mar 1 00:09:21.512: Vi2 LCP: (0xCC281200000000)

*Mar 1 00:09:21.512: Vi2 LCP: O CONFREJ [REQsent] id 0 len 11

*Mar 1 00:09:21.512: Vi2 LCP: Callback 6 (0x0D0306)

*Mar 1 00:09:21.512: Vi2 LCP: MRRU 1614 (0x1104064E)

*Mar 1 00:09:21.512: Vi2 VPDN FS Network to tunnel: Punted 51 byte pak to l2x process queue

*Mar 1 00:09:21.512: Vi2 LCP: I CONFACK [REQsent] id 1 len 12

*Mar 1 00:09:21.512: Vi2 LCP: MagicNumber 0x0015D0E0 (0x05060015D0E0)

*Mar 1 00:09:21.512: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.512: Vi2 VPDN PROCESS Into tunnel: Sending 51 byte pak

*Mar 1 00:09:21.512: L2X: IP socket write 65 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.572: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.572: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 65, seq 2, ack 2

*Mar 1 00:09:21.576: Vi2 VPDN PROCESS From tunnel: Queue 49 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.580: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.580: Vi2 LCP: I CONFREQ [ACKrcvd] id 1 len 45

*Mar 1 00:09:21.584: Vi2 LCP: MRU 1400 (0x01040578)

*Mar 1 00:09:21.584: Vi2 LCP: AuthProto EAP (0x0304C227)

*Mar 1 00:09:21.584: Vi2 LCP: MagicNumber 0x01B01546 (0x050601B01546)

*Mar 1 00:09:21.588: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.588: Vi2 LCP: ACFC (0x0802)

*Mar 1 00:09:21.588: Vi2 LCP: EndpointDisc 1 Local

*Mar 1 00:09:21.588: Vi2 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

*Mar 1 00:09:21.588: Vi2 LCP: (0xCC281200000000)

*Mar 1 00:09:21.588: Vi2 LCP: O CONFNAK [ACKrcvd] id 1 len 13

*Mar 1 00:09:21.588: Vi2 LCP: MRU 1500 (0x010405DC)

*Mar 1 00:09:21.588: Vi2 LCP: AuthProto CHAP (0x0305C22305)

*Mar 1 00:09:21.588: Vi2 VPDN FS Network to tunnel: Punted 53 byte pak to l2x process queue

*Mar 1 00:09:21.592: Vi2 VPDN PROCESS Into tunnel: Sending 53 byte pak

*Mar 1 00:09:21.592: L2X: IP socket write 67 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.612: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.616: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 66, seq 3, ack 3

*Mar 1 00:09:21.616: Vi2 VPDN PROCESS From tunnel: Queue 50 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.620: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.624: Vi2 LCP: I CONFREQ [ACKrcvd] id 2 len 46

*Mar 1 00:09:21.624: Vi2 LCP: MRU 1400 (0x01040578)

*Mar 1 00:09:21.624: Vi2 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

*Mar 1 00:09:21.628: Vi2 LCP: MagicNumber 0x01B01546 (0x050601B01546)

*Mar 1 00:09:21.628: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.628: Vi2 LCP: ACFC (0x0802)

*Mar 1 00:09:21.628: Vi2 LCP: EndpointDisc 1 Local

*Mar 1 00:09:21.628: Vi2 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

*Mar 1 00:09:21.628: Vi2 LCP: (0xCC281200000000)

*Mar 1 00:09:21.628: Vi2 LCP: O CONFNAK [ACKrcvd] id 2 len 8

*Mar 1 00:09:21.628: Vi2 LCP: MRU 1500 (0x010405DC)

*Mar 1 00:09:21.628: Vi2 VPDN FS Network to tunnel: Punted 48 byte pak to l2x process queue

*Mar 1 00:09:21.628: Vi2 VPDN PROCESS Into tunnel: Sending 48 byte pak

*Mar 1 00:09:21.628: L2X: IP socket write 62 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.648: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.652: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 66, seq 4, ack 4

*Mar 1 00:09:21.652: Vi2 VPDN PROCESS From tunnel: Queue 50 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.656: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.660: Vi2 LCP: I CONFREQ [ACKrcvd] id 3 len 46

*Mar 1 00:09:21.660: Vi2 LCP: MRU 1500 (0x010405DC)

*Mar 1 00:09:21.660: Vi2 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

*Mar 1 00:09:21.664: Vi2 LCP: MagicNumber 0x01B01546 (0x050601B01546)

*Mar 1 00:09:21.664: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.664: Vi2 LCP: ACFC (0x0802)

*Mar 1 00:09:21.668: Vi2 LCP: EndpointDisc 1 Local

*Mar 1 00:09:21.668: Vi2 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

*Mar 1 00:09:21.668: Vi2 LCP: (0xCC281200000000)

*Mar 1 00:09:21.672: Vi2 LCP: O CONFACK [ACKrcvd] id 3 len 46

*Mar 1 00:09:21.672: Vi2 LCP: MRU 1500 (0x010405DC)

*Mar 1 00:09:21.672: Vi2 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

*Mar 1 00:09:21.672: Vi2 LCP: MagicNumber 0x01B01546 (0x050601B01546)

*Mar 1 00:09:21.672: Vi2 LCP: PFC (0x0702)

*Mar 1 00:09:21.672: Vi2 LCP: ACFC (0x0802)

*Mar 1 00:09:21.672: Vi2 LCP: EndpointDisc 1 Local

*Mar 1 00:09:21.672: Vi2 LCP: (0x131701690AEC9546534D008BDC9EEA2D)

*Mar 1 00:09:21.672: Vi2 LCP: (0xCC281200000000)

*Mar 1 00:09:21.672: Vi2 VPDN FS Network to tunnel: Punted 86 byte pak to l2x process queue

*Mar 1 00:09:21.672: Vi2 LCP: State is Open

*Mar 1 00:09:21.672: Vi2 MCB: Initialize

*Mar 1 00:09:21.672: Vi2 PPP: Phase is AUTHENTICATING, by the peer

*Mar 1 00:09:21.676: Vi2 VPDN PROCESS Into tunnel: Sending 86 byte pak

*Mar 1 00:09:21.676: L2X: IP socket write 100 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.720: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.720: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 44, seq 5, ack 5

*Mar 1 00:09:21.724: Vi2 VPDN PROCESS From tunnel: Queue 28 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.724: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.728: Vi2 MS-CHAP-V2: I CHALLENGE id 0 len 24 from "VPN"

*Mar 1 00:09:21.740: Vi2 MS CHAP V2: Using hostname from interface CHAP

*Mar 1 00:09:21.744: Vi2 MS CHAP V2: Using password from interface CHAP

*Mar 1 00:09:21.744: Vi2 MS-CHAP-V2: O RESPONSE id 0 len 57 from "mit"

*Mar 1 00:09:21.748: Vi2 VPDN FS Network to tunnel: Punted 97 byte pak to l2x process queue

*Mar 1 00:09:21.752: Vi2 VPDN PROCESS Into tunnel: Sending 97 byte pak

*Mar 1 00:09:21.756: L2X: IP socket write 111 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.884: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.884: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 66, seq 6, ack 6

*Mar 1 00:09:21.888: Vi2 VPDN PROCESS From tunnel: Queue 50 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.892: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.892: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.892: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 26, seq 7

*Mar 1 00:09:21.896: Vi2 VPDN PROCESS From tunnel: Queue 14 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.900: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.900: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.904: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 26, seq 8

*Mar 1 00:09:21.904: Vi2 VPDN PROCESS From tunnel: Queue 14 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.908: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:21.908: Vi2 MS-CHAP-V2: I SUCCESS id 0 len 46 msg is "S=D3EE4B6CDCFFA39BFDEE257E877526294CDE7B33"

*Mar 1 00:09:21.912: Vi2 MS CHAP V2 No Password found for : VPN

*Mar 1 00:09:21.916: Vi2 MS CHAP V2 Check AuthenticatorResponse Success for : mit

*Mar 1 00:09:21.916: Vi2 PPP: Phase is FORWARDING, Attempting Forward

*Mar 1 00:09:21.916: Vi2 PPP: Queue CCP code[1] id[5]

*Mar 1 00:09:21.920: Vi2 PPP: Queue IPCP code[1] id[6]

*Mar 1 00:09:21.928: Vi2 PPP: Phase is ESTABLISHING, Finish LCP

*Mar 1 00:09:21.932: Vi2 PPP: Phase is UP

*Mar 1 00:09:21.936: Vi2 IPCP: O CONFREQ [Closed] id 1 len 10

*Mar 1 00:09:21.936: Vi2 IPCP: Address 0.0.0.0 (0x030600000000)

*Mar 1 00:09:21.940: Vi2 VPDN FS Network to tunnel: Punted 50 byte pak to l2x process queue

*Mar 1 00:09:21.940: Vi2 CCP: O CONFREQ [Closed] id 1 len 10

*Mar 1 00:09:21.944: Vi2 CCP: MS-PPC supported bits 0x01000061 (0x120601000061)

*Mar 1 00:09:21.944: Vi2 VPDN FS Network to tunnel: Punted 50 byte pak to l2x process queue

*Mar 1 00:09:21.948: Vi2 PPP: Process pending packets

*Mar 1 00:09:21.948: Vi2 IPCP: Redirect packet to Vi2

*Mar 1 00:09:21.948: Vi2 IPCP: I CONFREQ [REQsent] id 6 len 10

*Mar 1 00:09:21.952: Vi2 IPCP: Address 10.0.1.59 (0x03060A00013B)

*Mar 1 00:09:21.952: Vi2 IPCP: O CONFACK [REQsent] id 6 len 10

*Mar 1 00:09:21.956: Vi2 IPCP: Address 10.0.1.59 (0x03060A00013B)

*Mar 1 00:09:21.956: Vi2 VPDN FS Network to tunnel: Punted 50 byte pak to l2x process queue

*Mar 1 00:09:21.960: Vi2 CCP: Redirect packet to Vi2

*Mar 1 00:09:21.960: Vi2 CCP: I CONFREQ [REQsent] id 5 len 10

*Mar 1 00:09:21.960: Vi2 CCP: MS-PPC supported bits 0x01000041 (0x120601000041)

*Mar 1 00:09:21.960: Vi2 CCP: O CONFACK [REQsent] id 5 len 10

*Mar 1 00:09:21.960: Vi2 CCP: MS-PPC supported bits 0x01000041 (0x120601000041)

*Mar 1 00:09:21.960: Vi2 VPDN FS Network to tunnel: Punted 50 byte pak to l2x process queue

*Mar 1 00:09:21.960: Vi2 VPDN PROCESS Into tunnel: Sending 50 byte pak

*Mar 1 00:09:21.960: L2X: IP socket write 64 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.960: Vi2 VPDN PROCESS Into tunnel: Sending 50 byte pak

*Mar 1 00:09:21.964: L2X: IP socket write 64 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.964: Vi2 VPDN PROCESS Into tunnel: Sending 50 byte pak

*Mar 1 00:09:21.964: L2X: IP socket write 64 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.964: Vi2 VPDN PROCESS Into tunnel: Sending 50 byte pak

*Mar 1 00:09:21.964: L2X: IP socket write 64 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:21.988: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:21.992: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 30, seq 9, ack 7

*Mar 1 00:09:21.996: Vi2 VPDN PROCESS From tunnel: Queue 14 byte pak to ppp parse and iqueue

*Mar 1 00:09:21.996: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.000: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:22.000: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 30, seq 10, ack 8

*Mar 1 00:09:22.004: Vi2 VPDN PROCESS From tunnel: Queue 14 byte pak to ppp parse and iqueue

*Mar 1 00:09:22.008: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.008: Vi2 IPCP: I CONFNAK [ACKsent] id 1 len 10

*Mar 1 00:09:22.012: Vi2 IPCP: Address 10.0.1.111 (0x03060A00016F)

*Mar 1 00:09:22.012: Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 10

*Mar 1 00:09:22.012: Vi2 IPCP: Address 10.0.1.111 (0x03060A00016F)

*Mar 1 00:09:22.012: Vi2 VPDN FS Network to tunnel: Punted 50 byte pak to l2x process queue

*Mar 1 00:09:22.012: Vi2 CCP: I CONFNAK [ACKsent] id 1 len 10

*Mar 1 00:09:22.012: Vi2 CCP: MS-PPC supported bits 0x01000041 (0x120601000041)

*Mar 1 00:09:22.012: Vi2 CCP: O CONFREQ [ACKsent] id 2 len 10

*Mar 1 00:09:22.012: Vi2 CCP: MS-PPC supported bits 0x01000041 (0x120601000041)

*Mar 1 00:09:22.012: Vi2 VPDN FS Network to tunnel: Punted 50 byte pak to l2x process queue

*Mar 1 00:09:22.012: Vi2 VPDN PROCESS Into tunnel: Sending 50 byte pak

*Mar 1 00:09:22.012: L2X: IP socket write 64 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:22.012: Vi2 VPDN PROCESS Into tunnel: Sending 50 byte pak

*Mar 1 00:09:22.012: L2X: IP socket write 64 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:22.100: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:22.104: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 30, seq 11, ack 11

*Mar 1 00:09:22.108: Vi2 VPDN PROCESS From tunnel: Queue 14 byte pak to ppp parse and iqueue

*Mar 1 00:09:22.108: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.112: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:22.112: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 26, seq 12

*Mar 1 00:09:22.116: Vi2 VPDN PROCESS From tunnel: Queue 14 byte pak to ppp parse and iqueue

*Mar 1 00:09:22.116: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.116: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:22.116: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 82, seq 13

*Mar 1 00:09:22.116: Vi2 VPDN PROCESS From tunnel: Queue 70 byte pak to ppp parse and iqueue

*Mar 1 00:09:22.116: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.116: Vi2 IPCP: I CONFACK [ACKsent] id 2 len 10

*Mar 1 00:09:22.120: Vi2 IPCP: Address 10.0.1.111 (0x03060A00016F)

*Mar 1 00:09:22.120: Vi2 IPCP: State is Open

*Mar 1 00:09:22.120: Vi2 CCP: I CONFACK [ACKsent] id 2 len 10

*Mar 1 00:09:22.120: Vi2 CCP: MS-PPC supported bits 0x01000041 (0x120601000041)

*Mar 1 00:09:22.120: Vi2 CCP: State is Open

*Mar 1 00:09:22.120: Vi2 MPPE: AAA authorization not enabled.

*Mar 1 00:09:22.120: Vi2 CCP: O TERMREQ [Open] id 3 len 4

*Mar 1 00:09:22.124: Vi2 VPDN FS Network to tunnel: Punted 44 byte pak to l2x process queue

*Mar 1 00:09:22.128: Di4 IPCP: Install negotiated IP interface address 10.0.1.111

*Mar 1 00:09:22.144: Di4 IPCP: Install route to 10.0.1.59

*Mar 1 00:09:22.148: Vi2 IPCP: Add link info for cef entry 10.0.1.59

*Mar 1 00:09:22.148: Vi2 VPDN PROCESS Into tunnel: Sending 44 byte pak

*Mar 1 00:09:22.156: L2X: IP socket write 60 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:22.308: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:22.308: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 24, seq 14, ack 13

*Mar 1 00:09:22.312: Vi2 VPDN PROCESS From tunnel: Queue 8 byte pak to ppp parse and iqueue

*Mar 1 00:09:22.316: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.320: VPDN PROCESS: Processing GRE packet received from tunnel

*Mar 1 00:09:22.324: Vi2 PPTP/xGRE: I, src 213.202.103.45, len 32, seq 15

*Mar 1 00:09:22.324: Vi2 VPDN PROCESS From tunnel: Queue 20 byte pak to ppp parse and iqueue

*Mar 1 00:09:22.328: Vi2 VPDN PROCESS From tunnel: Pak send successful

*Mar 1 00:09:22.332: Vi2 CCP: I TERMACK [TERMsent] id 3 len 4

*Mar 1 00:09:22.332: Vi2 CCP: State is Closed

*Mar 1 00:09:22.336: Vi2 LCP: I TERMREQ [Open] id 7 len 16 (0x01B01546003CCD74000002E6)

*Mar 1 00:09:22.336: Vi2 LCP: O TERMACK [Open] id 7 len 4

*Mar 1 00:09:22.340: Vi2 VPDN FS Network to tunnel: Punted 44 byte pak to l2x process queue

*Mar 1 00:09:22.340: Vi2 PPP: Sending Acct Event[Down] id[5]

*Mar 1 00:09:22.344: Vi2 PPP: Phase is TERMINATING

*Mar 1 00:09:22.348: Vi2 VPDN PROCESS Into tunnel: Sending 44 byte pak

*Mar 1 00:09:22.352: L2X: IP socket write 60 bytes, 192.168.0.2 to 213.202.103.45, prot 47

*Mar 1 00:09:22.520: Vi2 Tnl/Sn 5/5 PPTP: ClearReq -> state change estabd to terminal

*Mar 1 00:09:22.520: Vi2 Tnl/Sn 5/5 PPTP: Illegal event 6 in state terminal

*Mar 1 00:09:22.524: Tnl 5 PPTP: no-sess -> state change estabd to wt-stprp

*Mar 1 00:09:22.528: Vi2 Tnl/Sn 5/5 PPTP: Destroying session

*Mar 1 00:09:22.528: Vi2 Tnl/Sn 5/5 PPTP: Unbinding session from idb

*Mar 1 00:09:22.536: VPDN CALL [3]: Received client message server disconnect

*Mar 1 00:09:22.540: Vi2 PPP: Block vaccess from being freed [0x15]

*Mar 1 00:09:22.544: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down

*Mar 1 00:09:22.548: Vi2 LCP: State is Closed

*Mar 1 00:09:22.552: Vi2 PPP: Phase is DOWN

*Mar 1 00:09:22.552: Vi2 IPCP: Remove link info for cef entry 10.0.1.59

*Mar 1 00:09:22.556: Vi2 PPP: Unlocked by [0x4] Still Locked by [0x13]

*Mar 1 00:09:22.556: Vi2 IPCP: State is Closed

*Mar 1 00:09:22.560: Vi2 PPP: Unlocked by [0x10] Still Locked by [0x3]

*Mar 1 00:09:22.560: Vi2 PPP: Unlocked by [0x2] Still Locked by [0x1]

*Mar 1 00:09:22.672: Tnl 5 PPTP: StopCCRP -> state change wt-stprp to terminal

*Mar 1 00:09:22.672: Tnl 5 PPTP: Destroy tunnel

*Mar 1 00:09:22.688: Di4 IPCP: Remove route to 10.0.1.59

*Mar 1 00:09:22.688: Vi2 PPP: Unlocked by [0x1] Still Locked by [0x0]

*Mar 1 00:09:22.688: Vi2 PPP: Free previously blocked vaccessR1#

R1#

Thanks in advance (again :-)).

Bruno

bsvorinic · ‎09-07-2012

Tried it on a (non-virtual) production router (c2900-universalk9-mz.SPA.151-4.M.bin) and configuration from my previous post works.

I'm not sure why it didn't work in GNS3 environment (I was using 1700 router there with c1700-k9o3sy7-mz.122-15.ZL1 image).

Maybe this helps someone down the road...