[c-nsp] Cisco 7606S PPP Multilink issues

James Edmondson biged7600 at gmail.com
Fri Apr 24 13:20:04 EDT 2009


I have a Cisco 7606S router with 8 port spa T1 card, running ios version:
c7600rsp72043-adventerprisek9-mz.122-33.SRC1.bin

Right now i have 2 T1's coming in on the same chassis and we are trying to
use PPP Multilink.  The far end equipment is a Cisco 7206 router with IOS
version: c7200-p-mz.123-19.bin

When we enable multilink and place the T1s in the ppp multilink group, the
T1's are up/up, the multilink interface is up/up, however no traffic passes
over the multilink, you cant ping the local or remote end multilink ip
address (/30 subnet).

I have tried just putting 1 t1 in the ppp multi group and leaving the other
alone.  When this happens, i get same results; T1 in multilink cant ping and
no traffic, the other t1 not in ppp multilink is up and working fine,
pinging, passing traffic just as expected.

 I have a Cisco case open, however so far its not much help, just want to
ensure proper multilink configuration, which isnt that difficult.

doing a sh ppp multilink - tells me the interfaces are active
debug ppp multilink negeotation tells me:
Apr 24 06:18:02.288: Se2/1/1:1 PPP: Sending cstate UP notification
Apr 24 06:18:02.288: Se2/1/1:1 PPP: Processing CstateUp message
Apr 24 06:18:02.288: PPP: Alloc Context [19321D28]
Apr 24 06:18:02.288: ppp630 PPP: Phase is ESTABLISHING
Apr 24 06:18:02.288: Se2/1/1:1 PPP: Using default call direction
Apr 24 06:18:02.288: Se2/1/1:1 PPP: Treating connection as a dedicated line
Apr 24 06:18:02.288: Se2/1/1:1 PPP: Session handle[FE0000E0] Session id[630]
Apr 24 06:18:02.288: Se2/1/1:1 LCP: Event[OPEN] State[Initial to Starting]
Apr 24 06:18:02.288: Se2/1/1:1 LCP: O CONFREQ [Starting] id 1 len 24
Apr 24 06:18:02.288: Se2/1/1:1 LCP:    MagicNumber 0x68F1815B
(0x050668F1815B)
Apr 24 06:18:02.288: Se2/1/1:1 LCP:    MRRU 1500 (0x110405DC)
Apr 24 06:18:02.288: Se2/1/1:1 LCP:    EndpointDisc 1 RTLOCAL
(0x130A0152543031524D44)
Apr 24 06:18:02.288: Se2/1/1:1 LCP: Event[UP] State[Starting to REQsent]
Apr 24 06:18:02.492: Se2/1/1:1 LCP: I CONFREQ [REQsent] id 89 len 25
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    MagicNumber 0x38221371
(0x050638221371)
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    MRRU 1524 (0x110405F4)
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    EndpointDisc 1 RTREMOTE
(0x130B0152543131304D4E41)
Apr 24 06:18:02.492: Se2/1/1:1 LCP: O CONFACK [REQsent] id 89 len 25
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    MagicNumber 0x38221371
(0x050638221371)
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    MRRU 1524 (0x110405F4)
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    EndpointDisc 1 RTREMOTE
(0x130B0152543131304D4E41)
Apr 24 06:18:02.492: Se2/1/1:1 LCP: Event[Receive ConfReq+] State[REQsent to
ACKsent]
Apr 24 06:18:02.492: Se2/1/1:1 LCP: I CONFACK [ACKsent] id 1 len 24
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    MagicNumber 0x68F1815B
(0x050668F1815B)
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    MRRU 1500 (0x110405DC)
Apr 24 06:18:02.492: Se2/1/1:1 LCP:    EndpointDisc 1 RTLOCAL
(0x130A0152543031524D44)
Apr 24 06:18:02.492: Se2/1/1:1 LCP: Event[Receive ConfAck] State[ACKsent to
Open]
Apr 24 06:18:02.492: Se2/1/1:1 PPP: Phase is FORWARDING, Attempting Forward
Apr 24 06:18:02.492: Se2/1/1:1 LCP: State is Open
Apr 24 06:18:02.492: Se2/1/1:1 PPP: Phase is ESTABLISHING, Finish LCP
Apr 24 06:18:02.492: Se2/1/1:1 MLP: Request add link to bundle
Apr 24 06:18:02.492: Se2/1/1:1 PPP: Phase is VIRTUALIZED
Apr 24 06:18:02.492: Se2/1/1:1 MLP: Adding link to bundle
Apr 24 06:18:02.492: Se2/1/1:1 MLP: Requested bundle Mu1 switching setup
Apr 24 06:18:02.492: Se2/1/1:1 MLP: Determine clone source for SSS
Apr 24 06:18:02.492: Se2/1/1:1 MLP: No cloning source provided, bundle
interface statically configured
Apr 24 06:18:02.492: Se2/1/1:1 MLP: SSS connect, bundle interface Mu1
Apr 24 06:18:02.492: PPP: Alloc Context [193223E8]
Apr 24 06:18:02.492: ppp631 PPP: Phase is ESTABLISHING
Apr 24 06:18:02.492: Mu1 MLP: Changing bundle bandwidth from 1544 to 1544
Apr 24 06:18:02.492: Se2/1/1:1 MLP: Computed frag size 5782 exceeds MTU,
changed to 1496
Apr 24 06:18:02.492: Mu1 MLP: Updated interface delay to 20000 usec
Apr 24 06:18:02.492: Mu1 MLP: Update bundle bandwidth 1544 set 1544
Apr 24 06:18:02.492: Se2/1/1:1 MLP: Change transmit status from Init to
Enabled, transmit links 1
Apr 24 06:18:02.492: DML(sip_mlp_vlan_init,Multilink1): sending vlan update
Apr 24 06:18:02.492:  Sending command 25 to slot 2 hwidb Multilink1
hw_if_index 79  vc = 1048577 slotunit 64, bundle = Multilink1 hw_if_index 79
vc = 1048577  slotunit = 64, direction = 0, interleave = 0 frag = 0
hw_support = 0 new_primary_link 0 acfc 0 pfc 0, mrru 1500
Apr 24 06:18:02.492:  Sending command 27 to slot 2 hwidb Serial2/1/1:1
hw_if_index 75  vc = 1 slotunit 65, bundle = Multilink1 hw_if_index 79 vc =
1048577  slotunit = 64, direction = 3, interleave = 0 frag = 1496 hw_support
= 1 new_primary_link 0 acfc 0 pfc 0, mrru 1500
Apr 24 06:18:02.496: Mu1 MLP: Added first link Se2/1/1:1 to bundle RTREMOTE
Apr 24 06:18:02.496: Mu1 MLP: Received segment updated message for bundle
Apr 24 06:18:02.696: Se2/1/1:1 PPP: Queue IPCP code[1] id[1]
Apr 24 06:18:02.696: Se2/1/1:1 PPP: Discarded CDPCP code[1] id[1]
Apr 24 06:18:02.696: Mu1 PPP: Force LCP OPEN on MLP Bundle
Apr 24 06:18:02.696: Mu1 PPP: Outbound cdp packet dropped, line protocol not
up
Apr 24 06:18:02.696: Mu1 PPP: Outbound ip packet dropped, line protocol not
up
Apr 24 06:18:02.696: Mu1 PPP: Outbound ip packet dropped, line protocol not
up
Apr 24 06:18:02.696: Mu1 PPP: Phase is UP
Apr 24 06:18:02.696: Mu1 IPCP: Protocol configured, start CP. state[Initial]
Apr 24 06:18:02.696: Mu1 IPCP: Event[OPEN] State[Initial to Starting]
Apr 24 06:18:02.696: Mu1 IPCP: O CONFREQ [Starting] id 1 len 10
Apr 24 06:18:02.696: Mu1 IPCP:    Address 10.X.X.X (0x03060AFB276A)
Apr 24 06:18:02.696: Se2/1/1:1 MLP: O data FF03 8021 0101 000A 0306 0AFB
276A
Apr 24 06:18:02.696: Mu1 IPCP: Event[UP] State[Starting to REQsent]
Apr 24 06:18:02.696: Mu1 CDPCP: Protocol configured, start CP.
state[Initial]
Apr 24 06:18:02.696: Mu1 CDPCP: Event[OPEN] State[Initial to Starting]
Apr 24 06:18:02.696: Mu1 CDPCP: O CONFREQ [Starting] id 1 len 4
Apr 24 06:18:02.696: Se2/1/1:1 MLP: O data FF03 8207 0101 0004
Apr 24 06:18:02.696: Mu1 CDPCP: Event[UP] State[Starting to REQsent]
Apr 24 06:18:02.696: Se2/1/1:1 PPP: Process pending ncp packets
Apr 24 06:18:02.696: Se2/1/1:1 IPCP: Redirect packet to Mu1
Apr 24 06:18:02.696: Mu1 IPCP: I CONFREQ [REQsent] id 1 len 10
Apr 24 06:18:02.696: Mu1 IPCP:    Address 10.X.X.X (0x03060AFB2769)
Apr 24 06:18:02.696: Mu1 IPCP: O CONFACK [REQsent] id 1 len 10
Apr 24 06:18:02.696: Mu1 IPCP:    Address 10.X.X.X (0x03060AFB2769)
Apr 24 06:18:02.696: Se2/1/1:1 MLP: O data FF03 8021 0201 000A 0306 0AFB
2769
Apr 24 06:18:02.696: Mu1 IPCP: Event[Receive ConfReq+] State[REQsent to
ACKsent]

