HWIC-1ADSL on 2811 - PPPoE error

[Safar Safarov]

Hello gents,

PPPoE goes up and down all the time with the following errors:

PPPoE: Failed to add PPPoE switching subblock
PPPoE: Unexpected Event!. PPPoE switching Subblock destroy called

Router config:

interface ATM0/0/0
no ip address
no atm ilmi-keepalive
pvc 8/35
  pppoe-client dial-pool-number 1
!
!
interface Dialer0
mtu 1492
bandwidth 100000
ip address negotiated
ip nat outside
ip virtual-reassembly in
encapsulation ppp
ip tcp adjust-mss 1452
dialer pool 1
ppp authentication pap callin
ppp pap sent-username 5987131 password 0 5987131
no cdp enable

IOS version:

Cisco IOS Software, 2800 Software (C2800NM-ADVSECURITYK9-M), Version 15.1(3)T, RELEASE SOFTWARE (fc1)

c2800nm-advsecurityk9-mz.151-3.T.bin

Have found the following thread but didn't work for me:

https://supportforums.cisco.com/message/3241483

P.S.: have two more routers with the same setup on other ISP with chap authentication and pvc 0/35 - work perfect.

Any help is appreciated.

[paolo bevilacqua]

Try 15.0(1)M4.

[Safar Safarov]

Tried c2800nm-advsecurityk9-mz.150-1.M4.bin, the same errors...

Any ideas?

[Safar Safarov]

Dear Paolo,

the problem was in MTU & MSS, everything works great with the following config of Dialer 0 interface:

interface Dialer0
bandwidth 100000
ip address negotiated
ip mtu 1452
ip nat outside
ip virtual-reassembly in
encapsulation ppp
ip tcp adjust-mss 1412
dialer pool 1
ppp authentication pap callin
ppp pap sent-username 5987131 password 0 5987131
no cdp enable

Many thanks to your reply and assistance.

[Safar Safarov]

ISP claims that everything works with D-Link ADSL modem and they don't know how Cisco HWIC works at all... hmm... The D-Link modem config is below:

Really no issues with D-Link, but again getting errors on Cisco. Seems that D-Link & Cisco configurations are similar, nevertheless cannot bring it up.

Maybe I'm missing smth in the Cisco config?!

[Safar Safarov]

Did some ppp debugging also:

Feb  3 05:28:11.484: %DIALER-6-BIND: Interface Vi1 bound to profile Di0
Feb  3 05:28:11.488: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
Feb  3 05:28:11.488: Vi1 PPP: Sending cstate UP notification
Feb  3 05:28:11.488: Vi1 PPP: Processing CstateUp message
Feb  3 05:28:11.492: PPP: Alloc Context [470F6240]
Feb  3 05:28:11.492: ppp614 PPP: Phase is ESTABLISHING
Feb  3 05:28:11.492: ppp614 PPP: Using AAA Unique Id = 66D
Feb  3 05:28:11.492: Vi1 PPP: Authorization required
Feb  3 05:28:11.492: Vi1 PPP: Using dialer call direction
Feb  3 05:28:11.492: Vi1 PPP: Treating connection as a callout
Feb  3 05:28:11.492: Vi1 PPP: Session handle[E0000050] Session id[614]
Feb  3 05:28:11.492: Vi1 LCP: Event[OPEN] State[Initial to Starting]
Feb  3 05:28:11.492: Vi1 PPP: No remote authentication for call-out
Feb  3 05:28:11.492: Vi1 LCP: O CONFREQ [Starting] id 1 len 14
Feb  3 05:28:11.492: Vi1 LCP:    MRU 1492 (0x010405D4)
Feb  3 05:28:11.492: Vi1 LCP:    MagicNumber 0x19850293 (0x050619850293)
Feb  3 05:28:11.492: Vi1 LCP: Event[UP] State[Starting to REQsent]
Feb  3 05:28:11.504: Vi1 LCP: I CONFREQ [REQsent] id 1 len 18
Feb  3 05:28:11.504: Vi1 LCP:    MRU 1492 (0x010405D4)
Feb  3 05:28:11.504: Vi1 LCP:    AuthProto PAP (0x0304C023)
Feb  3 05:28:11.504: Vi1 LCP:    MagicNumber 0x6C801BC6 (0x05066C801BC6)
Feb  3 05:28:11.504: Vi1 LCP: O CONFACK [REQsent] id 1 len 18
Feb  3 05:28:11.504: Vi1 LCP:    MRU 1492 (0x010405D4)
Feb  3 05:28:11.504: Vi1 LCP:    AuthProto PAP (0x0304C023)
Feb  3 05:28:11.504: Vi1 LCP:    MagicNumber 0x6C801BC6 (0x05066C801BC6)
Feb  3 05:28:11.504: Vi1 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent]
Feb  3 05:28:11.504: Vi1 LCP: I CONFACK [ACKsent] id 1 len 14
Feb  3 05:28:11.504: Vi1 LCP:    MRU 1492 (0x010405D4)
Feb  3 05:28:11.504: Vi1 LCP:    MagicNumber 0x19850293 (0x050619850293)
Feb  3 05:28:11.504: Vi1 LCP: Event[Receive ConfAck] State[ACKsent to Open]
Feb  3 05:28:11.524: Vi1 PPP: No authorization without authentication
Feb  3 05:28:11.524: Vi1 PPP: Phase is AUTHENTICATING, by the peer
Feb  3 05:28:11.524: Vi1 PAP: Using hostname from interface PAP
Feb  3 05:28:11.524: Vi1 PAP: Using password from interface PAP
Feb  3 05:28:11.524: Vi1 PAP: O AUTH-REQ id 1 len 21 from "5987131"
Feb  3 05:28:11.524: Vi1 LCP: State is Open
Feb  3 05:28:12.880: Vi1 PAP: I AUTH-NAK id 1 len 26 msg is "Authentication failed"
Feb  3 05:28:12.884: Vi1 PPP DISC: We failed authentication
Feb  3 05:28:12.884: PPP: NET STOP send to AAA.
Feb  3 05:28:12.884: Vi1 LCP: I TERMREQ [Open] id 2 len 4
Feb  3 05:28:12.884: Vi1 PPP: Phase is TERMINATING
Feb  3 05:28:12.884: Vi1 LCP: O TERMACK [Open] id 2 len 4
Feb  3 05:28:12.884: Vi1 LCP: Event[Receive TermReq] State[Open to Stopping]
Feb  3 05:28:12.896: %DIALER-6-UNBIND: Interface Vi1 unbound from profile Di0
Feb  3 05:28:12.896: Vi1 PPP: Block vaccess from being freed [0x10]
Feb  3 05:28:12.900: Vi1 LCP: Event[DOWN] State[Stopping to Starting]
Feb  3 05:28:12.900: Vi1 PPP: Unlocked by [0x10] Still Locked by [0x0]
Feb  3 05:28:12.900: Vi1 PPP: Free previously blocked vaccess
Feb  3 05:28:12.900: Vi1 PPP: Phase is DOWN
Feb  3 05:28:12.900: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to down
Feb  3 05:28:12.900: Vi1 PPP: Sending cstate DOWN notification
Feb  3 05:28:12.900: Vi1 PPP: Processing CstateDown message

