Troubleshooting Dial-Out Service


When an outbound call is placed, the output in Example 7-21 is generated from dial-on-demand events and PPP protocol negotiation debugging. The commands that enable this debugging include # debug dialer and # debug ppp negotiation .

Example 7-21. Debug Output of Dialer and PPP Negotiation for an Outgoing Call
[View full width]
 Mar  1 00:11:15.975: As65 DDR: place call Mar  1 00:11:15.975: As65 DDR: Dialing cause ip (s=192.168.0.2, d=216.115.102.82) Mar  1 00:11:15.975: As65 DDR: Attempting to dial 6222230 Mar  1 00:11:15.975: CHAT65: Attempting async line dialer script Mar  1 00:11:15.983: CHAT65: no matching chat script found for 6222230 Mar  1 00:11:15.983: CHAT65: Dialing using Modem script: d0efault-d0ials0cript & System  script: none Mar  1 00:11:15.987: CHAT65: process started Mar  1 00:11:15.987: CHAT65: Asserting DTR Mar  1 00:11:15.987: CHAT65: Chat script d0efault-d0ials0cript started 

To place a call, some interesting traffic must be routed out the async65 interface. In the output shown in Example 7-21, the source address 192.168.0.2 (a host on the Ethernet segment) sent a packet to 216.115.102.82, which caused the router to attempt to dial.

In most cases, you do not need a dial chat script and the default works. The default dial script simply performs the modem AT commands to cause the modem connect and then hands the connection over to the async interface. If the modem does not attempt to dial, check for cabling problems or the correct line configuration. The line must be set for modem InOut and the async interface requires a dialer string. Also, ensure that the phone line is active because without a dial tone the modem cannot dial.

At this point, the modem should train up. Once this is successful, the script ends and the interface changes state to up, as shown in the output in Example 7-22.

Example 7-22. Continuation of Debug from Example 7-21
 Mar  1 00:11:39.731: CHAT65: Chat script d0efault-d0ials0cript finished, status = success 00:11:41: %LINK-3-UPDOWN: Interface Async65, changed state to up Mar  1 00:11:41.735: As65 DDR: Dialer state change to up Mar  1 00:11:41.735: As65 DDR: Dialer call has been placed Mar  1 00:11:41.735: As65 PPP: Treating connection as a callout Mar  1 00:11:41.735: As65 PPP: Phase is ESTABLISHING, Active Open Mar  1 00:11:41.735: As65 PPP: No remote authentication for call-out 

After the interface is up, PPP negotiation takes place. By default with PAP and CHAP, the router attempts to authenticate the remote side, even on outbound calls. However, this router is configured to only authenticate inbound calls and does not authenticate the server that it is dialing into. To configure this, the word callin must be added to the ppp authentication interface configuration command.

From this point, the PPP negotiation is exactly the opposite from the previous section because the router acts as a client, and not as the server. The dial-out router sends an outgoing configuration request to the NAS to advise it has connected, as shown in Example 7-23.

Example 7-23. Debug Output of PPP Outgoing Configuration Request
 Mar  1 00:11:41.739: As65 LCP: O CONFREQ [Closed] id 12 len 20 Mar  1 00:11:41.739: As65 LCP:    ACCM 0x000A0000 (0x0206000A0000) Mar  1 00:11:41.739: As65 LCP:    MagicNumber 0xE0293F01 (0x0506E0293F01) Mar  1 00:11:41.739: As65 LCP:    PFC (0x0702) Mar  1 00:11:41.739: As65 LCP:    ACFC (0x0802) 

Then, the NAS sends the dial-out router a configuration request asking to authenticate through PAP, as shown in Example 7-24.

Example 7-24. Debug Output of Incoming Request for PAP
 Mar  1 00:11:41.915: As65 LCP: I CONFREQ [REQsent] id 253 len 28 Mar  1 00:11:41.915: As65 LCP:    MRU 1500 (0x010405DC) Mar  1 00:11:41.915: As65 LCP:    ACCM 0x000A0000 (0x0206000A0000) Mar  1 00:11:41.919: As65 LCP:    MagicNumber 0x01000000 (0x050601000000) Mar  1 00:11:41.919: As65 LCP:    PFC (0x0702) Mar  1 00:11:41.919: As65 LCP:    ACFC (0x0802) Mar  1 00:11:41.919: As65 LCP:    AuthProto PAP (0x0304C023) 

The router responds to the configuration request for PAP with a configuration acknowledgment, as shown in Example 7-25.

