pppoe issue on cisco 1921 ios 15.2

[zeuscyril]

hi all,

i confiured the cisco 1921 and my      pppoe is connecting and disconnecting.and i am using cisco ios 15.2

here is the log

Feb  6 06:59:04.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to down
Feb  6 06:59:05.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to down
Feb  6 06:59:26.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to up
Feb  6 06:59:27.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to up
Feb  6 06:59:37.591: Di0 Deleted neighbor route from AVL tree: topoid 0, address
213.42.5.11
Feb  6 06:59:37.591: Di0 IPCP: Remove route to 213.42.5.11
Feb  6 06:59:39.595: PPPoE: Failed to add PPPoE switching subblock
Feb  6 06:59:39.595: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di0
Feb  6 06:59:39.599: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Acc
ess2, changed state to down
Feb  6 06:59:39.599: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to
down
Feb  6 06:59:39.599: PPPoE: Unexpected Event!. PPPoE switching Subblockdestroy c
alled
Feb  6 07:00:02.111: %DIALER-6-BIND: Interface Vi2 bound to profile Di0
Feb  6 07:00:02.111: Vi2 Debug: Condition 1, interface Di0 triggered, count 1
Feb  6 07:00:02.119: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to
up
Feb  6 07:00:02.119: Vi2 PPP: Sending cstate UP notification
Feb  6 07:00:02.119: Vi2 PPP: Processing CstateUp message
Feb  6 07:00:02.119: Vi2 PPP: Using dialer call direction
Feb  6 07:00:02.119: Vi2 PPP: Treating connection as a callout
Feb  6 07:00:02.119: Vi2 PPP: Session handle[FE000004] Session id[4]
Feb  6 07:00:02.119: Vi2 LCP: Event[OPEN] State[Initial to Starting]
Feb  6 07:00:02.119: Vi2 PPP: No remote authentication for call-out
Feb  6 07:00:02.119: Vi2 LCP: O CONFREQ [Starting] id 1 len 10
Feb  6 07:00:02.119: Vi2 LCP:    MagicNumber 0xEF647988 (0x0506EF647988)
Feb  6 07:00:02.119: Vi2 LCP: Event[UP] State[Starting to REQsent]
Feb  6 07:00:02.215: Vi2 LCP: I CONFREQ [REQsent] id 46 len 18
Feb  6 07:00:02.215: Vi2 LCP:    MRU 1492 (0x010405D4)
Feb  6 07:00:02.215: Vi2 LCP:    AuthProto PAP (0x0304C023)
Feb  6 07:00:02.215: Vi2 LCP:    MagicNumber 0x6D0D5D24 (0x05066D0D5D24)
Feb  6 07:00:02.215: Vi2 LCP: O CONFNAK [REQsent] id 46 len 8
Feb  6 07:00:02.215: Vi2 LCP:    MRU 1500 (0x010405DC)
Feb  6 07:00:02.215: Vi2 LCP: Event[Receive ConfReq-] State[REQsent to REQsent]
Feb  6 07:00:02.215: Vi2 LCP: I CONFACK [REQsent] id 1 len 10
Feb  6 07:00:02.215: Vi2 LCP:    MagicNumber 0xEF647988 (0x0506EF647988)
Feb  6 07:00:02.215: Vi2 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
Feb  6 07:00:02.219: Vi2 LCP: I CONFREQ [ACKrcvd] id 47 len 18
Feb  6 07:00:02.219: Vi2 LCP:    MRU 1500 (0x010405DC)
Feb  6 07:00:02.219: Vi2 LCP:    AuthProto PAP (0x0304C023)
Feb  6 07:00:02.219: Vi2 LCP:    MagicNumber 0x6D0D5D24 (0x05066D0D5D24)
Feb  6 07:00:02.219: Vi2 LCP: O CONFACK [ACKrcvd] id 47 len 18
Feb  6 07:00:02.219: Vi2 LCP:    MRU 1500 (0x010405DC)
Feb  6 07:00:02.219: Vi2 LCP:    AuthProto PAP (0x0304C023)
Feb  6 07:00:02.219: Vi2 LCP:    MagicNumber 0x6D0D5D24 (0x05066D0D5D24)
Feb  6 07:00:02.219: Vi2 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
Feb  6 07:00:02.251: Vi2 PPP: Phase is AUTHENTICATING, by the peer
Feb  6 07:00:02.251: Vi2 PAP: Using hostname from interface PAP
Feb  6 07:00:02.251: Vi2 PAP: Using password from interface PAP
Feb  6 07:00:02.251: Vi2 PAP: O AUTH-REQ id 1 len 22 from "inmagdc1"
Feb  6 07:00:02.251: Vi2 LCP: State is Open
Feb  6 07:00:02.659: Vi2 PAP: I AUTH-ACK id 1 len 5
Feb  6 07:00:02.659: Vi2 PPP: Phase is FORWARDING, Attempting Forward
Feb  6 07:00:02.659: Vi2 PPP: Queue IPCP code[1] id[232]
Feb  6 07:00:02.659: Vi2 PPP: Phase is ESTABLISHING, Finish LCP
Feb  6 07:00:02.659: Vi2 PPP: Phase is UP
Feb  6 07:00:02.659: Vi2 IPCP: Protocol configured, start CP. state[Initial]
Feb  6 07:00:02.659: Vi2 IPCP: Event[OPEN] State[Initial to Starting]
Feb  6 07:00:02.659: Vi2 IPCP: O CONFREQ [Starting] id 1 len 10
Feb  6 07:00:02.659: Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Feb  6 07:00:02.659: Vi2 IPCP: Event[UP] State[Starting to REQsent]
Feb  6 07:00:02.659: Vi2 CDPCP: Protocol configured, start CP. state[Initial]
Feb  6 07:00:02.659: Vi2 CDPCP: Event[OPEN] State[Initial to Starting]
Feb  6 07:00:02.659: Vi2 CDPCP: O CONFREQ [Starting] id 1 len 4
Feb  6 07:00:02.659: Vi2 CDPCP: Event[UP] State[Starting to REQsent]
Feb  6 07:00:02.659: Vi2 PPP: Process pending ncp packets
Feb  6 07:00:02.659: Vi2 IPCP: Redirect packet to Vi2
Feb  6 07:00:02.659: Vi2 IPCP: I CONFREQ [REQsent] id 232 len 10
Feb  6 07:00:02.659: Vi2 IPCP:    Address 213.42.5.11 (0x0306D52A050B)
Feb  6 07:00:02.659: Vi2 IPCP: O CONFACK [REQsent] id 232 len 10
Feb  6 07:00:02.659: Vi2 IPCP:    Address 213.42.5.11 (0x0306D52A050B)
Feb  6 07:00:02.659: Vi2 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent]

