Mailing List Archive: Re: [c-nsp] PPP fails with IOS upgrade

Aaron --

Because a number of test calls from the telco hit this box, some of the debug commands you suggested produce tons of output, and it's difficult to tell which call is which. I'll get the other debug commands for you, but in the meantime here is the difference between the two IOS's for two of the commands.

debug dhcp
debug ip peer

Old IOS (call works)
voiptrunks#
011465: Aug 24 13:55:01.964: As2/43: Pools to search : nas-ip-pool
011466: Aug 24 13:55:01.964: As2/43: Pool nas-ip-pool returned address = 216.24.0.193
011467: Aug 24 13:55:01.964: DHCP: look up prim NBNS for As2/43 from any any ret: fail
011468: Aug 24 13:55:01.964: DHCP: look up sec NBNS for As2/43 from any any ret: fail
011469: Aug 24 13:55:02.168: As2/43 IPCP: Install route to 216.24.0.193
011470: Aug 24 13:55:02.168: As2/43 IPCP: Add link info for cef entry 216.24.0.

New IOS (call fails)
voiptrunks#
000055: Aug 24 14:03:17.050: As2/01: Pools to search : nas-ip-pool
000056: Aug 24 14:03:17.050: As2/01: Invoking POOL_GET: nas-ip-pool
000057: Aug 24 14:03:17.050: As2/01: Returned from POOL_GET: nas-ip-pool
000058: Aug 24 14:03:17.050: As2/01: Pool nas-ip-pool returned address = 216.24.0.193
000059: Aug 24 14:03:34.547: %MODEMCALLRECORD-6-PM_TERSE_CALL_FAILED_RECORD: DS0 slot/contr/chan=1/0/1, slot/port=2/3, call_id=4, calling=8664297605, called=5027454691, time=0, finl-state=Link, disc(modem)=1F06 <unknown>/Requested by host/network indicated disconnect

Here is the output of "show users" under the new IOS while the calling PC is showing "registering your computer on the network" and eventually timing out.

voiptrunks#show users
Line User Host(s) Idle Location
* 0 con 0 admin idle 00:00:00
tty 2/01 launchpad@ Async interface 00:00:01 PPP: 216.24.0.193

Interface User Mode Idle Peer Address

voiptrunks#

Here is the "show run" output. The box has two circuits in it. One is a standard PRI, the other is a telco interconnection trunk controlled by a softswitch communicating with IUA/SCTP. Both circuits work fine under the old IOS, but have calls fail in the exact same way under the new IOS.

voiptrunks#show run
Building configuration...