Example 7-25. Debug Output of Outgoing Acknowledgment for PAP
 Mar  1 00:11:41.919: As65 LCP: O CONFACK [REQsent] id 253 len 28 Mar  1 00:11:41.919: As65 LCP:    MRU 1500 (0x010405DC) Mar  1 00:11:41.919: As65 LCP:    ACCM 0x000A0000 (0x0206000A0000) Mar  1 00:11:41.919: As65 LCP:    MagicNumber 0x01000000 (0x050601000000) Mar  1 00:11:41.919: As65 LCP:    PFC (0x0702) Mar  1 00:11:41.919: As65 LCP:    ACFC (0x0802) Mar  1 00:11:41.919: As65 LCP:    AuthProto PAP (0x0304C023) 

The NAS then responds with a configuration acknowledgment and LCP is complete, as shown in Example 7-26.

Example 7-26. Debug Output of Incoming Acknowledgment for PAP
 Mar  1 00:11:41.923: As65 LCP: I CONFACK [ACKsent] id 12 len 20 Mar  1 00:11:41.923: As65 LCP:    ACCM 0x000A0000 (0x0206000A0000) Mar  1 00:11:41.927: As65 LCP:    MagicNumber 0xE0293F01 (0x0506E0293F01) Mar  1 00:11:41.927: As65 LCP:    PFC (0x0702) Mar  1 00:11:41.927: As65 LCP:    ACFC (0x0802) Mar  1 00:11:41.927: As65 LCP: State is Open 

After the LCP phase is completed, the router and NAS start authentication. First, the router sends an outgoing authentication request with the username and password. The following shows the username in the debug output:

 Mar  1 00:11:41.927: As65 PPP: Phase is AUTHENTICATING, by the peer Mar  1 00:11:41.927: As65 PAP: O AUTH-REQ id 1 len 37 from "jhuegen" 

Next, the router receives an incoming authentication acknowledgment, which indicates that authentication is successful. If authentication had failed, a NAK would have been received along with a reason, which is usually authentication failure:

 Mar  1 00:11:43.883: As65 PAP: I AUTH-ACK id 1 len 5 

The following output shows that authentication is now complete, and the router moves on to the NCP stage of PPP negotiation:

 Mar  1 00:11:43.883: As65 PPP: Phase is FORWARDING, Attempting Forward Mar  1 00:11:43.887: As65 PPP: Phase is ESTABLISHING, Finish LCP Mar  1 00:11:43.887: As65 PPP: Phase is UP 

The router now sends an outgoing configuration request stating its intent to use IP address 0.0.0.0. The router expects this request will be refused and a real address will be assigned to it:

 Mar  1 00:11:43.887: As65 IPCP: O CONFREQ [Closed] id 1 len 10 Mar  1 00:11:43.887: As65 IPCP:    Address 0.0.0.0 (0x030600000000) 

Next, the dial-out router receives an incoming configuration request to use VJ 15 header compression. Also in this configuration request, the NAS sends its IP address:

 Mar  1 00:11:43.891: As65 IPCP: I CONFREQ [REQsent] id 254 len 16 Mar  1 00:11:43.895: As65 IPCP:    CompressType VJ 15 slots CompressSlotID (0x0206002D0F01) Mar  1 00:11:43.895: As65 IPCP:    Address 216.192.135.254 (0x0306D8C087FE) 

The router then rejects the header compression, and by doing so it rejects the IP address of the NAS. This is sent back to the dial-out router another time without the compression request:

 Mar  1 00:11:43.895: As65 IPCP: O CONFREJ [REQsent] id 254 len 10 Mar  1 00:11:43.895: As65 IPCP:    CompressType VJ 15 slots CompressSlotID (0x0206002D0F01) 

The NAS rejects the requested IP address of 0.0.0.0 and offers 216.192.135.145 to the router for use:

 Mar  1 00:11:44.007: As65 IPCP: I CONFNAK [REQsent] id 1 len 10 Mar  1 00:11:44.007: As65 IPCP:    Address 216.192.135.145 (0x0306D8C08791) 

In return, the router requests that the NAS allow it to use the address it offered in the previous configuration request:

 Mar  1 00:11:44.007: As65 IPCP: O CONFREQ [REQsent] id 2 len 10 Mar  1 00:11:44.007: As65 IPCP:    Address 216.192.135.145 (0x0306D8C08791) 

The NAS then resends its IP address to the router; this time without requesting header compression:

 Mar  1 00:11:44.011: As65 IPCP: I CONFREQ [REQsent] id 255 len 10 Mar  1 00:11:44.011: As65 IPCP:    Address 216.192.135.254 (0x0306D8C087FE) 

The dial-out router replies and acknowledges the IP address of the NAS as follows :

 Mar  1 00:11:44.015: As65 IPCP: O CONFACK [REQsent] id 255 len 10 Mar  1 00:11:44.015: As65 IPCP:    Address 216.192.135.254 (0x0306D8C087FE) 

