Solved: PPTP VPN between Windows clients and Cisco 2921 router

sergey.sheremet · ‎10-24-2011

Hello everyone!

I have a trouble with PPTP VPN between Windows clients and Cisco 2921 router with RADIUS (IAS) authorization. When I try to connect to Cisco 2921 from Windows 7 using MS-CHAP v2 I receive error 778: it was not possible to verify the identity of server . Then I use PAP - everythig is OK. On Windows XP the same situation.

Cisco config:

version 15.0

service timestamps debug datetime msec

service timestamps log datetime msec

service password-encryption

!

hostname gw.izmv

!

boot-start-marker

boot-end-marker

!

logging buffered 51200 warnings

!

aaa new-model

!

aaa authentication ppp default group radius local

!

aaa session-id common

!

clock timezone +002 2

!

no ipv6 cef

ip source-route

ip cef

!

multilink bundle-name authenticated

!

async-bootp dns-server 192.168.192.XX

vpdn enable

!

vpdn-group 1

! Default PPTP VPDN group

accept-dialin

protocol pptp

virtual-template 1

pptp tunnel echo 10

l2tp tunnel timeout no-session 15

ip pmtu

ip mtu adjust

!

redundancy

!

interface Loopback0

ip address 192.168.207.1 255.255.255.0

!

interface GigabitEthernet0/0

description $ETH-LAN$$ETH-SW-LAUNCH$$INTF-INFO-GE 0/0$

ip address 192.168.192.XXX 255.255.255.0

ip address 192.168.192.XX 255.255.255.0 secondary

ip nat inside

ip virtual-reassembly

duplex auto

speed auto

!

interface GigabitEthernet0/1

no ip address

shutdown

duplex auto

speed auto

!

interface GigabitEthernet0/2

description --- Inet ---

no ip address

ip nat outside

ip virtual-reassembly

duplex auto

speed auto

pppoe enable group global

pppoe-client dial-pool-number 1

no cdp enable

!

interface Virtual-Template1

ip unnumbered Loopback0

ip mtu 1492

ip virtual-reassembly

autodetect encapsulation ppp

peer default ip address pool PPP

ppp encrypt mppe auto required

ppp authentication ms-chap-v2

!

interface Dialer1

ip address negotiated

ip nat outside

ip virtual-reassembly

encapsulation ppp

dialer pool 1

dialer-group 1

ppp authentication pap callin

ppp pap sent-username DSLUSERNAME password DSLPASSWORD

no cdp enable

!

ip local pool PPP 192.168.207.200 192.168.207.250

ip forward-protocol nd

!

ip nat inside source list NAT_ACL interface Dialer1 overload

ip nat inside source static tcp 192.168.192.XX 25 82.XXX.XXX.XXX 25 extendable

ip nat inside source static tcp 192.168.192.XX 1352 82.XXX.XXX.XXX 1352 extendable

ip route 0.0.0.0 0.0.0.0 Dialer1

!

ip access-list extended NAT_ACL

deny ip 192.168.192.0 0.0.0.255 192.168.YYY.0 0.0.0.255

permit tcp 192.168.192.0 0.0.0.255 any eq www

permit tcp 192.168.192.0 0.0.0.255 any eq 443

permit tcp 192.168.192.0 0.0.0.255 any eq 1352

permit tcp host 192.168.192.XX any eq smtp

permit tcp 192.168.192.0 0.0.0.255 any eq 22

permit tcp host 192.168.192.XX any eq domain

permit udp host 192.168.192.XX any eq domain

!

radius-server host 192.168.192.XX auth-port 1645 acct-port 1646

radius-server key IASKEY

!

control-plane

!

line con 0

line aux 0

line vty 0 4

line vty 5 15

!

scheduler allocate 20000 1000

end

The debug is follow:

Oct 21 14:47:51.755: PPP: Alloc Context [294C7BC4]

Oct 21 14:47:51.755: ppp98 PPP: Phase is ESTABLISHING

Oct 21 14:47:51.755: ppp98 PPP: Using AAA Unique Id = 8B

Oct 21 14:47:51.755: ppp98 PPP: Authorization NOT required

Oct 21 14:47:51.755: ppp98 PPP: Using vpn set call direction

Oct 21 14:47:51.755: ppp98 PPP: Treating connection as a callin

Oct 21 14:47:51.755: ppp98 PPP: Session handle[62] Session id[98]

Oct 21 14:47:51.755: ppp98 LCP: Event[OPEN] State[Initial to Starting]

Oct 21 14:47:51.755: ppp98 PPP LCP: Enter passive mode, state[Stopped]

Oct 21 14:47:53.759: ppp98 PPP LCP: Exit passive mode, state[Starting]

Oct 21 14:47:53.759: ppp98 LCP: O CONFREQ [Starting] id 1 len 19

Oct 21 14:47:53.759: ppp98 LCP: MRU 1464 (0x010405B8)

Oct 21 14:47:53.759: ppp98 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Oct 21 14:47:53.759: ppp98 LCP: MagicNumber 0xF018D237 (0x0506F018D237)