Current configuration : 10771 bytes
!
! Last configuration change at 14:07:05 EDT Mon Aug 24 2009
!
version 12.2
no service pad
service telnet-zeroidle
service tcp-keepalives-in
service tcp-keepalives-out
service timestamps debug datetime msec localtime
service timestamps log datetime msec localtime
service password-encryption
service linenumber
service sequence-numbers
no service dhcp
!
hostname voiptrunks
!
boot system flash:c5400-js-mz.122-16.T17.bin
no boot startup-test
logging queue-limit 100
logging buffered 262144 debugging
logging rate-limit 10000 except debugging
no logging console
enable secret 5 xxxxx
!
username admin password 7 094D4A04100B46
!
!
resource-pool enable
!
resource-pool group resource data
range port 2/0 2/47
!
resource-pool group resource office
range port 2/48 2/107
!
resource-pool group resource fax
range port 3/0 3/5
!
resource-pool group resource nulldnis
range port 3/6 3/47
!
resource-pool profile customer data
limit base-size all
limit overflow-size 0
resource data speech
dnis group data
!
resource-pool profile customer office
limit base-size all
limit overflow-size 0
resource office speech
dnis group office
!
resource-pool profile customer fax
limit base-size all
limit overflow-size 0
resource fax speech service fax
dnis group fax
!
resource-pool profile customer nulldnis
limit base-size all
limit overflow-size 0
resource nulldnis speech service nulldnis
dnis group default
!
resource-pool profile service fax
!
resource-pool profile service nulldnis
!
resource-pool profile service office
clock timezone EST -5
clock summer-time EDT recurring
clock calendar-valid
tdm clock priority 1 1/0
tdm clock priority 2 1/1
calltracker enable
calltracker history max-size 200
calltracker history retain-mins 60
calltracker call-record verbose quiet
spe country usa
!
spe call-record modem
!
spe default-firmware spe-firmware-1
spe 2/00 3/17
firmware location flash:np.8.8.1.spe
!
aaa new-model
!
!
aaa group server radius WinAuthAcct
server 216.24.27.48 auth-port 1812 acct-port 1813
server 216.24.27.49 auth-port 1812 acct-port 1813
server 216.24.27.201 auth-port 1645 acct-port 1646
!
aaa authentication banner ^CRASVOIP
^C
aaa authentication login default local
aaa authentication ppp default local group WinAuthAcct
aaa authorization exec default local none
aaa authorization network default local group WinAuthAcct if-authenticated
aaa accounting delay-start
aaa accounting update newinfo
aaa accounting exec default none
aaa accounting network default start-stop broadcast group WinAuthAcct
aaa session-id common
ip subnet-zero
no ip source-route
ip telnet hidden addresses
ip ftp username launchpad
ip ftp password 7 xxxxxx
ip domain list win.net
ip domain name win.net
ip name-server 216.24.27.3
ip name-server 24.235.0.25
ip name-server 216.24.27.4
!
no ip bootp server
ip cef
ip cef accounting per-prefix non-recursive prefix-length
ip cef traffic-statistics update-rate 30
virtual-profile if-needed
virtual-profile virtual-template 1
multilink virtual-template 1
multilink bundle-name both
async-bootp dns-server 216.24.27.3 24.235.0.25 216.24.27.4
no mpls ldp logging neighbor-changes
isdn switch-type primary-ni
modemcap entry v92:MSC=&FS0=0S29=6S62=0S63=0S21=3
modemcap entry nexport1:MSC=s62=8s63=0s21=15s29=36
modemcap entry winNet:MSC=&FS0=0S10=50S16=100S21=15S23=1S29=12S31=9600S32=2S34=18000S40=10S53=1S54=128S62=10S63=1S64=0S78=1
modemcap entry test4:MSC=&F&D2s16=200s32=0
modemcap entry 7xx:MSC=&FS0=0S10=5S19=6S21=15S29=12S31=9600S38=5S39=6S40=6S50=56000S59=6S62=10S63=3S64=0
modemcap entry 8xx:MSC=&FS0=0S62=8S63=0S21=15S29=12S34=18000S10=50S40=10
modemcap entry valuelinx:MSC=&FS0=0S10=50S16=100S21=15S23=1S29=12S31=9600S32=2S34=18000S40=10S53=1S54=128S62=10S63=1S64=0S78=1
modemcap entry new:MSC=&FS0=0S29=6S21=3Q2
!
voice rtp send-recv
!
voice service voip
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback none
h323
!
voice class codec 1
codec preference 1 g711ulaw
codec preference 2 g711alaw
codec preference 3 g723r63
codec preference 4 g723r53
!
!
!
voice class h323 1
!
!
!
!
!
no voice hpi capture buffer
no voice hpi capture destination
!
voice translation-rule 10
rule 1 /^./ //
!
!
voice translation-profile digitstrip
translate called 10
!
!
!
fax interface-type fax-mail
mta receive maximum-recipients 0
!
!
trunk group TransitTrunkGroup
hunt-scheme sequential both down
!
!
trunk group PRITrunkGroup
hunt-scheme sequential both down
!
iua
AS voipAS 216.24.23.80 5000
ASP voipPstn_X AS voipAS 24.235.0.25 7100
ASP voipPstn_Y AS voipAS 216.24.27.244 7100
!
!
controller T1 1/0
framing esf
linecode b8zs
pri-group timeslots 1-24 nfas_d primary nfas_int 0 nfas_group 1 iua voipAS
description nfas circuit with virtual DChannel, controlled by external MGC (AMSS softswitch). Networking over iua/SCTP port 5000.
!
controller T1 1/1
framing esf
linecode b8zs
pri-group timeslots 1-24
description Global Crossing 800 PRI (Bellsouth copper shelf slot 1)
!
controller T1 1/2
shutdown
framing sf
linecode ami
!
controller T1 1/3
shutdown
framing sf
linecode ami
!
controller T1 1/4
shutdown
framing sf
linecode ami
!
controller T1 1/5
framing esf
linecode b8zs
!
controller T1 1/6
shutdown
framing sf
linecode ami
!
controller T1 1/7
shutdown
framing esf
linecode b8zs
!
!
interface Loopback100
no ip address
!
interface FastEthernet0/0
ip address 216.24.23.80 255.255.255.192
ip verify unicast reverse-path
no ip route-cache
no ip mroute-cache
duplex full
speed 100
no cdp enable
!
interface FastEthernet0/1
no ip address
ip access-group 100 in
ip access-group 101 out
no ip route-cache
no ip mroute-cache
shutdown
duplex auto
speed auto
no cdp enable
!
interface Serial0/0
no ip address
ip access-group 100 in
ip access-group 101 out
ip verify unicast reverse-path
no ip route-cache
no ip mroute-cache
clockrate 2000000
no cdp enable
!
interface Serial1/0
no ip address
shutdown
!
interface Serial0/1
no ip address
ip access-group 100 in
ip access-group 101 out
ip verify unicast reverse-path
no ip route-cache
no ip mroute-cache
clockrate 2000000
no cdp enable
!
interface Serial1/1:23
ip unnumbered FastEthernet0/0
ip verify unicast reverse-path
encapsulation ppp
timeout absolute 720 0
dialer idle-timeout 1800
trunk-group PRITrunkGroup
isdn switch-type primary-5ess
isdn incoming-voice modem
isdn bchan-number-order ascending
peer default ip address pool nas-ip-pool
no cdp enable
ppp max-bad-auth 4
ppp authentication pap chap callin
ppp multilink
ppp timeout retry 5
!
interface Virtual-Template1
mtu 1514
ip unnumbered FastEthernet0/0
ip verify unicast reverse-path
timeout absolute 720 0
peer default ip address pool nas-ip-pool
compress stac
ppp max-bad-auth 4
ppp authentication pap chap callin
ppp multilink
ppp timeout retry 5
!
interface Dchannel1/0
no ip address
encapsulation ppp
dialer idle-timeout 1800
trunk-group TransitTrunkGroup
isdn timer t309 100
isdn timer t321 30000
isdn incoming-voice modem
isdn T303 20000
isdn T203 10000
isdn negotiate-bchan resend-setup
isdn bchan-number-order ascending
no cdp enable
!
interface Group-Async0
bandwidth 56
ip unnumbered FastEthernet0/0
encapsulation ppp
no ip mroute-cache
timeout absolute 86400 0
dialer in-band
dialer idle-timeout 1800
dialer-group 1
async mode interactive
peer default ip address pool nas-ip-pool
no keepalive
ppp max-bad-auth 4
ppp authentication pap callin
ppp multilink
ppp timeout retry 5
group-range 2/00 2/47
!
interface Group-Async1
no ip address
no ip mroute-cache
no peer default ip address
no fair-queue
group-range 2/48 3/107
!
ip local pool nas-ip-pool 216.24.0.193 216.24.0.254
ip classless
ip route 0.0.0.0 0.0.0.0 216.24.23.65
no ip http server
!
!
!
logging trap debugging
logging source-interface FastEthernet0/0
!
dialer dnis group data
range 5020000000 5025678799
range 5025678801 5025678997
range 5025679000 5025679899
range 5025680000 5028149999
range 5028160000 5029999999
number 8008001482
!
dialer dnis group office
number 50256799..
number 8008151482
number 5028157...
!
dialer dnis group fax
number 5025678999
dialer-list 1 protocol ip permit
no cdp run
!
!
snmp-server community baw10ls. RO 2
snmp-server community Glftcno. RW 2
snmp-server enable traps tty
!
radius-server attribute nas-port format c
radius-server host 216.24.27.203 auth-port 1645 acct-port 1646
radius-server host 216.24.27.204 auth-port 1645 acct-port 1646
radius-server host 216.24.27.205 auth-port 1645 acct-port 1646
radius-server host 216.24.27.206 auth-port 1645 acct-port 1646
radius-server host 216.24.27.207 auth-port 1645 acct-port 1646
radius-server host 216.24.27.208 auth-port 1645 acct-port 1646
radius-server host 216.24.27.209 auth-port 1645 acct-port 1646
radius-server host 216.24.27.200 auth-port 1645 acct-port 1646
radius-server host 216.24.27.201 auth-port 1645 acct-port 1646
radius-server host 216.24.27.202 auth-port 1645 acct-port 1646
radius-server retransmit 0
radius-server timeout 3
radius-server deadtime 2
radius-server key 7 151F5B5C077A3C7270636C
radius-server authorization permit missing Service-Type
radius-server vsa send accounting
radius-server vsa send authentication
call rsvp-sync
!
voice-port 1/0:D
!
voice-port 1/1:D
!
!
mgcp profile default
!
dial-peer cor custom
!
!
!
dial-peer voice 100 pots
incoming called-number 50256799..
direct-inward-dial
forward-digits all
!
dial-peer voice 110 pots
incoming called-number 5025678800
forward-digits all
!
dial-peer voice 120 pots
incoming called-number 8008151482
forward-digits all
!
dial-peer voice 200 pots
translation-profile outgoing digitstrip
destination-pattern 9..........
port 1/0:D
!
dial-peer voice 210 pots
trunkgroup TransitTrunkGroup
translation-profile outgoing digitstrip
destination-pattern 8..........
!
dial-peer voice 220 pots
translation-profile outgoing digitstrip
destination-pattern 7..........
port 1/1:D
!
dial-peer voice 230 pots
trunkgroup PRITrunkGroup
translation-profile outgoing digitstrip
destination-pattern 6..........
!
dial-peer voice 300 voip
incoming called-number 50256799..
destination-pattern 50256799..
voice-class h323 1
session target ipv4:216.24.23.79
codec g711ulaw
!
!
!
line con 0
exec-timeout 0 0
password 7 120D561A02075F0521
line aux 0
logging synchronous
line vty 0 4
exec-timeout 0 0
password 7 xxxxxxxxxxxxx
line vty 5
line 2/00 2/47
no flush-at-activation
modem InOut
modem autoconfigure type 8xx
autoselect during-login
autoselect ppp
line 2/48 3/107
no flush-at-activation
no modem InOut
!
scheduler allocate 10000 400
ntp clock-period 17179937
ntp update-calendar
ntp server 216.24.27.41 prefer
ntp server 216.24.27.2
end