Apr 24 06:18:02.860: Se2/1/1:1 MLP: I data FF03 8021 0201 000A 0306 0AFB
276A
Apr 24 06:18:02.860: Se2/1/1:1 MLP: I data FF03 8207 0201 0004
Apr 24 06:18:02.900: Mu1 IPCP: I CONFACK [ACKsent] id 1 len 10
Apr 24 06:18:02.900: Mu1 IPCP:    Address 10.X.X.X (0x03060AFB276A)
Apr 24 06:18:02.900: Mu1 IPCP: Event[Receive ConfAck] State[ACKsent to Open]
Apr 24 06:18:02.900: Mu1 CDPCP: I CONFACK [REQsent] id 1 len 4
Apr 24 06:18:02.900: Mu1 CDPCP: Event[Receive ConfAck] State[REQsent to
ACKrcvd]
Apr 24 06:18:02.908: Mu1 IPCP: State is Open
Apr 24 06:18:02.908: Mu1 IPCP: Add link info for cef entry 10.X.X.X
Apr 24 06:18:02.908: Mu1 IPCP: Install route to 10.X.X.X
Apr 24 06:18:03.696: Mu1 PPP: Outbound cdp packet dropped, NCP not
negotiated
Apr 24 06:18:04.508: Mu1 CDPCP: O CONFREQ [ACKrcvd] id 2 len 4
Apr 24 06:18:04.508: Mu1 CDPCP: Event[Timeout+] State[ACKrcvd to REQsent]
Apr 24 06:18:04.652: Se2/1/1:1 MLP: I data FF03 8207 0102 0004
Apr 24 06:18:04.652: Mu1 CDPCP: I CONFREQ [REQsent] id 2 len 4
Apr 24 06:18:04.652: Mu1 CDPCP: O CONFACK [REQsent] id 2 len 4
Apr 24 06:18:04.652: Mu1 CDPCP: Event[Receive ConfReq+] State[REQsent to
ACKsent]
Apr 24 06:18:04.668: Se2/1/1:1 MLP: I data FF03 8207 0202 0004
Apr 24 06:18:04.668: Mu1 CDPCP: I CONFACK [ACKsent] id 2 len 4
Apr 24 06:18:04.668: Mu1 CDPCP: Event[Receive ConfAck] State[ACKsent to
Open]
Apr 24 06:18:04.700: Mu1 CDPCP: State is Open
Apr 24 06:18:06.880: Se2/1/1:1 MLP: I data FF03 0207 02B4 7717 0001 000C
5254 3131
Apr 24 06:18:07.880: Se2/1/1:1 MLP: I data FF03 0207 02B4 7717 0001 000C
5254 3131


Any help is greatly appreciated!

-- 
James


More information about the cisco-nsp mailing list