Oct 21 14:47:53.759: ppp98 LCP: Event[UP] State[Starting to REQsent]

Oct 21 14:47:54.351: ppp98 LCP: I CONFREQ [REQsent] id 0 len 18

Oct 21 14:47:54.351: ppp98 LCP: MRU 1400 (0x01040578)

Oct 21 14:47:54.351: ppp98 LCP: MagicNumber 0x2F7C5F7E (0x05062F7C5F7E)

Oct 21 14:47:54.351: ppp98 LCP: PFC (0x0702)

Oct 21 14:47:54.351: ppp98 LCP: ACFC (0x0802)

Oct 21 14:47:54.351: ppp98 LCP: O CONFNAK [REQsent] id 0 len 8

Oct 21 14:47:54.351: ppp98 LCP: MRU 1464 (0x010405B8)

Oct 21 14:47:54.351: ppp98 LCP: Event[Receive ConfReq-] State[REQsent to REQsent]

Oct 21 14:47:54.751: ppp98 LCP: I CONFACK [REQsent] id 1 len 19

Oct 21 14:47:54.751: ppp98 LCP: MRU 1464 (0x010405B8)

Oct 21 14:47:54.751: ppp98 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Oct 21 14:47:54.751: ppp98 LCP: MagicNumber 0xF018D237 (0x0506F018D237)

Oct 21 14:47:54.751: ppp98 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]

Oct 21 14:47:54.915: ppp98 LCP: I CONFREQ [ACKrcvd] id 1 len 18

Oct 21 14:47:54.915: ppp98 LCP: MRU 1400 (0x01040578)

Oct 21 14:47:54.915: ppp98 LCP: MagicNumber 0x2F7C5F7E (0x05062F7C5F7E)

Oct 21 14:47:54.915: ppp98 LCP: PFC (0x0702)

Oct 21 14:47:54.915: ppp98 LCP: ACFC (0x0802)

Oct 21 14:47:54.915: ppp98 LCP: O CONFNAK [ACKrcvd] id 1 len 8

Oct 21 14:47:54.915: ppp98 LCP: MRU 1464 (0x010405B8)

Oct 21 14:47:54.915: ppp98 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]

Oct 21 14:47:55.275: ppp98 LCP: I CONFREQ [ACKrcvd] id 2 len 18

Oct 21 14:47:55.275: ppp98 LCP: MRU 1464 (0x010405B8)

Oct 21 14:47:55.275: ppp98 LCP: MagicNumber 0x2F7C5F7E (0x05062F7C5F7E)

Oct 21 14:47:55.275: ppp98 LCP: PFC (0x0702)

Oct 21 14:47:55.275: ppp98 LCP: ACFC (0x0802)

Oct 21 14:47:55.275: ppp98 LCP: O CONFACK [ACKrcvd] id 2 len 18

Oct 21 14:47:55.275: ppp98 LCP: MRU 1464 (0x010405B8)

Oct 21 14:47:55.275: ppp98 LCP: MagicNumber 0x2F7C5F7E (0x05062F7C5F7E)

Oct 21 14:47:55.275: ppp98 LCP: PFC (0x0702)

Oct 21 14:47:55.275: ppp98 LCP: ACFC (0x0802)

Oct 21 14:47:55.275: ppp98 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]

Oct 21 14:47:55.295: ppp98 PPP: Phase is AUTHENTICATING, by this end

Oct 21 14:47:55.295: ppp98 MS-CHAP-V2: O CHALLENGE id 1 len 28 from "gw.izmv"

Oct 21 14:47:55.295: ppp98 LCP: State is Open

Oct 21 14:47:55.583: ppp98 MS-CHAP-V2: I RESPONSE id 1 len 71 from "DOMAIN\username"

Oct 21 14:47:55.583: ppp98 PPP: Phase is FORWARDING, Attempting Forward

Oct 21 14:47:55.583: ppp98 PPP: Phase is AUTHENTICATING, Unauthenticated User

Oct 21 14:47:55.587: ppp98 PPP: Sent MSCHAP_V2 LOGIN Request

Oct 21 14:47:55.591: ppp98 PPP: Received LOGIN Response PASS

Oct 21 14:47:55.591: ppp98 PPP AUTHOR: Author Data NOT Available

Oct 21 14:47:55.591: ppp98 PPP: Phase is FORWARDING, Attempting Forward

Oct 21 14:47:55.595: Vi3 PPP: Phase is AUTHENTICATING, Authenticated User

Oct 21 14:47:55.595: Vi3: No MS_CHAP_V2 msg data

Oct 21 14:47:55.595: Vi3 MS-CHAP-V2: O SUCCESS id 1 len 46 msg is "tG@@#QDD@(@B@(@#@I@I@:QYbGAP@A@@@@@@ EJFDE"

Oct 21 14:47:55.595: Vi3 PPP: Phase is UP

Oct 21 14:47:55.595: Vi3 IPCP: Protocol configured, start CP. state[Initial]

