I'm having a problem with IP address negotiations at one site. I have
a Linux box (kernel 2.2.12, ppp 2.3.9) calling into various NT RAS
servers (NT 4.0+SP3). I've also seen this problem with kernel 2.2.10
and ppp 2.3.7.
I'm starting pppd with commands of this form:
pppd modem crtscts /dev/ttyD7 115200 10.1.0.8:10.1.0.7 netmask 255.255.0.0 \
idle 300 user xxx remotename chyyy nobsdcomp nodeflate ipparam ttyD7 debug \
connect "chat chat-script"
The address negotiation lines in the syslog look like this when calling
a correctly-configured NT box:
sent [IPCP ConfReq id=0x1 <addr 10.1.0.8> <compress VJ 0f 01>]
rcvd [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 10.1.0.7>]
sent [IPCP ConfAck id=0x2 <compress VJ 0f 01> <addr 10.1.0.7>]
rcvd [IPCP ConfAck id=0x1 <addr 10.1.0.8> <compress VJ 0f 01>]
local IP address 10.1.0.8
remote IP address 10.1.0.7
Each site is assigned a pair of unique, static IP addresses. This is
required in order to establish multiple simultaneous dial-out ppp
links to these sites.
Unfortunately, at one site, someone couldn't resist changing the IP
address settings. When I call that site with the command:
pppd modem crtscts /dev/ttyD7 115200 10.1.0.6:10.1.0.5 netmask 255.255.0.0 \
idle 300 user xxx remotename seyyy nobsdcomp nodeflate ipparam ttyD7 debug \
connect "chat chat-script"
Here's what the address negotiations look like (a complete syslog
follows):
sent [IPCP ConfReq id=0x1 <addr 10.1.0.6> <compress VJ 0f 01>]
rcvd [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 10.0.0.21>]
sent [IPCP ConfNak id=0x2 <addr 10.1.0.5>]
rcvd [IPCP ConfAck id=0x1 <addr 10.1.0.6> <compress VJ 0f 01>]
rcvd [IPCP ConfReq id=0x4 <compress VJ 0f 01> <addr 10.0.0.21>]
sent [IPCP ConfNak id=0x4 <addr 10.1.0.5>]
rcvd [IPCP ConfReq id=0x5 <compress VJ 0f 01> <addr 10.0.0.21>]
sent [IPCP ConfNak id=0x5 <addr 10.1.0.5>]
rcvd [IPCP ConfReq id=0x6 <compress VJ 0f 01> <addr 10.0.0.21>]
sent [IPCP ConfNak id=0x6 <addr 10.1.0.5>]
rcvd [IPCP ConfReq id=0x7 <compress VJ 0f 01> <addr 10.0.0.21>]
sent [IPCP ConfNak id=0x7 <addr 10.1.0.5>]
rcvd [IPCP ConfReq id=0x8 <compress VJ 0f 01> <addr 10.0.0.21>]
sent [IPCP ConfRej id=0x8 <addr 10.0.0.21>]
rcvd [IPCP ConfReq id=0x9 <compress VJ 0f 01>]
sent [IPCP ConfAck id=0x9 <compress VJ 0f 01>]
local IP address 10.1.0.6
remote IP address 10.1.0.5
The remote address, 10.1.0.5, is never Ack'd. Yet pppd proceeds as if
everything is fine. Of course, I cannot send packets to 10.1.0.5.
Here's the complete syslog:
Sep 17 14:19:15 cm pppd[4072]: pppd 2.3.9 started by nobody, uid 99
Sep 17 14:19:51 cm pppd[4072]: Serial connection established.
Sep 17 14:19:51 cm pppd[4072]: Using interface ppp0
Sep 17 14:19:51 cm pppd[4072]: Connect: ppp0 <--> /dev/ttyD7
Sep 17 14:19:52 cm pppd[4072]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic
0x24745ca> <pcomp> <accomp>]
Sep 17 14:19:52 cm pppd[4072]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap
m$oft> <magic 0x7d91> <pcomp> <accomp>]
Sep 17 14:19:52 cm pppd[4072]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap
m$oft> <magic 0x7d91> <pcomp> <accomp>]
Sep 17 14:19:52 cm pppd[4072]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic
0x24745ca> <pcomp> <accomp>]
Sep 17 14:19:52 cm pppd[4072]: rcvd [CHAP Challenge id=0x1f <c0286899a4f159d6>, name =
""]
Sep 17 14:19:52 cm pppd[4072]: sent [CHAP Response id=0x1f
<000000000000000000000000000000000000000000000000213e39ddcd75494184e06c88af1faec97cc6b3c1aaac7dd801>,
name = "hbscs"]
Sep 17 14:19:53 cm pppd[4072]: rcvd [CHAP Success id=0x1f ""]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfReq id=0x1 <addr 10.1.0.6> <compress VJ
0f 01>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [CCP ConfReq id=0x1 < 12 06 00 00 00 01>]
Sep 17 14:19:53 cm pppd[4072]: sent [CCP ConfReq id=0x1]
Sep 17 14:19:53 cm pppd[4072]: sent [CCP ConfRej id=0x1 < 12 06 00 00 00 01>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr
10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfNak id=0x2 <addr 10.1.0.5>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfAck id=0x1 <addr 10.1.0.6> <compress VJ
0f 01>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [CCP ConfAck id=0x1]
Sep 17 14:19:53 cm pppd[4072]: rcvd [CCP TermReq id=0x3 00 00 02 dc]
Sep 17 14:19:53 cm pppd[4072]: sent [CCP TermAck id=0x3]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x4 <compress VJ 0f 01> <addr
10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfNak id=0x4 <addr 10.1.0.5>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x5 <compress VJ 0f 01> <addr
10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfNak id=0x5 <addr 10.1.0.5>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x6 <compress VJ 0f 01> <addr
10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfNak id=0x6 <addr 10.1.0.5>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x7 <compress VJ 0f 01> <addr
10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfNak id=0x7 <addr 10.1.0.5>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x8 <compress VJ 0f 01> <addr
10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfRej id=0x8 <addr 10.0.0.21>]
Sep 17 14:19:53 cm pppd[4072]: rcvd [IPCP ConfReq id=0x9 <compress VJ 0f 01>]
Sep 17 14:19:53 cm pppd[4072]: sent [IPCP ConfAck id=0x9 <compress VJ 0f 01>]
Sep 17 14:19:53 cm pppd[4072]: local IP address 10.1.0.6
Sep 17 14:19:53 cm pppd[4072]: remote IP address 10.1.0.5
Sep 17 14:19:53 cm pppd[4072]: Script /etc/ppp/ip-up started (pid 4096)
Sep 17 14:19:54 cm pppd[4072]: Script /etc/ppp/ip-up finished (pid 4096), status = 0x0
Sep 17 14:19:56 cm pppd[4072]: sent [CCP ConfReq id=0x1]
Sep 17 14:19:56 cm pppd[4072]: rcvd [CCP TermAck id=0x1]
Sep 17 14:19:56 cm pppd[4072]: sent [CCP TermReq id=0x2"No compression negotiated"]
Sep 17 14:19:56 cm pppd[4072]: rcvd [CCP TermAck id=0x2]
Sep 17 15:28:47 cm pppd[4072]: Terminating on signal 15.
Sep 17 15:28:47 cm pppd[4072]: Script /etc/ppp/ip-down started (pid 4378)
Sep 17 15:28:47 cm pppd[4072]: sent [LCP TermReq id=0x2 "User request"]
Sep 17 15:28:47 cm pppd[4072]: Script /etc/ppp/ip-down finished (pid 4378), status =
0x0
Sep 17 15:28:47 cm pppd[4072]: rcvd [LCP TermAck id=0x2]
Sep 17 15:28:47 cm pppd[4072]: Connection terminated.
Sep 17 15:28:47 cm pppd[4072]: Connect time 69.0 minutes.
Sep 17 15:28:47 cm pppd[4072]: Sent 37539 bytes, received 26011 bytes.
Sep 17 15:28:48 cm pppd[4072]: Hangup (SIGHUP)
Sep 17 15:28:48 cm pppd[4072]: Exit.
As the syslog shows, I finally killed the pppd process after 69
minutes. Note that the idle timeout that should have kicked in after
5 minutes, never happened.
If anyone can shed some light on this, I'd very much appreciate it.
--
Thomas J. Pinkl 738 Louis Drive
Unix Systems Programmer Warminster, Pa 18974
Health Business Systems, Inc. (215) 442-9300 x9260
-
To unsubscribe from this list: send the line "unsubscribe linux-ppp" in
the body of a message to [EMAIL PROTECTED]
