INFO   13.03.2009 18:29:19   RESPONSE:
Type=AUTHENTICATION_ACCEPT
Process time:0
Attributes:
        Acct-Interim-Interval=60
        Service-Type=2
        Framed-Protocol=1
        Framed-IP-Address=89.28.255.28
        Framed-IP-Netmask=255.255.255.0
        Framed-MTU=1492
        Port-Limit=1
        cisco-avpair=lcp:interface-config=ip vrf forwarding
        cisco-avpair=multilink:max-links=6
        cisco-avpair=multilink:min-links=1

004598: Mar 13 17:59:37.098: PPPoE 0: I PADI  R:001f.c66e.578d L:ffff.ffff.ffff 377 Gi0/1.377
         FF FF FF FF FF FF 00 1F C6 6E 57 8D 81 00 01 79
         88 63 11 09 00 00 00 14 01 01 00 04 6E 61 73 31 ...
004599: Mar 13 17:59:37.098:  Service tag: nas1
004600: Mar 13 17:59:37.098: PPPoE 0: O PADO, R:0019.2f8e.f311 L:001f.c66e.578d 377 Gi0/1.377
004601: Mar 13 17:59:37.098:  Service tag: nas1
         00 1F C6 6E 57 8D 00 19 2F 8E F3 11 81 00 01 79
         88 63 11 07 00 00 00 30 01 01 00 04 6E 61 73 31 ...
004602: Mar 13 17:59:37.098: PPPoE 0: I PADR  R:001f.c66e.578d L:0019.2f8e.f311 377 Gi0/1.377
         00 19 2F 8E F3 11 00 1F C6 6E 57 8D 81 00 01 79
         88 63 11 19 00 00 00 28 01 01 00 04 6E 61 73 31 ...
004603: Mar 13 17:59:37.098:  Service tag: nas1
004604: Mar 13 17:59:37.098: PPPoE : encap string prepared
004605: Mar 13 17:59:37.098: [130]PPPoE 130: Access IE handle allocated
004606: Mar 13 17:59:37.098: [130]PPPoE 130: pppoe SSS switch updated
004607: Mar 13 17:59:37.098: [130]PPPoE 130: AAA get retrieved attrs
004608: Mar 13 17:59:37.098: [130]PPPoE 130: AAA get nas port details
004609: Mar 13 17:59:37.098: AAA/BIND(00000534): Bind i/f Virtual-Template1
004610: Mar 13 17:59:37.098: [130]PPPoE 130: AAA get dynamic attrs
004611: Mar 13 17:59:37.098: [130]PPPoE 130: AAA get dynamic attrs
004612: Mar 13 17:59:37.098: [130]PPPoE 130: AAA unique ID allocated
004613: Mar 13 17:59:37.098: [130]PPPoE 130: No AAA accounting method list
004614: Mar 13 17:59:37.098: [130]PPPoE 130: Service request sent to SSS
004615: Mar 13 17:59:37.098: [130]PPPoE 130: Created, Service: None R:0019.2f8e.f311 L:001f.c66e.578d 377 Gi0/1.377
004616: Mar 13 17:59:37.102: [130]PPPoE 130: State NAS_PORT_POLICY_INQUIRY    Event SSS_LOCAL
004617: Mar 13 17:59:37.102: [130]PPPoE 130: O PADS  R:001f.c66e.578d L:0019.2f8e.f311 Gi0/1.377
         00 1F C6 6E 57 8D 00 19 2F 8E F3 11 81 00 01 79
         88 63 11 65 00 82 00 28 01 01 00 04 6E 61 73 31 ...