Oct 21 14:47:55.595: Vi3 IPCP: Event[OPEN] State[Initial to Starting]

Oct 21 14:47:55.595: Vi3 IPCP: O CONFREQ [Starting] id 1 len 10

Oct 21 14:47:55.595: Vi3 IPCP: Address 192.168.207.1 (0x0306C0A8CF01)

Oct 21 14:47:55.595: Vi3 IPCP: Event[UP] State[Starting to REQsent]

Oct 21 14:47:55.595: Vi3 CCP: Protocol configured, start CP. state[Initial]

Oct 21 14:47:55.595: Vi3 CCP: Event[OPEN] State[Initial to Starting]

Oct 21 14:47:55.595: Vi3 CCP: O CONFREQ [Starting] id 1 len 10

Oct 21 14:47:55.595: Vi3 CCP: MS-PPC supported bits 0x01000060 (0x120601000060)

Oct 21 14:47:55.595: Vi3 CCP: Event[UP] State[Starting to REQsent]

Oct 21 14:47:55.599: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to up

Oct 21 14:47:55.603: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to up

Oct 21 14:47:56.027: Vi3 LCP: I TERMREQ [Open] id 3 len 16

Oct 21 14:47:56.027: Vi3 LCP: (0x2F7C5F7E003CCD740000030A)

Oct 21 14:47:56.027: Vi3 IPCP: Event[DOWN] State[REQsent to Starting]

Oct 21 14:47:56.027: Vi3 IPCP: Event[CLOSE] State[Starting to Initial]

Oct 21 14:47:56.027: Vi3 CCP: Event[DOWN] State[REQsent to Starting]

Oct 21 14:47:56.027: Vi3 PPP DISC: Required MPPE not negotiated

Oct 21 14:47:56.027: Vi3 PPP: Sending Acct Event[Down] id[8B]

Oct 21 14:47:56.027: Vi3 CCP: Event[CLOSE] State[Starting to Initial]

Oct 21 14:47:56.027: Vi3 LCP: O TERMACK [Open] id 3 len 4

Oct 21 14:47:56.027: Vi3 LCP: Event[Receive TermReq] State[Open to Stopping]

Oct 21 14:47:56.027: Vi3 PPP: Phase is TERMINATING

Oct 21 14:47:56.027: Vi3 LCP: Event[CLOSE] State[Stopping to Closing]

Oct 21 14:47:56.675: Vi3 PPP: Block vaccess from being freed [0x10]

Oct 21 14:47:56.675: Vi3 LCP: Event[CLOSE] State[Closing to Closing]

Oct 21 14:47:56.679: Vi3 LCP: Event[DOWN] State[Closing to Initial]

Oct 21 14:47:56.679: Vi3 PPP: Clearing AAA Unique Id = 8B

Oct 21 14:47:56.679: Vi3 PPP: Unlocked by [0x10] Still Locked by [0x0]

Oct 21 14:47:56.679: Vi3 PPP: Free previously blocked vaccess

Oct 21 14:47:56.679: Vi3 PPP: Phase is DOWN

Oct 21 14:47:56.679: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to down

Oct 21 14:47:56.683: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to down

I will be very grateful for any useful suggestions

wschenkeveld · ‎11-17-2011

We had the same problem using MS-CHAP-V2 and 3945 router using IOS 15.2. When adding the same user/password combination locally it worked fine but that was no solution offcourse. We solved this issue by adding the following line in the config :

aaa authorization network default if-authenticated

This is because Windows 2000 clients require the use of a aaa authorization statement in the router config. Maybe this was default (and therefore not shown) in previous IOS releases.

Succes !!!

Wil Schenkeveld

View solution in original post

Eugene Khabarov · ‎10-24-2011

What is your IOS version? Seems to me it can be a bug. What happens if there is local authentication confugured? Is it works?

---

HTH. Please rate this post if it was helpful. If this solves your problem, please mark this post as "Correct Answer."

sergey.sheremet · ‎10-24-2011

Hi Eugene,

gw.izmv#sh ver

Cisco IOS Software, C2900 Software (C2900-UNIVERSALK9-M), Version 15.0(1)M6, RELEASE SOFTWARE (fc1)

I don't try to use a local authentication, yet - it will be a "last chance".

sergey.sheremet · ‎10-24-2011

Situation the same, error code changed only - now it's 734.

Config:

aaa authentication ppp default local

Debug:

Oct 24 10:18:11.534: PPP: Alloc Context [294C7BC4]

Oct 24 10:18:11.534: ppp105 PPP: Phase is ESTABLISHING

Oct 24 10:18:11.534: ppp105 PPP: Using AAA Unique Id = A6

Oct 24 10:18:11.534: ppp105 PPP: Authorization NOT required

Oct 24 10:18:11.534: ppp105 PPP: Using vpn set call direction

Oct 24 10:18:11.534: ppp105 PPP: Treating connection as a callin

Oct 24 10:18:11.534: ppp105 PPP: Session handle[79000069] Session id[105]

Oct 24 10:18:11.534: ppp105 LCP: Event[OPEN] State[Initial to Starting]

