Solved: ISP works on ISR 4331 IOS 16.6 but doesn't on ISR 4451 IOS 15.5

varunoberoi · ‎02-05-2022

I am replacing an ISR 4331 ISO 16.6 that I bought new with an ISR 4451 IOS 15.5. I am running the exact same commands to configure an ISP using PPPOE. It works on the ISR 4331 but doesn't on the ISR 4451.

----------------------------

config t
interface GigabitEthernet 0/0/1
no shutdown
pppoe enable group global
pppoe-client dial-pool-number 1
exit
interface dialer 1
no shutdown
no shutdown
ip address negotiated
encapsulation ppp
ip tcp adjust-mss 1442
dialer pool 1
dialer-group 1
ppp authentication chap callin
ppp chap hostname user_id@ftth.bsnl.in
ppp chap password password
exit

!Default Route For Internet Traffic
ip route 0.0.0.0 0.0.0.0 dialer 1

! Set NAT outside
interface dialer 1
ip nat outside
exit

exit

----------------------------------

I tried `debug pppoe negotiation` but no such command exists on ISR 4451 running IOS 15.5. How to diagnose it and solve this.

Georg Pauwen · ‎02-05-2022

Hello,

try and configure:

ip mtu 1492

on the dialer interface. If that doesn't help, post the full running configuration.

View solution in original post

Georg Pauwen · ‎02-05-2022

Hello,

try and configure:

ip mtu 1492

on the dialer interface. If that doesn't help, post the full running configuration.

varunoberoi · ‎02-05-2022

Yes!! Thanks!

Georg Pauwen · ‎02-05-2022

Hello,

I think it is this bug:

ISR 4K|PPPoE Interface|Not Forwarding all IP fragments
CSCva13768

Description
Symptom:
ISR4K router is not forwarding all IP fragments "out" of the Dialer (PPPoE) interface (trying to reach dialer interface IP, to-the-box traffic)

For example, if user send ping with size 1800 bytes (~ 1500 (frag1) + 300(frag2)) then on the upstream device we receive only one fragment (300 (frag)).

Conditions:
** PPPoE interface configured
** Packet size is greater than MTU size on the Dialer interface so router has to fragment larger packet
** To the box, destined to the router dialer interface
** Dialer interface has default mtu of 1500

Workaround:
Configure "mtu 1492" on the dialer interface

varunoberoi · ‎02-20-2022

@Georg Pauwen

The interface still isn't stable. Sometimes it simply fails to negotiate an IP address. When it does, it drops the IP address after about 24 hours. Anything else that can be done?

debug ppp negotiation output:

OrionRouter#debug ppp negotiation
PPP protocol negotiation debugging is on
OrionRouter#
*Feb 21 05:55:22.209: %DIALER-6-BIND: Interface Vi3 bound to profile Di1
*Feb 21 05:55:22.210: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to up
*Feb 21 05:55:22.210: Vi3 PPP: Sending cstate UP notification
*Feb 21 05:55:22.210: Vi3 PPP: Processing CstateUp message
*Feb 21 05:55:22.211: PPP: Alloc Context [7F4F2577F7C8]
*Feb 21 05:55:22.211: ppp23 PPP: Phase is ESTABLISHING
*Feb 21 05:55:22.211: Vi3 PPP: Using dialer call direction
*Feb 21 05:55:22.211: Vi3 PPP: Treating connection as a callout
*Feb 21 05:55:22.211: Vi3 PPP: Session handle[3E000018] Session id[23]
*Feb 21 05:55:22.211: Vi3 LCP: Event[OPEN] State[Initial to Starting]
*Feb 21 05:55:22.211: Vi3 PPP: No remote authentication for call-out
*Feb 21 05:55:22.211: Vi3 LCP: O CONFREQ [Starting] id 1 len 10
*Feb 21 05:55:22.211: Vi3 LCP:    MagicNumber 0xF3151027 (0x0506F3151027)
*Feb 21 05:55:22.211: Vi3 LCP: Event[UP] State[Starting to REQsent]
*Feb 21 05:55:22.419: Vi3 LCP: I CONFREQ [REQsent] id 113 len 19
*Feb 21 05:55:22.419: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.419: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.419: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.419: Vi3 LCP: O CONFNAK [REQsent] id 113 len 8
*Feb 21 05:55:22.419: Vi3 LCP:    MRU 1500 (0x010405DC)
*Feb 21 05:55:22.419: Vi3 LCP: Event[Receive ConfReq-] State[REQsent to REQsent]
*Feb 21 05:55:22.419: Vi3 LCP: I CONFACK [REQsent] id 1 len 10
*Feb 21 05:55:22.419: Vi3 LCP:    MagicNumber 0xF3151027 (0x0506F3151027)
*Feb 21 05:55:22.419: Vi3 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
*Feb 21 05:55:22.425: Vi3 LCP: I CONFREQ [ACKrcvd] id 114 len 19
*Feb 21 05:55:22.425: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.425: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.425: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.425: Vi3 LCP: O CONFNAK [ACKrcvd] id 114 len 8
*Feb 21 05:55:22.425: Vi3 LCP:    MRU 1500 (0x010405DC)
*Feb 21 05:55:22.425: Vi3 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Feb 21 05:55:22.431: Vi3 LCP: I CONFREQ [ACKrcvd] id 115 len 19
*Feb 21 05:55:22.431: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.431: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.431: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.431: Vi3 LCP: O CONFNAK [ACKrcvd] id 115 len 8
*Feb 21 05:55:22.431: Vi3 LCP:    MRU 1500 (0x010405DC)
*Feb 21 05:55:22.431: Vi3 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Feb 21 05:55:22.436: Vi3 LCP: I CONFREQ [ACKrcvd] id 116 len 19
*Feb 21 05:55:22.436: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.436: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.436: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.436: Vi3 LCP: O CONFNAK [ACKrcvd] id 116 len 8
*Feb 21 05:55:22.436: Vi3 LCP:    MRU 1500 (0x010405DC)
*Feb 21 05:55:22.436: Vi3 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Feb 21 05:55:22.441: Vi3 LCP: I CONFREQ [ACKrcvd] id 117 len 19
*Feb 21 05:55:22.441: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.441: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.441: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.441: Vi3 LCP: O CONFNAK [ACKrcvd] id 117 len 8
*Feb 21 05:55:22.441: Vi3 LCP:    MRU 1500 (0x010405DC)
*Feb 21 05:55:22.441: Vi3 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Feb 21 05:55:22.446: Vi3 LCP: I CONFREQ [ACKrcvd] id 118 len 19
*Feb 21 05:55:22.446: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.446: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.446: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.446: Vi3 LCP: Sent too many CONFNAKs.  Switch to CONFREJ
*Feb 21 05:55:22.446: Vi3 LCP: O CONFREJ [ACKrcvd] id 118 len 8
*Feb 21 05:55:22.446: Vi3 LCP:    MRU 1460 (0x010405B4)
*Feb 21 05:55:22.446: Vi3 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Feb 21 05:55:22.449: Vi3 LCP: I CONFREQ [ACKrcvd] id 119 len 15
*Feb 21 05:55:22.449: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.449: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.449: Vi3 LCP: O CONFACK [ACKrcvd] id 119 len 15
*Feb 21 05:55:22.449: Vi3 LCP:    AuthProto CHAP (0x0305C22305)
*Feb 21 05:55:22.449: Vi3 LCP:    MagicNumber 0x16AF0ABA (0x050616AF0ABA)
*Feb 21 05:55:22.449: Vi3 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
*Feb 21 05:55:22.451: Vi3 PPP: Phase is AUTHENTICATING, by the peer
*Feb 21 05:55:22.451: Vi3 LCP: State is Open
*Feb 21 05:55:22.452: Vi3 CHAP: I CHALLENGE id 1 len 39 from "his-ras-bng-hsr-01"
*Feb 21 05:55:22.452: Vi3 CHAP: Using hostname from interface CHAP
*Feb 21 05:55:22.452: Vi3 CHAP: Using password from interface CHAP
*Feb 21 05:55:22.452: Vi3 CHAP: O RESPONSE id 1 len 50 from "or16xxxx533_nid@ftth.bsnl.in"
*Feb 21 05:55:22.642: Vi3 CHAP: I SUCCESS id 1 len 26 msg is "Authentication Success"
*Feb 21 05:55:22.642: Vi3 PPP: Phase is FORWARDING, Attempting Forward
*Feb 21 05:55:22.642: Vi3 PPP: Control packet rate limit 10 reached
*Feb 21 05:55:22.642: Vi3 PPP: Entering block state for 30 seconds
*Feb 21 05:55:22.642: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:22.642: Vi3 PPP: Phase is ESTABLISHING, Finish LCP
*Feb 21 05:55:22.642: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to up
*Feb 21 05:55:22.643: Vi3 PPP: Phase is UP
*Feb 21 05:55:22.643: Vi3 IPCP: Protocol configured, start CP. state[Initial]
*Feb 21 05:55:22.643: Vi3 IPCP: Event[OPEN] State[Initial to Starting]
*Feb 21 05:55:22.643: Vi3 IPCP: O CONFREQ [Starting] id 1 len 10
*Feb 21 05:55:22.643: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:22.643: Vi3 IPCP: Event[UP] State[Starting to REQsent]
*Feb 21 05:55:22.643: Vi3 CDPCP: Protocol configured, start CP. state[Initial]
*Feb 21 05:55:22.643: Vi3 CDPCP: Event[OPEN] State[Initial to Starting]
*Feb 21 05:55:22.643: Vi3 CDPCP: O CONFREQ [Starting] id 1 len 4
*Feb 21 05:55:22.643: Vi3 CDPCP: Event[UP] State[Starting to REQsent]
*Feb 21 05:55:22.649: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:22.649: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:24.627: Vi3 CDPCP: O CONFREQ [REQsent] id 2 len 4
*Feb 21 05:55:24.627: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:24.631: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:25.710: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:26.644: Vi3 CDPCP: O CONFREQ [REQsent] id 3 len 4
*Feb 21 05:55:26.644: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:26.648: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:28.660: Vi3 CDPCP: O CONFREQ [REQsent] id 4 len 4
*Feb 21 05:55:28.660: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:28.663: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:28.802: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:30.675: Vi3 CDPCP: O CONFREQ [REQsent] id 5 len 4
*Feb 21 05:55:30.676: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:30.683: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:31.924: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:32.692: Vi3 CDPCP: O CONFREQ [REQsent] id 6 len 4
*Feb 21 05:55:32.692: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:32.696: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:34.708: Vi3 CDPCP: O CONFREQ [REQsent] id 7 len 4
*Feb 21 05:55:34.708: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:34.711: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:35.013: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:36.723: Vi3 CDPCP: O CONFREQ [REQsent] id 8 len 4
*Feb 21 05:55:36.723: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:36.726: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:38.105: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:38.740: Vi3 CDPCP: O CONFREQ [REQsent] id 9 len 4
*Feb 21 05:55:38.740: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:38.743: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:40.756: Vi3 CDPCP: O CONFREQ [REQsent] id 10 len 4
*Feb 21 05:55:40.756: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:40.758: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:41.211: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:42.772: Vi3 CDPCP: Event[Timeout-] State[REQsent to Stopped]
*Feb 21 05:55:44.313: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:44.787: Vi3 IPCP: O CONFREQ [REQsent] id 2 len 10
*Feb 21 05:55:44.787: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:44.787: Vi3 IPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:44.791: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:44.884: Vi3 PPP CDPCP: Exit passive mode, state[Starting]
*Feb 21 05:55:44.884: Vi3 CDPCP: O CONFREQ [Starting] id 11 len 4
*Feb 21 05:55:44.884: Vi3 CDPCP: Event[UP] State[Starting to REQsent]
*Feb 21 05:55:44.889: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:46.803: Vi3 IPCP: O CONFREQ [REQsent] id 3 len 10
*Feb 21 05:55:46.803: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:46.803: Vi3 IPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:46.806: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:46.900: Vi3 CDPCP: O CONFREQ [REQsent] id 12 len 4
*Feb 21 05:55:46.900: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:46.903: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:47.414: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:48.820: Vi3 IPCP: O CONFREQ [REQsent] id 4 len 10
*Feb 21 05:55:48.820: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:48.820: Vi3 IPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:48.822: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:48.916: Vi3 CDPCP: O CONFREQ [REQsent] id 13 len 4
*Feb 21 05:55:48.916: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:48.919: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:50.511: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:50.836: Vi3 IPCP: O CONFREQ [REQsent] id 5 len 10
*Feb 21 05:55:50.836: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:50.836: Vi3 IPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:50.839: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:50.932: Vi3 CDPCP: O CONFREQ [REQsent] id 14 len 4
*Feb 21 05:55:50.932: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:50.935: Vi3 PPP: Packet throttled, Dropping packet
*Feb 21 05:55:52.851: Vi3 IPCP: O CONFREQ [REQsent] id 6 len 10
*Feb 21 05:55:52.851: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:52.851: Vi3 IPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:52.854: Vi3 IPCP: I CONFREJ [REQsent] id 6 len 10
*Feb 21 05:55:52.854: Vi3 IPCP:    Address 0.0.0.0 (0x030600000000)
*Feb 21 05:55:52.854: Vi3 IPCP: O CONFREQ [REQsent] id 7 len 4
*Feb 21 05:55:52.854: Vi3 IPCP: Event[Receive ConfNak/Rej] State[REQsent to REQsent]
*Feb 21 05:55:52.857: Vi3 IPCP: I CONFACK [REQsent] id 7 len 4
*Feb 21 05:55:52.857: Vi3 IPCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
*Feb 21 05:55:52.947: Vi3 CDPCP: O CONFREQ [REQsent] id 15 len 4
*Feb 21 05:55:52.947: Vi3 CDPCP: Event[Timeout+] State[REQsent to REQsent]
*Feb 21 05:55:52.951: Vi3 LCP: I PROTREJ [Open] id 134 len 10 protocol CDPCP (0x010F0004)
*Feb 21 05:55:52.951: Vi3 CDPCP: Event[Receive CodeRej-] State[REQsent to Stopped]
*Feb 21 05:55:53.606: Vi3 IPCP: I CONFREQ [ACKrcvd] id 12 len 10
*Feb 21 05:55:53.606: Vi3 IPCP:    Address 117.242.47.1 (0x030675F22F01)
*Feb 21 05:55:53.606: Vi3 IPCP: O CONFACK [ACKrcvd] id 12 len 10
*Feb 21 05:55:53.606: Vi3 IPCP:    Address 117.242.47.1 (0x030675F22F01)
*Feb 21 05:55:53.606: Vi3 IPCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
*Feb 21 05:55:53.620: Vi3 IPCP: State is Open
*Feb 21 05:55:53.620: Di1 Added to neighbor route AVL tree: topoid 0, address 117.242.47.1
*Feb 21 05:55:53.620: Di1 IPCP: Install route to 117.242.47.1
*Feb 21 05:56:05.690: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated
*Feb 21 05:56:30.886: Vi3 PPP: Outbound cdp packet dropped, NCP not negotiated
*Feb 21 05:56:56.577: Vi2 PPP: Outbound cdp packet dropped, NCP not negotiated
*Feb 21 05:57:26.246: Vi3 PPP: Outbound cdp packet dropped, NCP not negotiated