Feb  6 07:00:02.659: Vi2 IPCP: I CONFNAK [ACKsent] id 1 len 10
Feb  6 07:00:02.659: Vi2 IPCP:    Address 217.165.68.7 (0x0306D9A54407)
Feb  6 07:00:02.659: Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 10
Feb  6 07:00:02.659: Vi2 IPCP:    Address 217.165.68.7 (0x0306D9A54407)
Feb  6 07:00:02.663: Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKse
nt]
Feb  6 07:00:02.663: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Acc
ess2, changed state to up
Feb  6 07:00:02.663: Vi2 LCP: I PROTREJ [Open] id 48 len 10 protocol CDPCP (0x01
010004)
Feb  6 07:00:02.663: Vi2 CDPCP: Event[Receive CodeRej-] State[REQsent to Stopped
]
Feb  6 07:00:02.663: Vi2 IPCP: I CONFACK [ACKsent] id 2 len 10
Feb  6 07:00:02.663: Vi2 IPCP:    Address 217.165.68.7 (0x0306D9A54407)
Feb  6 07:00:02.663: Vi2 IPCP: Event[Receive ConfAck] State[ACKsent to Open]
Feb  6 07:00:02.667: Vi2 IPCP: State is Open
Feb  6 07:00:02.667: Di0 IPCP: Install negotiated IP interface address 217.165.6
8.7
Feb  6 07:00:02.667: Di0 Added to neighbor route AVL tree: topoid 0, address 213
.42.5.11
Feb  6 07:00:02.667: Di0 IPCP: Install route to 213.42.5.11
Feb  6 07:00:08.615: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated
Feb  6 07:00:15.859: %SEC-6-IPACCESSLOGNP: list wan-security permitted 50 83.111
.161.50 -> 217.165.68.7, 1 packet
Feb  6 07:00:22.551: %IP_VFR-4-FRAG_TABLE_OVERFLOW: Dialer0: the fragment table
has reached its maximum threshold 16
Feb  6 07:01:08.603: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated
Feb  6 07:01:25.587: Vi2 LCP: I TERMREQ [Open] id 49 len 4
Feb  6 07:01:25.587: Vi2 PPP DISC: Received LCP TERMREQ from peer
Feb  6 07:01:25.587: PPP: NET STOP send to AAA.
Feb  6 07:01:25.587: Vi2 PPP: Phase is TERMINATING
Feb  6 07:01:25.587: Vi2 IPCP: Event[DOWN] State[Open to Starting]
Feb  6 07:01:25.587: Vi2 IPCP: Event[CLOSE] State[Starting to Initial]
Feb  6 07:01:25.587: Vi2 CDPCP: Event[DOWN] State[Stopped to Starting]
Feb  6 07:01:25.587: Vi2 CDPCP: Event[CLOSE] State[Starting to Initial]
Feb  6 07:01:25.587: Vi2 LCP: O TERMACK [Open] id 49 len 4
Feb  6 07:01:25.587: Vi2 LCP: Event[Receive TermReq] State[Open to Stopping]
Feb  6 07:01:25.591: Di0 Deleted neighbor route from AVL tree: topoid 0, address
213.42.5.11
Feb  6 07:01:25.591: Di0 IPCP: Remove route to 213.42.5.11
Feb  6 07:01:25.747: Vi2 PPP: Outbound ip packet dropped, line protocol not up
Feb  6 07:01:26.303: Vi2 PPP: Outbound ip packet dropped, line protocol not up
Feb  6 07:01:27.351: Vi2 PPP: Outbound ip packet dropped, line protocol not up
Feb  6 07:01:27.595: Vi2 PPP: No remote authentication for call-out
Feb  6 07:01:27.595: Vi2 LCP: Event[Timeout-] State[Stopping to Stopped]
Feb  6 07:01:27.595: Vi2 LCP: Event[DOWN] State[Stopped to Starting]
Feb  6 07:01:27.595: Vi2 PPP: Phase is DOWN
Feb  6 07:01:27.595: PPPoE: Failed to add PPPoE switching subblock
Feb  6 07:01:27.595: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di0
Feb  6 07:01:27.599: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Acc
ess2, changed state to down
Feb  6 07:01:27.599: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to
down
Feb  6 07:01:27.599: Vi2 Debug: Condition 1, interface Di0 cleared, count 0
Feb  6 07:01:27.599: PPPoE: Unexpected Event!. PPPoE switching Subblockdestroy c
alled
Feb  6 07:02:35.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/0, changed state to down
Feb  6 07:02:36.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/0, changed state
to down
Feb  6 07:02:40.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to down
Feb  6 07:02:41.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to down
Feb  6 07:02:44.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to up
Feb  6 07:02:47.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to down
Feb  6 07:02:51.339: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to up
Feb  6 07:02:52.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/0, changed state
to up
Feb  6 07:02:52.339: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to up
Feb  6 07:02:53.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/0, changed state to up
Feb  6 07:02:58.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to down
Feb  6 07:02:59.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to down
Feb  6 07:03:08.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to up
Feb  6 07:03:09.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to up
Feb  6 07:03:47.067: %SEC-6-IPACCESSLOGNP: list wan-security permitted 50 83.111
.161.50 -> 217.165.68.84, 282 packets
Feb  6 07:03:47.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to down
Feb  6 07:03:48.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to down
Feb  6 07:03:51.331: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state
to up
Feb  6 07:03:52.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthe
rnet0/1, changed state to up
Feb  6 07:05:31.847: %DIALER-6-BIND: Interface Vi2 bound to profile Di0
Feb  6 07:05:31.847: Vi2 Debug: Condition 1, interface Di0 triggered, count 1
Feb  6 07:05:31.851: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to
up
Feb  6 07:05:31.851: Vi2 PPP: Sending cstate UP notification
Feb  6 07:05:31.851: Vi2 PPP: Processing CstateUp message
Feb  6 07:05:31.851: Vi2 PPP: Using dialer call direction
Feb  6 07:05:31.851: Vi2 PPP: Treating connection as a callout
Feb  6 07:05:31.851: Vi2 PPP: Session handle[DD000005] Session id[5]
Feb  6 07:05:31.851: Vi2 LCP: Event[OPEN] State[Initial to Starting]
Feb  6 07:05:31.851: Vi2 PPP: No remote authentication for call-out
Feb  6 07:05:31.851: Vi2 LCP: O CONFREQ [Starting] id 1 len 10
Feb  6 07:05:31.851: Vi2 LCP:    MagicNumber 0xEF698266 (0x0506EF698266)
Feb  6 07:05:31.851: Vi2 LCP: Event[UP] State[Starting to REQsent]
Feb  6 07:05:31.855: Vi2 LCP: I CONFREQ [REQsent] id 18 len 18
Feb  6 07:05:31.855: Vi2 LCP:    MRU 1492 (0x010405D4)
Feb  6 07:05:31.855: Vi2 LCP:    AuthProto PAP (0x0304C023)
Feb  6 07:05:31.855: Vi2 LCP:    MagicNumber 0x1288BF5E (0x05061288BF5E)
Feb  6 07:05:31.855: Vi2 LCP: O CONFNAK [REQsent] id 18 len 8
Feb  6 07:05:31.855: Vi2 LCP:    MRU 1500 (0x010405DC)
Feb  6 07:05:31.855: Vi2 LCP: Event[Receive ConfReq-] State[REQsent to REQsent]
Feb  6 07:05:31.855: Vi2 LCP: I CONFACK [REQsent] id 1 len 10
Feb  6 07:05:31.855: Vi2 LCP:    MagicNumber 0xEF698266 (0x0506EF698266)
Feb  6 07:05:31.855: Vi2 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
Feb  6 07:05:31.859: Vi2 LCP: I CONFREQ [ACKrcvd] id 19 len 18
Feb  6 07:05:31.859: Vi2 LCP:    MRU 1500 (0x010405DC)
Feb  6 07:05:31.859: Vi2 LCP:    AuthProto PAP (0x0304C023)
Feb  6 07:05:31.859: Vi2 LCP:    MagicNumber 0x1288BF5E (0x05061288BF5E)
Feb  6 07:05:31.859: Vi2 LCP: O CONFACK [ACKrcvd] id 19 len 18
Feb  6 07:05:31.859: Vi2 LCP:    MRU 1500 (0x010405DC)
Feb  6 07:05:31.859: Vi2 LCP:    AuthProto PAP (0x0304C023)
Feb  6 07:05:31.859: Vi2 LCP:    MagicNumber 0x1288BF5E (0x05061288BF5E)
Feb  6 07:05:31.859: Vi2 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
Feb  6 07:05:31.883: Vi2 PPP: Phase is AUTHENTICATING, by the peer
Feb  6 07:05:31.883: Vi2 PAP: Using hostname from interface PAP
Feb  6 07:05:31.883: Vi2 PAP: Using password from interface PAP
Feb  6 07:05:31.883: Vi2 PAP: O AUTH-REQ id 1 len 22 from "inmagdc1"
Feb  6 07:05:31.883: Vi2 LCP: State is Open
Feb  6 07:05:32.363: Vi2 PAP: I AUTH-ACK id 1 len 5
Feb  6 07:05:32.363: Vi2 PPP: Phase is FORWARDING, Attempting Forward
Feb  6 07:05:32.363: Vi2 PPP: Queue IPCP code[1] id[236]
Feb  6 07:05:32.363: Vi2 PPP: Phase is ESTABLISHING, Finish LCP
Feb  6 07:05:32.363: Vi2 PPP: Phase is UP
Feb  6 07:05:32.363: Vi2 IPCP: Protocol configured, start CP. state[Initial]
Feb  6 07:05:32.363: Vi2 IPCP: Event[OPEN] State[Initial to Starting]
Feb  6 07:05:32.363: Vi2 IPCP: O CONFREQ [Starting] id 1 len 10
Feb  6 07:05:32.363: Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Feb  6 07:05:32.363: Vi2 IPCP: Event[UP] State[Starting to REQsent]
Feb  6 07:05:32.363: Vi2 CDPCP: Protocol configured, start CP. state[Initial]
Feb  6 07:05:32.363: Vi2 CDPCP: Event[OPEN] State[Initial to Starting]
Feb  6 07:05:32.363: Vi2 CDPCP: O CONFREQ [Starting] id 1 len 4
Feb  6 07:05:32.363: Vi2 CDPCP: Event[UP] State[Starting to REQsent]
Feb  6 07:05:32.363: Vi2 PPP: Process pending ncp packets
Feb  6 07:05:32.363: Vi2 IPCP: Redirect packet to Vi2
Feb  6 07:05:32.363: Vi2 IPCP: I CONFREQ [REQsent] id 236 len 10
Feb  6 07:05:32.363: Vi2 IPCP:    Address 213.42.5.11 (0x0306D52A050B)
Feb  6 07:05:32.363: Vi2 IPCP: O CONFACK [REQsent] id 236 len 10
Feb  6 07:05:32.363: Vi2 IPCP:    Address 213.42.5.11 (0x0306D52A050B)
Feb  6 07:05:32.363: Vi2 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent]

