Hi,My personal impression

tradeaccc · ‎01-15-2015

Have a ADSL connection connected to a Cisco router - It has been working for a long time and now all of a sudden it fails with the following logs. There has been no change to the configuration on our end. Can anyone help me with the logs. It looks like PPP authenticates and then CP fails because of too many 'CONFREJs'. What exactly does this mean? Is the ISP at fault here?

Vi2 LCP:    MRU 1492 (0x010405D4)
Vi2 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
Vi2 LCP: I CONFREQ [ACKrcvd] id 103 len 14
Vi2 LCP:    AuthProto PAP (0x0304C023)
Vi2 LCP:    MagicNumber 0x07397505 (0x050607397505)
Vi2 LCP: O CONFACK [ACKrcvd] id 103 len 14
Vi2 LCP:    AuthProto PAP (0x0304C023)
Vi2 LCP:    MagicNumber 0x07397505 (0x050607397505)
Vi2 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
Vi2 PPP: Phase is AUTHENTICATING, by the peer
Vi2 PAP: Using hostname from interface PAP
Vi2 PAP: Using password from interface PAP
Vi2 PAP: O AUTH-REQ id 1 len 22 from "xxxx"
Vi2 LCP: State is Open
Vi2 PAP: I AUTH-ACK id 1 len 13 msg is "Login ok"
Vi2 PPP: Phase is FORWARDING, Attempting Forward
Vi2 PPP: Phase is ESTABLISHING, Finish LCP
%LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
Vi2 PPP: No AAA accounting method list
Vi2 PPP: Phase is UP
Vi2 IPCP: Protocol configured, start CP. state[Initial]
Vi2 IPCP: Event[OPEN] State[Initial to Starting]
Vi2 IPCP: O CONFREQ [Starting] id 1 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: Event[UP] State[Starting to REQsent]
Vi2 IPCP: I CONFREQ [REQsent] id 18 len 10
Vi2 IPCP:    Address x.x.x.x (0x0306B0CD6001)
Vi2 IPCP: O CONFACK [REQsent] id 18 len 10
Vi2 IPCP:    Address x.x.x.x (0x0306B0CD6001)
Vi2 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent]
Vi2 PPP: Control packet rate limit 10 reached
Vi2 PPP: Entering block state for 30 seconds
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: Event[Timeout+] State[ACKsent to ACKsent]
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 IPCP: O CONFREQ [ACKsent] id 3 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: Event[Timeout+] State[ACKsent to ACKsent]
Vi2 PPP: Packet throttled, Dropping packet
Vi2 IPCP: O CONFREQ [ACKsent] id 4 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: Event[Timeout+] State[ACKsent to ACKsent]
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 IPCP: O CONFREQ [ACKsent] id 5 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: Event[Timeout+] State[ACKsent to ACKsent]
Vi2 PPP: Packet throttled, Dropping packet
Vi2 PPP: Packet throttled, Dropping packet
Vi2 IPCP: O CONFREQ [ACKsent] id 6 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: Event[Timeout+] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 6 len 10
Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
Vi2 IPCP: O CONFREQ [ACKsent] id 7 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 7 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 8 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 8 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 9 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 9 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 10 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 10 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 11 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 11 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 12 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 12 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 13 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 13 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 14 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 14 len 4
Vi2 IPCP: O CONFREQ [ACKsent] id 15 len 4
Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
Vi2 IPCP: I CONFREJ [ACKsent] id 15 len 4
Vi2 IPCP: Received too many CONFREJs. Closing CP
Vi2 PPP IPCP: Enter passive mode, state[Stopped]
Vi2 LCP: I TERMREQ [Open] id 104 len 4
Vi2 PPP DISC: Received LCP TERMREQ from peer
Vi2 PPP: Sending Acct Event[Down] id[F5]
PPP: NET STOP send to AAA.
Vi2 PPP: Phase is TERMINATING
Vi2 IPCP: Event[DOWN] State[Stopped to Starting]
Vi2 IPCP: Event[CLOSE] State[Starting to Initial]
Vi2 LCP: O TERMACK [Open] id 104 len 4
Vi2 LCP: Event[Receive TermReq] State[Open to Stopping]
PPPoE 1: I PADT R:0000.5e00.010c L:b0fa.ebc1.b190 Gi0/0
PPPoE : Shutting down client session
[0]PPPoE 1: O PADT R:0000.5e00.010c L:b0fa.ebc1.b190 Gi0/0
PPPoE: Failed to add PPPoE switching subblock
%DIALER-6-UNBIND: Interface Vi2 unbound from profile Di0
Vi2 PPP: Block vaccess from being freed [0x10]
Vi2 LCP: Event[DOWN] State[Stopping to Starting]
Vi2 PPP: Unlocked by [0x10] Still Locked by [0x0]
Vi2 PPP: Free previously blocked vaccess
Vi2 PPP: Phase is DOWN
%LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down
%LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down
PPPoE: Unexpected Event!. PPPoE switching Subblockdestroy called
%SYS-5-CONFIG_I: Configured from console by admin-boekell on vty0 (10.64.2.142)