Oct 24 10:18:11.534: ppp105 PPP LCP: Enter passive mode, state[Stopped]

Oct 24 10:18:11.706: ppp105 LCP: I CONFREQ [Stopped] id 0 len 18

Oct 24 10:18:11.706: ppp105 LCP: MRU 1400 (0x01040578)

Oct 24 10:18:11.706: ppp105 LCP: MagicNumber 0x374A4A26 (0x0506374A4A26)

Oct 24 10:18:11.706: ppp105 LCP: PFC (0x0702)

Oct 24 10:18:11.706: ppp105 LCP: ACFC (0x0802)

Oct 24 10:18:11.706: ppp105 LCP: O CONFREQ [Stopped] id 1 len 19

Oct 24 10:18:11.706: ppp105 LCP: MRU 1464 (0x010405B8)

Oct 24 10:18:11.706: ppp105 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Oct 24 10:18:11.706: ppp105 LCP: MagicNumber 0xFE95021B (0x0506FE95021B)

Oct 24 10:18:11.706: ppp105 LCP: O CONFNAK [Stopped] id 0 len 8

Oct 24 10:18:11.706: ppp105 LCP: MRU 1464 (0x010405B8)

Oct 24 10:18:11.706: ppp105 LCP: Event[Receive ConfReq-] State[Stopped to REQsent]

Oct 24 10:18:11.758: ppp105 LCP: I CONFACK [REQsent] id 1 len 19

Oct 24 10:18:11.758: ppp105 LCP: MRU 1464 (0x010405B8)

Oct 24 10:18:11.758: ppp105 LCP: AuthProto MS-CHAP-V2 (0x0305C22381)

Oct 24 10:18:11.758: ppp105 LCP: MagicNumber 0xFE95021B (0x0506FE95021B)

Oct 24 10:18:11.758: ppp105 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]

Oct 24 10:18:11.758: ppp105 LCP: I CONFREQ [ACKrcvd] id 1 len 18

Oct 24 10:18:11.758: ppp105 LCP: MRU 1400 (0x01040578)

Oct 24 10:18:11.758: ppp105 LCP: MagicNumber 0x374A4A26 (0x0506374A4A26)

Oct 24 10:18:11.758: ppp105 LCP: PFC (0x0702)

Oct 24 10:18:11.758: ppp105 LCP: ACFC (0x0802)

Oct 24 10:18:11.758: ppp105 LCP: O CONFNAK [ACKrcvd] id 1 len 8

Oct 24 10:18:11.758: ppp105 LCP: MRU 1464 (0x010405B8)

Oct 24 10:18:11.758: ppp105 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]

Oct 24 10:18:11.806: ppp105 LCP: I CONFREQ [ACKrcvd] id 2 len 18

Oct 24 10:18:11.806: ppp105 LCP: MRU 1464 (0x010405B8)

Oct 24 10:18:11.806: ppp105 LCP: MagicNumber 0x374A4A26 (0x0506374A4A26)

Oct 24 10:18:11.806: ppp105 LCP: PFC (0x0702)

Oct 24 10:18:11.810: ppp105 LCP: ACFC (0x0802)

Oct 24 10:18:11.810: ppp105 LCP: O CONFACK [ACKrcvd] id 2 len 18

Oct 24 10:18:11.810: ppp105 LCP: MRU 1464 (0x010405B8)

Oct 24 10:18:11.810: ppp105 LCP: MagicNumber 0x374A4A26 (0x0506374A4A26)

Oct 24 10:18:11.810: ppp105 LCP: PFC (0x0702)

Oct 24 10:18:11.810: ppp105 LCP: ACFC (0x0802)

Oct 24 10:18:11.810: ppp105 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]

Oct 24 10:18:11.822: ppp105 PPP: Phase is AUTHENTICATING, by this end

Oct 24 10:18:11.822: ppp105 MS-CHAP-V2: O CHALLENGE id 1 len 28 from "gw.izmv"

Oct 24 10:18:11.822: ppp105 LCP: State is Open

Oct 24 10:18:11.874: ppp105 MS-CHAP-V2: I RESPONSE id 1 len 61 from "vpnuser"

Oct 24 10:18:11.874: ppp105 PPP: Phase is FORWARDING, Attempting Forward

Oct 24 10:18:11.874: ppp105 PPP: Phase is AUTHENTICATING, Unauthenticated User

Oct 24 10:18:11.874: ppp105 PPP: Sent MSCHAP_V2 LOGIN Request

Oct 24 10:18:11.878: ppp105 PPP: Received LOGIN Response PASS

Oct 24 10:18:11.878: ppp105 PPP AUTHOR: Author Data NOT Available

Oct 24 10:18:11.878: ppp105 PPP: Phase is FORWARDING, Attempting Forward

Oct 24 10:18:11.882: Vi5 PPP: Phase is AUTHENTICATING, Authenticated User

Oct 24 10:18:11.882: Vi5: No MS_CHAP_V2 msg data