voiptrunks#

> The PPP debug is of interest; the call connects, an address is taken
> from the pool, and PPP should start negotiating. Either it's not
> starting at all (most likely I believe) or it's not able to
negotiate.

What would prevent PPP from starting up?

I'm reattaching the ppp debug from the first message I sent under this
subject header. Where in this process is PPP normally starting? This
is the output of ppp events, error, and negotiation. The first example
is the old IOS, which works. The second is the newer IOS, and you can
see where it fails.

With IOS c5400-js-mz.122-16.T17.bin

005248: Aug 23 12:00:14.918: As2/42 LCP: Lower layer not up, Fast
Starting
005249: Aug 23 12:00:14.918: As2/42 PPP: Using dialer call direction
005250: Aug 23 12:00:14.918: As2/42 PPP: Treating connection as a
callin
005251: Aug 23 12:00:14.918: As2/42 PPP: Phase is ESTABLISHING,
Passive Open
005252: Aug 23 12:00:14.918: As2/42 LCP: State is Listen
[...]
005299: Aug 23 12:00:15.174: As2/42 PAP: Authenticating peer
launchpad@win.net
005300: Aug 23 12:00:15.174: As2/42 PPP: Phase is FORWARDING,
Attempting Forward
005301: Aug 23 12:00:15.174: As2/42 EVT: Hook 1 0x00000000
005302: Aug 23 12:00:15.174: As2/42 EVT: Hook 1 0x00000000
005303: Aug 23 12:00:15.174: As2/42 EVT: Forwarded 0 0x00000000
005304: Aug 23 12:00:15.174: As2/42 PPP: Phase is AUTHENTICATING,
Unauthenticated User
005305: Aug 23 12:00:15.230: As2/42 EVT: AAA Response 0 0x6387270C
005306: Aug 23 12:00:15.230: As2/42 PPP: Phase is FORWARDING,
Attempting Forward
005307: Aug 23 12:00:15.230: As2/42 EVT: Hook 1 0x00000000
005308: Aug 23 12:00:15.230: As2/42 EVT: Forwarded 0 0x00000000
005309: Aug 23 12:00:15.230: As2/42 PPP: Phase is AUTHENTICATING,
Authenticated User
005310: Aug 23 12:00:15.230: As2/42 EVT: AAA Response 0 0x64BBD314
005311: Aug 23 12:00:15.230: As2/42 PAP: O AUTH-ACK id 27 len 5
005312: Aug 23 12:00:15.234: As2/42 PPP: Phase is UP
[...]
005361: Aug 23 12:00:15.550: As2/42 IPCP: Add link info for cef entry
216.24.0.207