004618: Mar 13 17:59:37.102: ppp130 PPP: Send Message[Dynamic Bind Response]
004619: Mar 13 17:59:37.102: ppp130 PPP: Using default call direction
004620: Mar 13 17:59:37.102: ppp130 PPP: Treating connection as a dedicated line
004621: Mar 13 17:59:37.102: ppp130 PPP: Session handle[920004BE] Session id[130]
004622: Mar 13 17:59:37.102: ppp130 PPP: Phase is ESTABLISHING, Active Open
004623: Mar 13 17:59:37.102: ppp130 PPP: Authorization required
004624: Mar 13 17:59:37.102: ppp130 AAA/AUTHOR/LCP: Authorization succeeds trivially
004625: Mar 13 17:59:37.102: ppp130 LCP: O CONFREQ [Closed] id 1 len 19
004626: Mar 13 17:59:37.102: ppp130 LCP:    MRU 1492 (0x010405D4)
004627: Mar 13 17:59:37.102: ppp130 LCP:    AuthProto CHAP (0x0305C22305)
004628: Mar 13 17:59:37.102: ppp130 LCP:    MagicNumber 0x234177C9 (0x0506234177C9)
004629: Mar 13 17:59:37.102: [130]PPPoE 130: State PPP_START    Event DYN_BIND
004630: Mar 13 17:59:37.102: [130]PPPoE 130: data path set to PPP
004631: Mar 13 17:59:37.170: ppp130 LCP: I CONFREQ [REQsent] id 0 len 17
004632: Mar 13 17:59:37.170: ppp130 LCP:    MRU 1466 (0x010405BA)
004633: Mar 13 17:59:37.170: ppp130 LCP:    MagicNumber 0x0B924CEB (0x05060B924CEB)
004634: Mar 13 17:59:37.170: ppp130 LCP:    Callback 6  (0x0D0306)
004635: Mar 13 17:59:37.170: ppp130 LCP: O CONFREJ [REQsent] id 0 len 7
004636: Mar 13 17:59:37.170: ppp130 LCP:    Callback 6  (0x0D0306)
004637: Mar 13 17:59:37.174: ppp130 LCP: I CONFACK [REQsent] id 1 len 19
004638: Mar 13 17:59:37.174: ppp130 LCP:    MRU 1492 (0x010405D4)
004639: Mar 13 17:59:37.174: ppp130 LCP:    AuthProto CHAP (0x0305C22305)
004640: Mar 13 17:59:37.174: ppp130 LCP:    MagicNumber 0x234177C9 (0x0506234177C9)
004641: Mar 13 17:59:37.174: ppp130 LCP: I CONFREQ [ACKrcvd] id 1 len 14
004642: Mar 13 17:59:37.174: ppp130 LCP:    MRU 1466 (0x010405BA)
004643: Mar 13 17:59:37.174: ppp130 LCP:    MagicNumber 0x0B924CEB (0x05060B924CEB)
004644: Mar 13 17:59:37.174: ppp130 LCP: O CONFNAK [ACKrcvd] id 1 len 8
004645: Mar 13 17:59:37.174: ppp130 LCP:    MRU 1492 (0x010405D4)
004646: Mar 13 17:59:37.190: ppp130 LCP: I CONFREQ [ACKrcvd] id 2 len 14
004647: Mar 13 17:59:37.190: ppp130 LCP:    MRU 1466 (0x010405BA)
004648: Mar 13 17:59:37.190: ppp130 LCP:    MagicNumber 0x0B924CEB (0x05060B924CEB)
004649: Mar 13 17:59:37.190: ppp130 LCP: O CONFNAK [ACKrcvd] id 2 len 8
004650: Mar 13 17:59:37.190: ppp130 LCP:    MRU 1492 (0x010405D4)
004651: Mar 13 17:59:37.210: ppp130 LCP: I CONFREQ [ACKrcvd] id 3 len 14
004652: Mar 13 17:59:37.210: ppp130 LCP:    MRU 1492 (0x010405D4)
004653: Mar 13 17:59:37.210: ppp130 LCP:    MagicNumber 0x0B924CEB (0x05060B924CEB)
004654: Mar 13 17:59:37.210: ppp130 LCP: O CONFACK [ACKrcvd] id 3 len 14
004655: Mar 13 17:59:37.210: ppp130 LCP:    MRU 1492 (0x010405D4)
004656: Mar 13 17:59:37.210: ppp130 LCP:    MagicNumber 0x0B924CEB (0x05060B924CEB)
004657: Mar 13 17:59:37.210: ppp130 LCP: State is Open
004658: Mar 13 17:59:37.210: ppp130 PPP: Phase is AUTHENTICATING, by this end
004659: Mar 13 17:59:37.210: ppp130 CHAP: O CHALLENGE id 1 len 39 from "c2851-sanfrancisco"
004660: Mar 13 17:59:37.226: ppp130 LCP: I IDENTIFY [Open] id 4 len 18 magic 0x0B924CEB MSRASV5.10
004661: Mar 13 17:59:37.226: ppp130 LCP: I IDENTIFY [Open] id 5 len 19 magic 0x0B924CEB MSRAS-0-LAP
004662: Mar 13 17:59:37.226: ppp130 CHAP: I RESPONSE id 1 len 27 from "pptest"
004663: Mar 13 17:59:37.226: ppp130 PPP: Phase is FORWARDING, Attempting Forward
004664: Mar 13 17:59:37.226: ppp130 PPP: Phase is AUTHENTICATING, Unauthenticated User
004665: Mar 13 17:59:37.230: ppp130 PPP: Sent CHAP LOGIN Request
004666: Mar 13 17:59:37.234: ppp130 PPP: Received LOGIN Response PASS
004667: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: acct-interval
004668: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: service-type
004669: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: Framed-Protocol
004670: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: addr
004671: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: route: Peruser
004672: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: netmask
004673: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: Framed-MTU
004674: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: Port-Limit
004675: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: interface-config: Peruser I/F
004676: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: max-links
004677: Mar 13 17:59:37.234: ppp130 PPP/AAA: Check Attr: min-links
004678: Mar 13 17:59:37.234: ppp130 PPP: Phase is FORWARDING, Attempting Forward
004679: Mar 13 17:59:37.234: ppp130 PPP: Send Message[Connect Local]
004680: Mar 13 17:59:37.234: [130]PPPoE 130: State LCP_NEGOTIATION    Event PPP_LOCAL
004681: Mar 13 17:59:37.234: PPPoE 130: Can not use sub-interface
004682: Mar 13 17:59:37.246: Vi82 PPP: Phase is DOWN, Setup
004683: Mar 13 17:59:37.246: [130]PPPoE 130: State VACCESS_REQUESTED    Event VA_RESP
004684: Mar 13 17:59:37.246: [130]PPPoE 130: Vi82 interface obtained
004685: Mar 13 17:59:37.246: ppp130 PPP: Bind to [Virtual-Access82]
004686: Mar 13 17:59:37.246: AAA/BIND(00000534): Bind i/f Virtual-Access82
004687: Mar 13 17:59:37.246: Vi82 PPP: Send Message[Static Bind Response]
004688: Mar 13 17:59:37.246: [130]PPPoE 130: State PTA_BINDING    Event STAT_BIND
004689: Mar 13 17:59:37.246: [130]PPPoE 130: data path set to Virtual Acess
004690: Mar 13 17:59:37.246: [130]PPPoE 130: Connected PTA
004691: 1d22h: %LINK-3-UPDOWN: Interface Virtual-Access82, changed state to up
004692: Mar 13 17:59:37.250: Vi82 PPP: Phase is AUTHENTICATING, Authenticated User
004693: Mar 13 17:59:37.250: Vi82 AAA/AUTHOR/LCP: Process Author
004694: Mar 13 17:59:37.250: Vi82 AAA/AUTHOR/LCP: Process Attr: interface-config
004695: Mar 13 17:59:37.250: AAA/AUTHOR: Processing PerUser AV interface-config
004696: Mar 13 17:59:37.250: Vi82 AAA/AUTHOR/LCP: Process Attr: acct-interval
004697: Mar 13 17:59:37.250: Vi82 AAA/AUTHOR/LCP: Process Attr: service-type
004698: Mar 13 17:59:37.250: Vi82 AAA/AUTHOR/LCP: Process Attr: interface-config
004699: Mar 13 17:59:37.250: Vi82 AAA/AUTHOR/LCP: IF_config:
ip vrf forwarding