Oct 24 10:18:11.882: Vi5 MS-CHAP-V2: O SUCCESS id 1 len 46 msg is "S=3823C25FC6EA157AF892E29AE1590A527DE1B976"

Oct 24 10:18:11.882: Vi5 PPP: Phase is UP

Oct 24 10:18:11.882: Vi5 IPCP: Protocol configured, start CP. state[Initial]

Oct 24 10:18:11.882: Vi5 IPCP: Event[OPEN] State[Initial to Starting]

Oct 24 10:18:11.882: Vi5 IPCP: O CONFREQ [Starting] id 1 len 10

Oct 24 10:18:11.882: Vi5 IPCP: Address 192.168.207.1 (0x0306C0A8CF01)

Oct 24 10:18:11.882: Vi5 IPCP: Event[UP] State[Starting to REQsent]

Oct 24 10:18:11.882: Vi5 CCP: Protocol configured, start CP. state[Initial]

Oct 24 10:18:11.882: Vi5 CCP: Event[OPEN] State[Initial to Starting]

Oct 24 10:18:11.882: Vi5 CCP: O CONFREQ [Starting] id 1 len 10

Oct 24 10:18:11.882: Vi5 CCP: MS-PPC supported bits 0x01000060 (0x120601000060)

Oct 24 10:18:11.882: Vi5 CCP: Event[UP] State[Starting to REQsent]

Oct 24 10:18:11.886: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to up

Oct 24 10:18:11.890: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to up

Oct 24 10:18:11.962: Vi5 CCP: I CONFREQ [REQsent] id 3 len 10

Oct 24 10:18:11.962: Vi5 CCP: MS-PPC supported bits 0x01000000 (0x120601000000)

Oct 24 10:18:11.962: Vi5 CCP: MPPC Option asks for neither compression nor encryption

Oct 24 10:18:11.962: Vi5 CCP: O CONFREJ [REQsent] id 3 len 10

Oct 24 10:18:11.962: Vi5 CCP: MS-PPC supported bits 0x01000000 (0x120601000000)

Oct 24 10:18:11.962: Vi5 CCP: Event[Receive ConfReq-] State[REQsent to REQsent]

Oct 24 10:18:11.962: Vi5 IPCP: I CONFREQ [REQsent] id 4 len 34

Oct 24 10:18:11.962: Vi5 IPCP: Address 0.0.0.0 (0x030600000000)

Oct 24 10:18:11.962: Vi5 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)

Oct 24 10:18:11.962: Vi5 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)

Oct 24 10:18:11.966: Vi5 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)

Oct 24 10:18:11.966: Vi5 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)

Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: Done. Her address 0.0.0.0, we want 0.0.0.0

Oct 24 10:18:11.966: Vi5 IPCP: Pool returned 192.168.207.203

Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for primary dns

Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for primary wins

Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for seconday dns

Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for seconday wins

Oct 24 10:18:11.966: Vi5 IPCP: O CONFREJ [REQsent] id 4 len 22

Oct 24 10:18:11.966: Vi5 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)

Oct 24 10:18:11.966: Vi5 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)

Oct 24 10:18:11.966: Vi5 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)

Oct 24 10:18:11.966: Vi5 IPCP: Event[Receive ConfReq-] State[REQsent to REQsent]

Oct 24 10:18:11.966: Vi5 IPCP: I CONFACK [REQsent] id 1 len 10

Oct 24 10:18:11.966: Vi5 IPCP: Address 192.168.207.1 (0x0306C0A8CF01)

Oct 24 10:18:11.966: Vi5 IPCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]

Oct 24 10:18:11.966: Vi5 CCP: I CONFNAK [REQsent] id 1 len 10

Oct 24 10:18:11.966: Vi5 CCP: MS-PPC supported bits 0x01000040 (0x120601000040)

Oct 24 10:18:11.966: Vi5 CCP: O CONFREQ [REQsent] id 2 len 10

Oct 24 10:18:11.966: Vi5 CCP: MS-PPC supported bits 0x01000040 (0x120601000040)

Oct 24 10:18:11.966: Vi5 CCP: Event[Receive ConfNak/Rej] State[REQsent to REQsent]

Oct 24 10:18:12.018: Vi5 CCP: I TERMREQ [REQsent] id 5 len 16

Oct 24 10:18:12.018: Vi5 CCP: (0x374A4A26003CCD74000002DC)

Oct 24 10:18:12.018: Vi5 CCP: O TERMACK [REQsent] id 5 len 4

Oct 24 10:18:12.018: Vi5 CCP: Event[Receive TermReq] State[REQsent to REQsent]

Oct 24 10:18:12.018: Vi5 PPP DISC: Required MPPE not negotiated

Oct 24 10:18:12.018: Vi5 PPP: Sending Acct Event[Down] id[A6]

Oct 24 10:18:12.018: Vi5 PPP CCP: Enter passive mode, state[Stopped]

Oct 24 10:18:12.018: Vi5 IPCP: Event[DOWN] State[ACKrcvd to Starting]

Oct 24 10:18:12.018: Vi5 IPCP: Event[CLOSE] State[Starting to Initial]

