<15>2890: *Apr 15 14:21:52.593: AAA/BIND(0000008F): Bind i/f <15>2891: *Apr 15 14:21:52.597: AAA/BIND(0000008F): Bind i/f Virtual-Template1 <15>2892: *Apr 15 14:21:52.597: ppp84 PPP: Send Message[Dynamic Bind Response] <15>2893: *Apr 15 14:21:52.597: ppp84 PPP: Using vpn set call direction <15>2894: *Apr 15 14:21:52.597: ppp84 PPP: Treating connection as a callin <15>2895: *Apr 15 14:21:52.597: ppp84 PPP: Session handle[85000093] Session id[84] <15>2896: *Apr 15 14:21:52.597: ppp84 PPP: Phase is ESTABLISHING, Passive Open <15>2897: *Apr 15 14:21:52.597: ppp84 LCP: State is Listen <15>2898: *Apr 15 14:21:52.609: ppp84 LCP: I CONFREQ [Listen] id 0 len 21 <15>2899: *Apr 15 14:21:52.609: ppp84 LCP: MRU 1400 (0x01040578) <15>2900: *Apr 15 14:21:52.613: ppp84 LCP: MagicNumber 0x19B464B4 (0x050619B464B4) <15>2901: *Apr 15 14:21:52.613: ppp84 LCP: PFC (0x0702) <15>2902: *Apr 15 14:21:52.613: ppp84 LCP: ACFC (0x0802) <15>2903: *Apr 15 14:21:52.613: ppp84 LCP: Callback 6 (0x0D0306) <15>2904: *Apr 15 14:21:52.613: ppp84 PPP: Authorization required <15>2905: *Apr 15 14:21:52.613: ppp84 LCP: O CONFREQ [Listen] id 1 len 15 <15>2906: *Apr 15 14:21:52.613: ppp84 LCP: AuthProto MS-CHAP (0x0305C22380) <15>2907: *Apr 15 14:21:52.613: ppp84 LCP: MagicNumber 0x878796F3 (0x0506878796F3) <15>2908: *Apr 15 14:21:52.613: ppp84 LCP: O CONFREJ [Listen] id 0 len 7 <15>2909: *Apr 15 14:21:52.613: ppp84 LCP: Callback 6 (0x0D0306) <15>2910: *Apr 15 14:21:52.613: ppp84 LCP: I CONFACK [REQsent] id 1 len 15 <15>2911: *Apr 15 14:21:52.613: ppp84 LCP: AuthProto MS-CHAP (0x0305C22380) <15>2912: *Apr 15 14:21:52.613: ppp84 LCP: MagicNumber 0x878796F3 (0x0506878796F3) <15>2913: *Apr 15 14:21:52.613: ppp84 LCP: I CONFREQ [ACKrcvd] id 1 len 18 <15>2914: *Apr 15 14:21:52.613: ppp84 LCP: MRU 1400 (0x01040578) <15>2915: *Apr 15 14:21:52.613: ppp84 LCP: MagicNumber 0x19B464B4 (0x050619B464B4) <15>2916: *Apr 15 14:21:52.617: ppp84 LCP: PFC (0x0702) <15>2917: *Apr 15 14:21:52.617: ppp84 LCP: ACFC (0x0802) <15>2918: *Apr 15 14:21:52.617: ppp84 LCP: O CONFNAK [ACKrcvd] id 1 len 8 <15>2919: *Apr 15 14:21:52.617: ppp84 LCP: MRU 1500 (0x010405DC) <15>2920: *Apr 15 14:21:52.617: ppp84 LCP: I CONFREQ [ACKrcvd] id 2 len 18 <15>2921: *Apr 15 14:21:52.617: ppp84 LCP: MRU 1400 (0x01040578) <15>2922: *Apr 15 14:21:52.617: ppp84 LCP: MagicNumber 0x19B464B4 (0x050619B464B4) <15>2923: *Apr 15 14:21:52.617: ppp84 LCP: PFC (0x0702) <15>2924: *Apr 15 14:21:52.617: ppp84 LCP: ACFC (0x0802) <15>2925: *Apr 15 14:21:52.617: ppp84 LCP: O CONFNAK [ACKrcvd] id 2 len 8 <15>2926: *Apr 15 14:21:52.617: ppp84 LCP: MRU 1500 (0x010405DC) <15>2927: *Apr 15 14:21:52.617: ppp84 LCP: I CONFREQ [ACKrcvd] id 3 len 18 <15>2928: *Apr 15 14:21:52.617: ppp84 LCP: MRU 1500 (0x010405DC) <15>2929: *Apr 15 14:21:52.621: ppp84 LCP: MagicNumber 0x19B464B4 (0x050619B464B4) <15>2930: *Apr 15 14:21:52.621: ppp84 LCP: PFC (0x0702) <15>2931: *Apr 15 14:21:52.621: ppp84 LCP: ACFC (0x0802) <15>2932: *Apr 15 14:21:52.621: ppp84 LCP: O CONFACK [ACKrcvd] id 3 len 18 <15>2933: *Apr 15 14:21:52.621: ppp84 LCP: MRU 1500 (0x010405DC) <15>2934: *Apr 15 14:21:52.621: ppp84 LCP: MagicNumber 0x19B464B4 (0x050619B464B4) <15>2935: *Apr 15 14:21:52.621: ppp84 LCP: PFC (0x0702) <15>2936: *Apr 15 14:21:52.621: ppp84 LCP: ACFC (0x0802) <15>2937: *Apr 15 14:21:52.621: ppp84 LCP: State is Open <15>2938: *Apr 15 14:21:52.621: ppp84 PPP: Phase is AUTHENTICATING, by this end <15>2939: *Apr 15 14:21:52.625: ppp84 MS-CHAP: O CHALLENGE id 1 len 27 from "HO-router-2811" <15>2940: *Apr 15 14:21:52.625: ppp84 LCP: I IDENTIFY [Open] id 4 len 18 magic 0x19B464B4 MSRASV5.10 <15>2941: *Apr 15 14:21:52.625: ppp84 LCP: I IDENTIFY [Open] id 5 len 24 magic 0x19B464B4 MSRAS-1-PCRU0433 <15>2942: *Apr 15 14:21:52.625: ppp84 MS-CHAP: I RESPONSE id 1 len 66 from "user.name" <15>2943: *Apr 15 14:21:52.625: ppp84 PPP: Phase is FORWARDING, Attempting Forward <15>2944: *Apr 15 14:21:52.625: ppp84 PPP: Phase is AUTHENTICATING, Unauthenticated User <15>2945: *Apr 15 14:21:52.625: AAA/AUTHEN/PPP (0000008F): Pick method list 'default' <15>2946: *Apr 15 14:21:52.629: ppp84 PPP: Sent MSCHAP LOGIN Request <15>2947: *Apr 15 14:21:52.629: RADIUS/ENCODE(0000008F):Orig. component type = VPDN <15>2948: *Apr 15 14:21:52.629: RADIUS: AAA Unsupported Attr: interface [157] 14 <15>2949: *Apr 15 14:21:52.629: RADIUS: 55 6E 69 71 2D 53 65 73 73 2D 49 44 [Uniq-Sess-ID] <15>2950: *Apr 15 14:21:52.629: RADIUS(0000008F): Config NAS IP: 0.0.0.0 <15>2951: *Apr 15 14:21:52.629: RADIUS/ENCODE(0000008F): acct_session_id: 143 <15>2952: *Apr 15 14:21:52.629: RADIUS(0000008F): sending <15>2953: *Apr 15 14:21:52.629: RADIUS/ENCODE: Best Local IP-Address 10.252.252.250 for Radius-Server 192.168.33.81 <15>2954: *Apr 15 14:21:52.629: RADIUS(0000008F): Send Access-Request to 192.168.33.81:1645 id 1645/70, len 154 <15>2955: *Apr 15 14:21:52.629: RADIUS: authenticator 31 96 5E 35 1E 09 8F 76 - 00 00 00 00 00 00 00 00 <15>2956: *Apr 15 14:21:52.629: RADIUS: Framed-Protocol [7] 6 PPP [1] <15>2957: *Apr 15 14:21:52.629: RADIUS: User-Name [1] 14 "user.name" <15>2958: *Apr 15 14:21:52.629: RADIUS: Vendor, Microsoft [26] 16 <15>2959: *Apr 15 14:21:52.629: RADIUS: MSCHAP_Challenge [11] 10 <15>2960: *Apr 15 14:21:52.629: RADIUS: 31 96 5E 35 1E 09 8F 76 [1?^5???v] <15>2961: *Apr 15 14:21:52.629: RADIUS: Vendor, Microsoft [26] 58 <15>2962: *Apr 15 14:21:52.629: RADIUS: MS-CHAP-Response [1] 52 * <15>2963: *Apr 15 14:21:52.629: RADIUS: NAS-Port-Type [61] 6 Virtual [5] <15>2964: *Apr 15 14:21:52.629: RADIUS: NAS-Port [5] 6 84 <15>2965: *Apr 15 14:21:52.629: RADIUS: NAS-Port-Id [87] 16 "Uniq-Sess-ID84" <15>2966: *Apr 15 14:21:52.633: RADIUS: Service-Type [6] 6 Framed [2] <15>2967: *Apr 15 14:21:52.633: RADIUS: NAS-IP-Address [4] 6 10.252.252.250 <15>2968: *Apr 15 14:21:52.941: RADIUS: Received from id 1645/70 192.168.33.81:1645, Access-Accept, len 192 <15>2969: *Apr 15 14:21:52.941: RADIUS: authenticator 71 B5 1D E0 3F 87 8E EA - BA 62 BA 14 4A EC CC 47 <15>2970: *Apr 15 14:21:52.941: RADIUS: Vendor, Microsoft [26] 40 <15>2971: *Apr 15 14:21:52.941: RADIUS: MS-CHAP-MPPE-Keys [12] 34 * <15>2972: *Apr 15 14:21:52.941: RADIUS: Vendor, Microsoft [26] 12 <15>2973: *Apr 15 14:21:52.941: RADIUS: MS-MPPE-Enc-Policy [7] 6 <15>2974: *Apr 15 14:21:52.941: RADIUS: 00 00 00 02 [????] <15>2975: *Apr 15 14:21:52.941: RADIUS: Vendor, Microsoft [26] 12 <15>2976: *Apr 15 14:21:52.941: RADIUS: MS-MPPE-Enc-Type [8] 6 <15>2977: *Apr 15 14:21:52.945: RADIUS: 00 00 00 02 [????] <15>2978: *Apr 15 14:21:52.945: RADIUS: Service-Type [6] 6 Framed [2] <15>2979: *Apr 15 14:21:52.945: RADIUS: Framed-Protocol [7] 6 PPP [1] <15>2980: *Apr 15 14:21:52.945: RADIUS: Vendor, Cisco [26] 65 <15>2981: *Apr 15 14:21:52.945: RADIUS: Cisco AVpair [1] 59 "ACS:CiscoSecure-Defined-ACL=#ACSACL#-IP-Testlist-47fb76aa" <15>2982: *Apr 15 14:21:52.945: RADIUS: Framed-IP-Address [8] 6 10.252.22.5 <15>2983: *Apr 15 14:21:52.945: RADIUS: Class [25] 25 <15>2984: *Apr 15 14:21:52.945: RADIUS: 43 41 43 53 3A 30 2F 34 33 62 36 32 2F 61 66 63 [CACS:0/43b62/afc] <15>2985: *Apr 15 14:21:52.945: RADIUS: 66 63 66 61 2F 38 34 [fcfa/84] <15>2986: *Apr 15 14:21:52.945: RADIUS(0000008F): Received from id 1645/70 <15>2987: *Apr 15 14:21:52.945: AAA/ATTR: unrecognized attribute prefix: "ACS" (WARNING) <15>2988: *Apr 15 14:21:52.945: ppp84 PPP: Received LOGIN Response PASS <15>2989: *Apr 15 14:21:52.949: ppp84 PPP/AAA: Check Attr: MS-CHAP-MPPE-Keys <15>2990: *Apr 15 14:21:52.949: ppp84 PPP/AAA: Check Attr: service-type <15>2991: *Apr 15 14:21:52.949: ppp84 PPP/AAA: Check Attr: Framed-Protocol <15>2992: *Apr 15 14:21:52.949: ppp84 PPP/AAA: Check Attr: CiscoSecure-Defined-ACL <15>2993: *Apr 15 14:21:52.949: ppp84 PPP/AAA: Check Attr: addr <15>2994: *Apr 15 14:21:52.949: ppp84 PPP: Phase is FORWARDING, Attempting Forward <15>2995: *Apr 15 14:21:52.949: ppp84 PPP: Send Message[Connect Local] <15>2996: *Apr 15 14:21:52.953: Vi4 PPP: Phase is DOWN, Setup <15>2997: *Apr 15 14:21:52.953: ppp84 PPP: Bind to [Virtual-Access4] <15>2998: *Apr 15 14:21:52.953: AAA/BIND(0000008F): Bind i/f Virtual-Access4 <15>2999: *Apr 15 14:21:52.953: Vi4 PPP: Send Message[Static Bind Response] <11>3000: *Apr 15 14:21:52.957: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state to up <15>3001: *Apr 15 14:21:52.957: Vi4 PPP: Phase is AUTHENTICATING, Authenticated User <15>3002: *Apr 15 14:21:52.957: Vi4 AAA/AUTHOR/LCP: Process Author <15>3003: *Apr 15 14:21:52.957: Vi4 AAA/AUTHOR/LCP: Process Attr: service-type <15>3004: *Apr 15 14:21:52.957: Vi4 MS-CHAP: O SUCCESS id 1 len 4 <15>3005: *Apr 15 14:21:52.961: Vi4 PPP: Phase is UP <15>3006: *Apr 15 14:21:52.961: Vi4 AAA/AUTHOR/IPCP: FSM authorization not needed <15>3007: *Apr 15 14:21:52.961: Vi4 AAA/AUTHOR/FSM: We can start IPCP <15>3008: *Apr 15 14:21:52.961: Vi4 IPCP: O CONFREQ [Closed] id 1 len 10 <15>3009: *Apr 15 14:21:52.961: Vi4 IPCP: Address external.ip (0x030652CCB573) <15>3010: *Apr 15 14:21:52.961: Vi4 AAA/AUTHOR/CCP: FSM authorization not needed <15>3011: *Apr 15 14:21:52.961: Vi4 AAA/AUTHOR/FSM: We can start CCP <15>3012: *Apr 15 14:21:52.961: Vi4 CCP: O CONFREQ [Closed] id 1 len 10 <15>3013: *Apr 15 14:21:52.961: Vi4 CCP: MS-PPC supported bits 0x01000060 (0x120601000060) <15>3014: *Apr 15 14:21:52.961: Vi4 PPP: Process pending ncp packets <15>3015: *Apr 15 14:21:52.981: Vi4 CCP: I CONFREQ [REQsent] id 6 len 10 <15>3016: *Apr 15 14:21:52.981: Vi4 CCP: MS-PPC supported bits 0x010000F1 (0x1206010000F1) <15>3017: *Apr 15 14:21:52.981: Vi4 CCP: O CONFNAK [REQsent] id 6 len 10 <15>3018: *Apr 15 14:21:52.981: Vi4 CCP: MS-PPC supported bits 0x01000060 (0x120601000060) <15>3019: *Apr 15 14:21:52.981: Vi4 CCP: I CONFNAK [REQsent] id 1 len 10 <15>3020: *Apr 15 14:21:52.981: Vi4 CCP: MS-PPC supported bits 0x01000040 (0x120601000040) <15>3021: *Apr 15 14:21:52.981: Vi4 CCP: O CONFREQ [REQsent] id 2 len 10 <15>3022: *Apr 15 14:21:52.981: Vi4 CCP: MS-PPC supported bits 0x01000040 (0x120601000040) <15>3023: *Apr 15 14:21:52.981: Vi4 IPCP: I CONFREQ [REQsent] id 7 len 34 <15>3024: *Apr 15 14:21:52.981: Vi4 IPCP: Address 0.0.0.0 (0x030600000000) <15>3025: *Apr 15 14:21:52.981: Vi4 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000) <15>3026: *Apr 15 14:21:52.981: Vi4 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000) <15>3027: *Apr 15 14:21:52.981: Vi4 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000) <15>3028: *Apr 15 14:21:52.981: Vi4 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000) <15>3029: *Apr 15 14:21:52.981: Vi4 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0 <15>3030: *Apr 15 14:21:52.981: Vi4 AAA/AUTHOR/IPCP: Processing AV addr <15>3031: *Apr 15 14:21:52.981: Vi4 AAA/AUTHOR/IPCP: Authorization succeeded <15>3032: *Apr 15 14:21:52.981: Vi4 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.252.22.5 <15>3033: *Apr 15 14:21:52.981: Vi4 AAA/AUTHOR/IPCP: no author-info for primary dns <15>3034: *Apr 15 14:21:52.981: Vi4 AAA/AUTHOR/IPCP: no author-info for primary wins <15>3053: *Apr 15 14:21:53.001: Vi4 AAA/AUTHOR/IPCP: no author-info for primary dns <15>3075: *Apr 15 14:21:53.013: Vi4 IPCP: Install route to 10.252.22.5 <13>3076: *Apr 15 14:21:53.957: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access4, changed state to up <15>3077: *Apr 15 14:22:01.133: Vi4 LCP: I TERMREQ [Open] id 11 len 16 (0x19B464B4003CCD7400000000) <15>3078: *Apr 15 14:22:01.133: Vi4 LCP: O TERMACK [Open] id 11 len 4 <15>3079: *Apr 15 14:22:01.133: Vi4 PPP: Sending Acct Event[Down] id[8F] <15>3080: *Apr 15 14:22:01.133: Vi4 PPP: Phase is TERMINATING <15>3081: *Apr 15 14:22:03.117: Vi4 LCP: Timeout: State TERMsent <15>3082: *Apr 15 14:22:03.117: Vi4 LCP: State is Closed <15>3083: *Apr 15 14:22:03.117: Vi4 PPP: Phase is DOWN <15>3084: *Apr 15 14:22:03.117: Vi4 CCP: State is Closed <15>3085: *Apr 15 14:22:03.117: Vi4 IPCP: State is Closed <15>3086: *Apr 15 14:22:03.121: Vi4 PPP: Send Message[Disconnect] <15>3087: *Apr 15 14:22:03.121: Vi4 IPCP: Remove route to 10.252.22.5 <11>3088: *Apr 15 14:22:03.129: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state to down <13>3089: *Apr 15 14:22:04.117: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access4, changed state to down