Georg Pauwen · ‎02-21-2022

Hello,

annoying indeed. So the MTU setting did not resolve this. What if you configure 'dialer persistent' on the dialer interface (I think you have to shut/no shut the interface for that command to take effect):

interface dialer 1
ip address negotiated
--> ip mtu 1492
encapsulation ppp
--> ip tcp adjust-mss 1452
dialer pool 1
dialer-group 1
--> dialer persistent
ppp authentication chap callin
ppp chap hostname user_id@ftth.bsnl.in
ppp chap password password

varunoberoi · ‎02-24-2022

So far so good. Let me just observe this for another week and I will revert after.

Thanks for the help.

varunoberoi · ‎02-27-2022

Nope, still causing problems.

It just stops after like 24 hours. Then it works again when I run some commands in no particular order, or sometimes I run them one at a time, sometime all of them.

I try changing MTU value, sometimes it works on 1500, sometimes on 1350, sometimes on 1450.

I shut down the interface and no shut down it after few minutes. Then I run debug ppp negotiation. Somehow this works most times.

I remove the ip route to the dialer and then add it again.

Don't know what exactly is going on. Maybe this is a bug in the OS. My previous ISR 4331 router running IOS 16.6 never gave such issues.

varunoberoi · ‎02-28-2022

As a hack solution, Can I schedule a reboot at a particular time every day? Maybe that'll help.

I could also schedule a set of commands to run every day as well.

Is that possible?

Georg Pauwen · ‎02-28-2022

Hello,

you certainly could run an EEM script that would execute certain commands. The script below would bounce (shut/no shut) the dialer interface each day at midnight:

event manager applet SHUT_DIALER
event timer cron cron-entry "0 0 * * *" maxrun 999999
action 1.0 cli command "enable"
action 2.0 cli command "config t"
action 3.0 cli command "interface Dialer 1"
action 4.0 cli command "shut"
action 5.0 cli command "no shut"
action 6.0 cli command "end"

However, I would start with a simple IP SLA that keeps pinging an external address permanently, maybe that is enough:

ip sla 1
icmp-echo 8.8.8.8 source-interface Dialer 1
!
ip sla schedule 1 start-time now life forever