Feb  6 07:05:32.367: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Acc
ess2, changed state to up
Feb  6 07:05:32.367: Vi2 IPCP: I CONFNAK [ACKsent] id 1 len 10
Feb  6 07:05:32.367: Vi2 IPCP:    Address 2.50.165.46 (0x03060232A52E)
Feb  6 07:05:32.367: Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 10
Feb  6 07:05:32.367: Vi2 IPCP:    Address 2.50.165.46 (0x03060232A52E)
Feb  6 07:05:32.367: Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKse
nt]
Feb  6 07:05:32.367: Vi2 LCP: I PROTREJ [Open] id 20 len 10 protocol CDPCP (0x01
010004)
Feb  6 07:05:32.367: Vi2 CDPCP: Event[Receive CodeRej-] State[REQsent to Stopped
]
Feb  6 07:05:32.371: Vi2 IPCP: I CONFACK [ACKsent] id 2 len 10
Feb  6 07:05:32.371: Vi2 IPCP:    Address 2.50.165.46 (0x03060232A52E)
Feb  6 07:05:32.371: Vi2 IPCP: Event[Receive ConfAck] State[ACKsent to Open]
Feb  6 07:05:32.395: Vi2 IPCP: State is Open
Feb  6 07:05:32.395: Di0 IPCP: Install negotiated IP interface address 2.50.165.
46
Feb  6 07:05:32.395: Di0 Added to neighbor route AVL tree: topoid 0, address 213
.42.5.11
Feb  6 07:05:32.395: Di0 IPCP: Install route to 213.42.5.11
Feb  6 07:05:37.019: %SEC-6-IPACCESSLOGNP: list wan-security permitted 50 83.111
.161.50 -> 2.50.165.46, 1 packet
Feb  6 07:05:38.735: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated
Feb  6 07:05:47.067: %SEC-6-IPACCESSLOGNP: list wan-security permitted 50 83.111
.161.50 -> 217.165.68.7, 197 packets
Feb  6 07:06:36.515: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated
Feb  6 07:07:31.055: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated

thnaks

cyril

[AJ Cruz]

Sounds like it could be an MTU issue. You could either band aide it by allowing more buffer space for fragment reassembly with "virtual-reassembly max-reassemblies <#>" or figure out the root cause of all the fragments.

Keep in mind that the PPPoE header adds an extra 8 bytes to PPP frames encapsulated in Ethernet frames.

Sent from Cisco Technical Support iPad App

[Nandan Mathure]

Hi!

I suppose this relates to MTU mismatch.  You can try using mtu 1492 under the dialer interface.

Could you also share your config .

Thanks,

Nandan Mathure

[Volodymyr Grys]

I had similar issue and it was MTU mismatch. Thanks for this information.