Authentication failed... hmm. But username & password are 100% correct... will check again.

[Safar Safarov]

After changing MTU to 1452 everything works fine, no PPPoE errors anymore, however ATM shows the following info:

ATM0/0/0
Alcatel 20190 chipset information
                ATU-R (DS)                      ATU-C (US)
Modem Status:    Showtime (DMTDSL_SHOWTIME)
DSL Mode:        ITU G.992.5 (ADSL2+) Annex A
ITU STD NUM:     0x03                            0x2
Chip Vendor ID:  'STMI'                          'IFTN'
Chip Vendor Specific:  0x0000                    0x71B0
Chip Vendor Country:   0x0F                      0xB5
Modem Vendor ID: 'CSCO'                          '    '
Modem Vendor Specific: 0x0000                    0x0000
Modem Vendor Country:  0xB5                      0x00
Serial Number Near:    FOC14473PB7CISCO73993206
Serial Number Far:  Chip ID:     C196 (3)
DFE BOM:         DFE3.0 Annex A (1)
Capacity Used:   15%                             69%
Noise Margin:    30.5 dB                         20.0 dB
Output Power:     7.5 dBm                        11.0 dBm
Attenuation:      5.5 dB                          1.0 dB
FEC ES Errors:    0                               0
ES Errors:        1                               0
SES Errors:       1                               0
LOSES Errors:     1                               0
UES Errors:       0                              29
Defect Status:   None                            None
Last Fail Code:  None
Watchdog Counter: 0xDD
Watchdog Resets: 0
Selftest Result: 0x00
Subfunction:     0x00
Interrupts:      16534 (0 spurious)
PHY Access Err:  0
Activations:     4
LED Status:      OFF
LED On Time:     0
LED Off Time:    0
Init FW:         init_AMR-4.0.015_no_bist.bin
Operation FW:    AMR-4.0.015.bin
FW Source:       embedded
FW Version:      4.0.15

                 DS Channel1      DS Channel0   US Channel1       US Channel0
Speed (kbps):             0             4095             0               894
DS User cells:            0          1016721
US User & Idle cells:                                     0          5247959
Reed-Solomon EC:          0                0             0                 0
CRC Errors:               0                0             0                 0
Header Errors:            0                0             0                 0
Total BER:                0E-0           0E-0
Leakage Average BER:      0E-0           0E-0
Interleave Delay:         0                2             0                56
                        ATU-R (DS)      ATU-C (US)
Bitswap:               enabled            enabled

I tested the speed at speedtest.net, no issues with the speed. But would like to know, what is capacity used value works for?

It shows low values, is it a normal behavior?