004700: Mar 13 17:59:37.250: Vi82 CHAP: O SUCCESS id 1 len 4
004701: Mar 13 17:59:37.250: [130]PPPoE 130: AAA get dynamic attrs
004702: Mar 13 17:59:37.250: [130]PPPoE 130: AAA get dynamic attrs
004703: Mar 13 17:59:37.250: Vi82 PPP: Phase is FORWARDING
004704: Mar 13 17:59:37.258: Vi82 PPP: Sending Acct Event[Down] id[534]
004705: Mar 13 17:59:37.258: [130]PPPoE 130: AAA get dynamic attrs
004706: Mar 13 17:59:37.258: [130]PPPoE 130: AAA get dynamic attrs
004707: Mar 13 17:59:37.258: Vi82 PPP: Phase is TERMINATING
004708: Mar 13 17:59:37.258: Vi82 LCP: O TERMREQ [Open] id 2 len 4
004709: Mar 13 17:59:37.262: Vi82 PPP: LCP not open, discarding IPCP packet
004710: Mar 13 17:59:37.274: Vi82 LCP: I TERMACK [TERMsent] id 2 len 4
004711: Mar 13 17:59:37.274: Vi82 LCP: State is Closed
004712: Mar 13 17:59:37.274: Vi82 PPP: Phase is DOWN
004713: Mar 13 17:59:37.274: Vi82 PPP: Send Message[Disconnect]
004714: Mar 13 17:59:37.274: [130]PPPoE 130: State LOCALLY_TERMINATED    Event PPP_DISCNCT
004715: Mar 13 17:59:37.274: [130]PPPoE 130: O PADT  R:001f.c66e.578d L:0019.2f8e.f311 Gi0/1.377
         00 1F C6 6E 57 8D 00 19 2F 8E F3 11 81 00 01 79
         88 63 11 A7 00 82 00 00 00 00 00 00 00 00 00 00 ...
004716: Mar 13 17:59:37.274: [130]PPPoE 130: Destroying  R:001f.c66e.578d L:0019.2f8e.f311 377 Gi0/1.377
004717: Mar 13 17:59:37.274: PPPoE: Returning Vaccess Virtual-Access82
004718: Mar 13 17:59:37.274: [130]PPPoE 130: AAA account stopped
004719: Mar 13 17:59:37.274: PPPoE 130: I PADT  R:001f.c66e.578d L:0019.2f8e.f311 377 Gi0/1.377
         00 19 2F 8E F3 11 00 1F C6 6E 57 8D 81 00 01 79
         88 63 11 A7 00 82 00 00 00 00 00 00 00 00 00 00 ...
c2851-sanfrancisco#
004720: 1d22h: %LINK-3-UPDOWN: Interface Virtual-Access82, changed state to down