Peter Paluch · ‎01-16-2015

Hi,

My personal impression from what I see here is that your router tries to obtain its own IP address from ISP, and for some reason, ISP is unable to provide an IP address. After some time, your router gives up.

Specifically, your router tries to negotiate its own IP address by sending out a CONFREQ with the IP set to 0.0.0.0. Normally, this would elicit a CONFNAK response from the ISP containing the suggested IP address, and your router would repeat the CONFREQ request now with the assigned IP address.

However, in the debug you have provided, the initial CONFREQ has to be re-sent multiple times before a response arrives, and the response is a CONFREJ, totally dismissing your router's attempt at obtaining an IP address. It almost seems as if the ISP had troubles contacting its DHCP server or another mechanism to allocate an IP address to you, and after a timeout, ISP resorts to CONFREJ messages.

To me, this seems to be an issue caused by your ISP, and I personally suggest going over this debug with them. Without either knowing what static IP address you need to use, or the ISP being able to provide you with a negotiated IP address, the link does not appear to be willing to come up.

Best regards,
Peter

Dimitris Kotsilis · ‎03-13-2015

Hi,

After Upgrading one of my BNG routers to 3.13.2S I noticed this issue for PPP sessions coming from specific CPEs. Those CPEs seemed to send more than 10 PPP packets which is the default throttling value, so the PPP negotiation was entering the blocking state for 30 seconds (the default blocking time):

Vi2 PPP: Control packet rate limit 10 reached
Vi2 PPP: Entering block state for 30 seconds
Vi2 PPP: Packet throttled, Dropping packet

During this blocking period, the PPP packets are being dropped, so that's the reason the session cannot be established.

I assume that the default values have been changed in the latest version, causing issues to sessions that in previous versions didn't have this issue.

I have found the ppp packet throttle command that gives you the opportunity to change the default values. Unfortunately I can't find any document describing the variables in order to tune it exactly as I would like (I am informing Cisco about that), but by playing with the values and the help in the CLI I increased the rate limit and the sessions can be established normally.

EDIT no1: After playing with some values, I have found that in 3.13.2S the default values are ppp packet throttle 10 1 30. In 3.7.4S this is not the default (I am not willing to try all possible combinations in order to find the default values though ;) ). The fact is that the default values have been changed.

EDIT no2: After some investigation with Cisco guys: DDTS CSCuo88855 changed the default behavior for ppp packet throttling to be more aggressive. It is still private DDTS, I don't know if it will become public.

Hope this will help you.

Dimitris

mkhalil10 · ‎07-29-2015

Hi Dimitris

Thanks for the information above , I have almost the same issue

What am looking for now , is what are the default values for the ppp packet throttle?

Thanks

BR,

Mohammad

Dimitris Kotsilis · ‎07-29-2015

Hi Mohammad,

During our investigation with Cisco, we got the following info:

before CSCuo88855
the defaults are 10000 packets in 3600 sec with no blocking (ppp packet throttle 10000 3600 0)

after CSCuo88855
the defaults are 10 packets in 1 sec with 30 seconds blocking (ppp packet throttle 10 1 30)

As you can see, before the change, the throttling was practically inactive. After the change, the default values are quite aggressive.

Hope it helps you.

Regards,

Dimitris

mkhalil10 · ‎07-29-2015

Hi Dimitris

Thanks for the kind reply , what drove me to investigate this is a strange issue we faced with our clients

I started a new topic for it in the below link , I will appreciate if you have the time to look at it

https://supportforums.cisco.com/discussion/12568991/pppoe-ppp-packet-throttle#comment-10678686

Thanks again

BR,

Mohammad

PPP - PPPOE connection failing