Next, the NAS acknowledges the requested IP address of the dial-out router, which it offered to the router in the first place:

 Mar  1 00:11:44.123: As65 IPCP: I CONFACK [ACKsent] id 2 len 10 Mar  1 00:11:44.123: As65 IPCP:    Address 216.192.135.145 (0x0306D8C08791) 

Finally, the NCP state of PPP negotiation is completed, as signaled by the State is Open statement:

 Mar  1 00:11:44.123: As65 IPCP: State is Open Mar  1 00:11:44.123: As65 IPCP: Install negotiated IP interface address 216.192.135.145 

NOTE

The router did not request DNS and WINS server information. It is configured this way because there is no way to automatically provide negotiated information to PCs upon connection. Therefore, this information was obtained ahead of time, and statically configured into the Dynamic Host Configuration Protocol (DHCP) server in the router.


When PPP is up, the router forwards the packets it was holding in the dialer hold-queue during the train-up, authentication, and PPP negotiation phases to their destination. The router also installs a route to the peer on the other end of the connection, as shown in the third line of the output:

 Mar  1 00:11:44.127: As65 DDR: dialer protocol up Mar  1 00:11:44.127: As65 DDR: Call connected, 5 packets unqueued, 5 transmitted, 0 discarded Mar  1 00:11:44.131: As65 IPCP: Install route to 216.192.135.254 00:11:44: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async65, changed state to up 

The command show ip interface brief shows the async interface with its negotiated IP address, and the method by which this IP address was received. Because in this case the IP address is a result of successful PPP negotiation, it shows IPCP as the method. This command and output is demonstrated in Example 7-27.

Example 7-27. Output of show ip interface brief
 Router#  show ip interface brief  Interface                  IP-Address      OK? Method Status          Protocol Async65                    216.192.135.145 YES IPCP   up              up Ethernet0/0                192.168.0.1     YES NVRAM  up              up 

If PPP does not fully negotiate, it is most likely not caused by a LCP timeout issue on the NAS site. This is because a line speed issue prevents the modem from dialing in the first place. If you receive LCP timeouts as covered in the section, "Troubleshooting Dial-In Service," the service provider is most likely the source of the issue.

Another issue is an authentication problem caused when the username and password combination fails. If this occurs, reconfigure the username and password and, if necessary, verify it with the provider.

The last issue that can cause problems is the router trying to authenticate the NAS. Because the router is the connecting party, and no provider allows a connecting party to authenticate them (unless this is arranged in advance), check the configuration for ppp authentication type . This command should not be included in the async interface configuration because it will try to authenticate the NAS. If this is the case, your debug should display the output, as shown in Example 7-28.

Example 7-28. Authentication Type Mismatch
 Mar  1 00:09:29.507: As65 LCP: O CONFREQ [ACKsent] id 2 len 24 Mar  1 00:09:29.511: As65 LCP:    ACCM 0x000A0000 (0x0206000A0000) Mar  1 00:09:29.511: As65 LCP:    AuthProto PAP (0x0304C023) Mar  1 00:09:29.511: As65 LCP:    MagicNumber 0xE0273903 (0x0506E0273903) Mar  1 00:09:29.511: As65 LCP:    PFC (0x0702) Mar  1 00:09:29.511: As65 LCP:    ACFC (0x0802) Mar  1 00:09:29.827: As65 LCP: I CONFREJ [ACKsent] id 2 len 8 Mar  1 00:09:29.831: As65 LCP:    AuthProto PAP (0x0304C023) Mar  1 00:09:29.831: As65 LCP: O CONFREQ [ACKsent] id 3 len 24 Mar  1 00:09:29.831: As65 LCP:    ACCM 0x000A0000 (0x0206000A0000) Mar  1 00:09:29.831: As65 LCP:    AuthProto PAP (0x0304C023) Mar  1 00:09:29.831: As65 LCP:    MagicNumber 0xE0273903 (0x0506E0273903) Mar  1 00:09:29.831: As65 LCP:    PFC (0x0702) Mar  1 00:09:29.831: As65 LCP:    ACFC (0x0802) Mar  1 00:09:30.083: As65 LCP: I CONFREJ [ACKsent] id 3 len 8 Mar  1 00:09:30.083: As65 LCP:    AuthProto PAP (0x0304C023) 

In the debug in Example 7-28, the router requests PAP authentication from the NAS. The NAS rejects the request, and because authentication is required, the router requests it again. This process continues in a loop until the router is disconnected for exceeding the connect timer.




Troubleshooting Remote Access Networks CCIE Professional Development
Troubleshooting Remote Access Networks (CCIE Professional Development)
ISBN: 1587050765
EAN: 2147483647
Year: 2002
Pages: 235

flylib.com © 2008-2017.
If you may any questions please contact us: flylib@qtcs.net