With IOS c5400-js-mz.123-13b.bin

000835: Aug 23 12:15:59.328: As2/46 LCP: Lower layer not up, Fast
Starting
000836: Aug 23 12:15:59.328: As2/46 PPP: Using dialer call direction
000837: Aug 23 12:15:59.328: As2/46 PPP: Treating connection as a
callin
000838: Aug 23 12:15:59.328: As2/46 PPP: Session handle[D0000062]
Session id[0]
000839: Aug 23 12:15:59.328: As2/46 PPP: Phase is ESTABLISHING,
Passive Open
000840: Aug 23 12:15:59.328: As2/46 LCP: State is Listen
[...]
000887: Aug 23 12:15:59.576: As2/46 PAP: Authenticating peer
launchpad@win.net
000888: Aug 23 12:15:59.576: As2/46 PPP: Phase is FORWARDING,
Attempting Forward
000889: Aug 23 12:15:59.576: As2/46 EVT: Hook 1 0x00000000
000890: Aug 23 12:15:59.580: As2/46 EVT: Forwarded 0 0x00000000
000891: Aug 23 12:15:59.580: As2/46 PPP: Phase is AUTHENTICATING,
Unauthenticated User
000892: Aug 23 12:15:59.584: As2/46 EVT: AAA Response 0 0x64DFF388
000893: Aug 23 12:15:59.584: As2/46 PPP: Phase is FORWARDING,
Attempting Forward
000894: Aug 23 12:15:59.584: As2/46 EVT: Hook 1 0x00000000
000895: Aug 23 12:15:59.584: As2/46 EVT: Forwarded 0 0x00000000
000896: Aug 23 12:15:59.584: As2/46 PPP: Phase is AUTHENTICATING,
Authenticated User
000897: Aug 23 12:15:59.584: As2/46 EVT: AAA Response 0 0x64E0A3EC
000898: Aug 23 12:15:59.584: As2/46 EVT: AAA Response 0 0x64DDA8F8
000899: Aug 23 12:15:59.588: As2/46 PAP: O AUTH-ACK id 30 len 5
000900: Aug 23 12:15:59.700: As2/46 EVT: Packet 0 0x62AC4B40
000901: Aug 23 12:15:59.700: As2/46 PPP: Queue CCP code[1] id[4]
000902: Aug 23 12:15:59.700: As2/46 EVT: IPCP Packet 0 0x62AC7508
000903: Aug 23 12:15:59.700: As2/46 PPP: Queue IPCP code[1] id[5]
000904: Aug 23 12:16:01.328: As2/46 EVT: IPCP Packet 0 0x62AC98D8
000905: Aug 23 12:16:01.328: As2/46 PPP: Update queued IPCP code[1]
id[6]
000906: Aug 23 12:16:01.328: As2/46 EVT: Packet 0 0x62AC9BD4
000907: Aug 23 12:16:01.328: As2/46 PPP: Update queued CCP code[1]
id[7]
000908: Aug 23 12:16:04.328: As2/46 EVT: IPCP Packet 0 0x62AD4EE4
000909: Aug 23 12:16:04.328: As2/46 PPP: Update queued IPCP code[1]
id[8]
[...]

_______________________________________________
cisco-nas mailing list
cisco-nas@puck.nether.net
https://puck.nether.net/mailman/listinfo/cisco-nas