Oct 24 10:18:12.018: Vi5 CCP: Event[DOWN] State[Stopped to Starting]

Oct 24 10:18:12.018: Vi5 CCP: Event[CLOSE] State[Starting to Initial]

Oct 24 10:18:12.018: Vi5 LCP: O TERMREQ [Open] id 2 len 4

Oct 24 10:18:12.018: Vi5 LCP: Event[CLOSE] State[Open to Closing]

Oct 24 10:18:12.018: Vi5 PPP: Phase is TERMINATING

Oct 24 10:18:12.018: Vi5 LCP: Event[CLOSE] State[Closing to Closing]

Oct 24 10:18:12.066: Vi5 LCP: I TERMACK [Closing] id 2 len 4

Oct 24 10:18:12.066: Vi5 LCP: Event[Receive TermAck] State[Closing to Closed]

Oct 24 10:18:12.066: Vi5 LCP: Event[DOWN] State[Closed to Initial]

Oct 24 10:18:12.066: Vi5 PPP: Clearing AAA Unique Id = A6

Oct 24 10:18:12.066: Vi5 PPP: Phase is DOWN

Oct 24 10:18:12.070: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to down

Oct 24 10:18:12.070: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to down Oct 24 10:18:11.534: PPP: Alloc Context [294C7BC4]
Oct 24 10:18:11.534: ppp105 PPP: Phase is ESTABLISHING
Oct 24 10:18:11.534: ppp105 PPP: Using AAA Unique Id = A6
Oct 24 10:18:11.534: ppp105 PPP: Authorization NOT required
Oct 24 10:18:11.534: ppp105 PPP: Using vpn set call direction
Oct 24 10:18:11.534: ppp105 PPP: Treating connection as a callin
Oct 24 10:18:11.534: ppp105 PPP: Session handle[79000069] Session id[105]
Oct 24 10:18:11.534: ppp105 LCP: Event[OPEN] State[Initial to Starting]
Oct 24 10:18:11.534: ppp105 PPP LCP: Enter passive mode, state[Stopped]
Oct 24 10:18:11.706: ppp105 LCP: I CONFREQ [Stopped] id 0 len 18
Oct 24 10:18:11.706: ppp105 LCP:    MRU 1400 (0x01040578)
Oct 24 10:18:11.706: ppp105 LCP:    MagicNumber 0x374A4A26 (0x0506374A4A26)
Oct 24 10:18:11.706: ppp105 LCP:    PFC (0x0702)
Oct 24 10:18:11.706: ppp105 LCP:    ACFC (0x0802)
Oct 24 10:18:11.706: ppp105 LCP: O CONFREQ [Stopped] id 1 len 19
Oct 24 10:18:11.706: ppp105 LCP:    MRU 1464 (0x010405B8)
Oct 24 10:18:11.706: ppp105 LCP:    AuthProto MS-CHAP-V2 (0x0305C22381)
Oct 24 10:18:11.706: ppp105 LCP:    MagicNumber 0xFE95021B (0x0506FE95021B)
Oct 24 10:18:11.706: ppp105 LCP: O CONFNAK [Stopped] id 0 len 8
Oct 24 10:18:11.706: ppp105 LCP:    MRU 1464 (0x010405B8)
Oct 24 10:18:11.706: ppp105 LCP: Event[Receive ConfReq-] State[Stopped to REQsent]
Oct 24 10:18:11.758: ppp105 LCP: I CONFACK [REQsent] id 1 len 19
Oct 24 10:18:11.758: ppp105 LCP:    MRU 1464 (0x010405B8)
Oct 24 10:18:11.758: ppp105 LCP:    AuthProto MS-CHAP-V2 (0x0305C22381)
Oct 24 10:18:11.758: ppp105 LCP:    MagicNumber 0xFE95021B (0x0506FE95021B)
Oct 24 10:18:11.758: ppp105 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
Oct 24 10:18:11.758: ppp105 LCP: I CONFREQ [ACKrcvd] id 1 len 18
Oct 24 10:18:11.758: ppp105 LCP:    MRU 1400 (0x01040578)
Oct 24 10:18:11.758: ppp105 LCP:    MagicNumber 0x374A4A26 (0x0506374A4A26)
Oct 24 10:18:11.758: ppp105 LCP:    PFC (0x0702)
Oct 24 10:18:11.758: ppp105 LCP:    ACFC (0x0802)
Oct 24 10:18:11.758: ppp105 LCP: O CONFNAK [ACKrcvd] id 1 len 8
Oct 24 10:18:11.758: ppp105 LCP:    MRU 1464 (0x010405B8)
Oct 24 10:18:11.758: ppp105 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
Oct 24 10:18:11.806: ppp105 LCP: I CONFREQ [ACKrcvd] id 2 len 18
Oct 24 10:18:11.806: ppp105 LCP:    MRU 1464 (0x010405B8)
Oct 24 10:18:11.806: ppp105 LCP:    MagicNumber 0x374A4A26 (0x0506374A4A26)
Oct 24 10:18:11.806: ppp105 LCP:    PFC (0x0702)
Oct 24 10:18:11.810: ppp105 LCP:    ACFC (0x0802)
Oct 24 10:18:11.810: ppp105 LCP: O CONFACK [ACKrcvd] id 2 len 18
Oct 24 10:18:11.810: ppp105 LCP:    MRU 1464 (0x010405B8)
Oct 24 10:18:11.810: ppp105 LCP:    MagicNumber 0x374A4A26 (0x0506374A4A26)
Oct 24 10:18:11.810: ppp105 LCP:    PFC (0x0702)
Oct 24 10:18:11.810: ppp105 LCP:    ACFC (0x0802)
Oct 24 10:18:11.810: ppp105 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
Oct 24 10:18:11.822: ppp105 PPP: Phase is AUTHENTICATING, by this end
Oct 24 10:18:11.822: ppp105 MS-CHAP-V2: O CHALLENGE id 1 len 28 from "gw.izmv"
Oct 24 10:18:11.822: ppp105 LCP: State is Open
Oct 24 10:18:11.874: ppp105 MS-CHAP-V2: I RESPONSE id 1 len 61 from "vpnuser"
Oct 24 10:18:11.874: ppp105 PPP: Phase is FORWARDING, Attempting Forward
Oct 24 10:18:11.874: ppp105 PPP: Phase is AUTHENTICATING, Unauthenticated User
Oct 24 10:18:11.874: ppp105 PPP: Sent MSCHAP_V2 LOGIN Request
Oct 24 10:18:11.878: ppp105 PPP: Received LOGIN Response PASS
Oct 24 10:18:11.878: ppp105 PPP AUTHOR: Author Data NOT Available
Oct 24 10:18:11.878: ppp105 PPP: Phase is FORWARDING, Attempting Forward
Oct 24 10:18:11.882: Vi5 PPP: Phase is AUTHENTICATING, Authenticated User
Oct 24 10:18:11.882: Vi5: No MS_CHAP_V2 msg data
Oct 24 10:18:11.882: Vi5 MS-CHAP-V2: O SUCCESS id 1 len 46 msg is "S=3823C25FC6EA157AF892E29AE1590A527DE1B976"
Oct 24 10:18:11.882: Vi5 PPP: Phase is UP
Oct 24 10:18:11.882: Vi5 IPCP: Protocol configured, start CP. state[Initial]
Oct 24 10:18:11.882: Vi5 IPCP: Event[OPEN] State[Initial to Starting]
Oct 24 10:18:11.882: Vi5 IPCP: O CONFREQ [Starting] id 1 len 10
Oct 24 10:18:11.882: Vi5 IPCP:    Address 192.168.207.1 (0x0306C0A8CF01)
Oct 24 10:18:11.882: Vi5 IPCP: Event[UP] State[Starting to REQsent]
Oct 24 10:18:11.882: Vi5 CCP: Protocol configured, start CP. state[Initial]
Oct 24 10:18:11.882: Vi5 CCP: Event[OPEN] State[Initial to Starting]
Oct 24 10:18:11.882: Vi5 CCP: O CONFREQ [Starting] id 1 len 10
Oct 24 10:18:11.882: Vi5 CCP:    MS-PPC supported bits 0x01000060 (0x120601000060)
Oct 24 10:18:11.882: Vi5 CCP: Event[UP] State[Starting to REQsent]
Oct 24 10:18:11.886: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to up
Oct 24 10:18:11.890: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to up
Oct 24 10:18:11.962: Vi5 CCP: I CONFREQ [REQsent] id 3 len 10
Oct 24 10:18:11.962: Vi5 CCP:    MS-PPC supported bits 0x01000000 (0x120601000000)
Oct 24 10:18:11.962: Vi5 CCP: MPPC Option asks for neither compression nor encryption
Oct 24 10:18:11.962: Vi5 CCP: O CONFREJ [REQsent] id 3 len 10
Oct 24 10:18:11.962: Vi5 CCP:    MS-PPC supported bits 0x01000000 (0x120601000000)
Oct 24 10:18:11.962: Vi5 CCP: Event[Receive ConfReq-] State[REQsent to REQsent]
Oct 24 10:18:11.962: Vi5 IPCP: I CONFREQ [REQsent] id 4 len 34
Oct 24 10:18:11.962: Vi5 IPCP:    Address 0.0.0.0 (0x030600000000)
Oct 24 10:18:11.962: Vi5 IPCP:    PrimaryDNS 0.0.0.0 (0x810600000000)
Oct 24 10:18:11.962: Vi5 IPCP:    PrimaryWINS 0.0.0.0 (0x820600000000)
Oct 24 10:18:11.966: Vi5 IPCP:    SecondaryDNS 0.0.0.0 (0x830600000000)
Oct 24 10:18:11.966: Vi5 IPCP:    SecondaryWINS 0.0.0.0 (0x840600000000)
Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: Done. Her address 0.0.0.0, we want 0.0.0.0
Oct 24 10:18:11.966: Vi5 IPCP: Pool returned 192.168.207.203
Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for primary dns
Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for primary wins
Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for seconday dns
Oct 24 10:18:11.966: Vi5 IPCP AUTHOR: no author-info for seconday wins
Oct 24 10:18:11.966: Vi5 IPCP: O CONFREJ [REQsent] id 4 len 22
Oct 24 10:18:11.966: Vi5 IPCP:    PrimaryWINS 0.0.0.0 (0x820600000000)
Oct 24 10:18:11.966: Vi5 IPCP:    SecondaryDNS 0.0.0.0 (0x830600000000)
Oct 24 10:18:11.966: Vi5 IPCP:    SecondaryWINS 0.0.0.0 (0x840600000000)
Oct 24 10:18:11.966: Vi5 IPCP: Event[Receive ConfReq-] State[REQsent to REQsent]
Oct 24 10:18:11.966: Vi5 IPCP: I CONFACK [REQsent] id 1 len 10
Oct 24 10:18:11.966: Vi5 IPCP:    Address 192.168.207.1 (0x0306C0A8CF01)
Oct 24 10:18:11.966: Vi5 IPCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
Oct 24 10:18:11.966: Vi5 CCP: I CONFNAK [REQsent] id 1 len 10
Oct 24 10:18:11.966: Vi5 CCP:    MS-PPC supported bits 0x01000040 (0x120601000040)
Oct 24 10:18:11.966: Vi5 CCP: O CONFREQ [REQsent] id 2 len 10
Oct 24 10:18:11.966: Vi5 CCP:    MS-PPC supported bits 0x01000040 (0x120601000040)
Oct 24 10:18:11.966: Vi5 CCP: Event[Receive ConfNak/Rej] State[REQsent to REQsent]
Oct 24 10:18:12.018: Vi5 CCP: I TERMREQ [REQsent] id 5 len 16
Oct 24 10:18:12.018: Vi5 CCP: (0x374A4A26003CCD74000002DC)
Oct 24 10:18:12.018: Vi5 CCP: O TERMACK [REQsent] id 5 len 4
Oct 24 10:18:12.018: Vi5 CCP: Event[Receive TermReq] State[REQsent to REQsent]
Oct 24 10:18:12.018: Vi5 PPP DISC: Required MPPE not negotiated
Oct 24 10:18:12.018: Vi5 PPP: Sending Acct Event[Down] id[A6]
Oct 24 10:18:12.018: Vi5 PPP CCP: Enter passive mode, state[Stopped]
Oct 24 10:18:12.018: Vi5 IPCP: Event[DOWN] State[ACKrcvd to Starting]
Oct 24 10:18:12.018: Vi5 IPCP: Event[CLOSE] State[Starting to Initial]
Oct 24 10:18:12.018: Vi5 CCP: Event[DOWN] State[Stopped to Starting]
Oct 24 10:18:12.018: Vi5 CCP: Event[CLOSE] State[Starting to Initial]
Oct 24 10:18:12.018: Vi5 LCP: O TERMREQ [Open] id 2 len 4
Oct 24 10:18:12.018: Vi5 LCP: Event[CLOSE] State[Open to Closing]
Oct 24 10:18:12.018: Vi5 PPP: Phase is TERMINATING
Oct 24 10:18:12.018: Vi5 LCP: Event[CLOSE] State[Closing to Closing]
Oct 24 10:18:12.066: Vi5 LCP: I TERMACK [Closing] id 2 len 4
Oct 24 10:18:12.066: Vi5 LCP: Event[Receive TermAck] State[Closing to Closed]
Oct 24 10:18:12.066: Vi5 LCP: Event[DOWN] State[Closed to Initial]
Oct 24 10:18:12.066: Vi5 PPP: Clearing AAA Unique Id = A6
Oct 24 10:18:12.066: Vi5 PPP: Phase is DOWN
Oct 24 10:18:12.070: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to down
Oct 24 10:18:12.070: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to down

I mark as bold debug row that repeating with previous case: Vi5 PPP DISC: Required MPPE not negotiated. Google keep silence about it. Do You have any ideas?

Eugene Khabarov · ‎10-24-2011

Try to upgrade to

Version 15.1(4)M2 first and than try once again. I'm not sure, but seems to me there is serious bugs with MPPE in previvius versions. At least in 15.0(1)M.

---

HTH. Please rate this post if it was helpful. If this solves your problem, please mark this post as "Correct Answer."

wschenkeveld · ‎11-17-2011

We had the same problem using MS-CHAP-V2 and 3945 router using IOS 15.2. When adding the same user/password combination locally it worked fine but that was no solution offcourse. We solved this issue by adding the following line in the config :

aaa authorization network default if-authenticated

This is because Windows 2000 clients require the use of a aaa authorization statement in the router config. Maybe this was default (and therefore not shown) in previous IOS releases.

Succes !!!

Wil Schenkeveld

sergey.sheremet · ‎11-18-2011

Hi Wil,

Thank You! Its work!

--

With best regards,

Sergey