Date: Sun, 21 Sep 1997 22:28:35 From: David Goddard <goddard@acm.org> To: questions@freebsd.org Cc: Greg Lehey <grog@lemis.com>, Brian Somers <brian@awfulhak.org> Subject: Re: ppp -auto problems and boot-time error messages Message-ID: <3.0.1.16.19970921222835.238f44ce@sg1.cc.ic.ac.uk> In-Reply-To: <199709201634.RAA17171@awfulhak.demon.co.uk> References: <Your message of "Sat, 20 Sep 1997 14:07:10." <3.0.1.16.19970920140710.22dfc0a6@sg1.cc.ic.ac.uk>
next in thread | previous in thread | raw e-mail | index | archive | help
At 17:34 20/09/97 +0100, Brian Somers wrote:
>By "more details", I mean your config files and a log of what
>happened. Set your logging with
>
> set log chat phase connect lcp ipcp ccp command tun
^^^ YM 'debug'?
OK, here are some more details:-
Here's one a section of ppp.log. Please note the log setting in
ppp.conf below. Any explanations as to why it is logging only a
subset of this gratefully received (yes, I did restart ppp (by
rebooting) after editing the file). I've varied log levels before
with no problem, but now it seems to be ignoring the set debug
section of the ppp.conf file and only giving me Link debug info.
This log section is for a dialup caused by a telnet command. Telnet timed
out, but the link came up OK and was usable.
=== start ppp.log ===
[...]
09-21 21:40:38 [44] Dial attempt 1
09-21 21:40:38 [44] Expecting
09-21 21:40:38 [44] sending: ATE1Q0M0
09-21 21:40:38 [44] Expecting OK-AT-OK
09-21 21:40:38 [44] Wait for (5): OK --> OK
09-21 21:40:38 [44] Chat: ATE1Q0M0
09-21 21:40:38 [44] Chat: OK
09-21 21:40:38 [44] sending: ATDT01715949988
09-21 21:40:38 [44] Expecting CONNECT
09-21 21:40:38 [44] Wait for (40): CONNECT --> CONNECT
09-21 21:40:38 [44] Chat:
09-21 21:40:58 [44] Chat: ATDT01715949988
09-21 21:40:58 [44] Chat: CONNECT
09-21 21:40:58 [44] Expecting return
09-21 21:40:58 [44] Wait for (5): return --> return
09-21 21:40:58 [44] Chat: 31200/ARQ/V34/LAPM/V42BIS
09-21 21:40:59 [44] Chat:
09-21 21:40:59 [44] Chat:
09-21 21:40:59 [44] Chat: Annex Command Line Interpreter * Copyright
1991 Xylogics, Inc.
09-21 21:40:59 [44] Chat:
09-21 21:40:59 [44] Chat: Press return
09-21 21:40:59 [44] sending: r
09-21 21:40:59 [44] Expecting sername:-\r-sername:
09-21 21:40:59 [44] Wait for (5): sername: --> sername:
09-21 21:40:59 [44] Chat: to start log-in.
09-21 21:40:59 [44] Chat:
09-21 21:40:59 [44] Chat: Checking authorization, Please wait...
09-21 21:40:59 [44] Chat:
09-21 21:40:59 [44] Chat: Annex port checks complete.
[snipped a message from my ISP]
09-21 21:41:00 [44] Chat: Annex username:
09-21 21:41:00 [44] sending: dgoddard
09-21 21:41:00 [44] Expecting word:
09-21 21:41:00 [44] Wait for (5): word: --> word:
09-21 21:41:00 [44] Chat: MYLOGIN
09-21 21:41:00 [44] Chat: Annex password:
09-21 21:41:00 [44] sending: MYPASSWD
09-21 21:41:00 [44] Expecting port
09-21 21:41:00 [44] Wait for (5): port --> port
09-21 21:41:00 [44] Chat:
09-21 21:41:02 [44] Chat:
09-21 21:41:02 [44] Chat: Permission granted
[snipped some more message text from ISP]
09-21 21:41:02 [44] Chat: V34 Service port
09-21 21:41:02 [44] sending: ppp
09-21 21:41:03 [44] LCP: state change Initial --> Closed
09-21 21:41:03 [44] LCP: SendConfigReq
09-21 21:41:03 [44] ACFCOMP
09-21 21:41:03 [44] PROTOCOMP
09-21 21:41:03 [44] ACCMAP [6] 00000000
09-21 21:41:03 [44] MRU [4] 1500
09-21 21:41:03 [44] MAGICNUM [6] ed1b212c
09-21 21:41:03 [44] LCP: state change Closed --> Req-Sent
09-21 21:41:03 [44] LCP: Received Configure Request (1) state = Req-Sent (6)
09-21 21:41:03 [44] ACCMAP 00000000
09-21 21:41:03 [44] MAGICNUM 7a9d32cd
09-21 21:41:03 [44] PROTOCOMP
09-21 21:41:03 [44] ACFCOMP
09-21 21:41:03 [44] LCP: SendConfigAck(Req-Sent)
09-21 21:41:03 [44] ACCMAP 00000000
09-21 21:41:03 [44] MAGICNUM 7a9d32cd
09-21 21:41:03 [44] PROTOCOMP
09-21 21:41:03 [44] ACFCOMP
09-21 21:41:03 [44] LCP: state change Req-Sent --> Ack-Sent
09-21 21:41:06 [44] LCP: SendConfigReq
09-21 21:41:06 [44] ACFCOMP
09-21 21:41:06 [44] PROTOCOMP
09-21 21:41:06 [44] ACCMAP [6] 00000000
09-21 21:41:06 [44] MRU [4] 1500
09-21 21:41:06 [44] MAGICNUM [6] ed1b212c
09-21 21:41:06 [44] LCP: Received Configure Ack (2) state = Ack-Sent (8)
09-21 21:41:06 [44] LCP: state change Ack-Sent --> Opend
09-21 21:41:06 [44] LCP: LayerUp
09-21 21:41:06 [44] IPCP: state change Initial --> Closed
09-21 21:41:06 [44] IPCP Up event!!
09-21 21:41:06 [44] IPCP: SendConfigReq
09-21 21:41:06 [44] IPADDR [6] 155.198.8.0
09-21 21:41:06 [44] COMPPROTO [6] 002d0f00
09-21 21:41:06 [44] IPCP: state change Closed --> Req-Sent
09-21 21:41:06 [44] CCP: state change Initial --> Closed
09-21 21:41:06 [44] CCP Up event!!
09-21 21:41:06 [44] CCP: SendConfigReq
09-21 21:41:06 [44] CCP: state change Closed --> Req-Sent
09-21 21:41:06 [44] IPCP: Received Configure Nak (1) state = Req-Sent (6)
09-21 21:41:06 [44] IPADDR[6] 155.198.8.2
09-21 21:41:06 [44] IPADDR[6] changing address: 155.198.8.0 --> 155.198.8.2
09-21 21:41:06 [44] IPCP: SendConfigReq
09-21 21:41:06 [44] IPADDR [6] 155.198.8.2
09-21 21:41:06 [44] COMPPROTO [6] 002d0f00
09-21 21:41:06 [44] LCP: Received Protocol Reject (2) state = Opend (9)
09-21 21:41:06 [44] -- Protocol (80fd) was rejected.
09-21 21:41:06 [44] CCP: LayerFinish.
09-21 21:41:06 [44] CCP: state change Req-Sent --> Stopped
09-21 21:41:06 [44] IPCP: Received Configure Ack (2) state = Req-Sent (6)
09-21 21:41:06 [44] IPCP: state change Req-Sent --> Ack-Rcvd
09-21 21:41:09 [44] IPCP: Received Configure Request (3) state = Ack-Rcvd (7)
09-21 21:41:09 [44] COMPPROTO[6] 002d0f01
09-21 21:41:09 [44] IPADDR[6] 155.198.8.241
09-21 21:41:09 [44] IPCP: SendConfigAck(Ack-Rcvd)
09-21 21:41:09 [44] COMPPROTO[6] 002d0f01
09-21 21:41:09 [44] IPADDR[6] 155.198.8.241
09-21 21:41:09 [44] IPCP: state change Ack-Rcvd --> Opend
09-21 21:41:09 [44] IPCP: LayerUp.
09-21 21:41:09 [44] myaddr = 155.198.8.2 hisaddr = 155.198.8.241
09-21 21:41:09 [44] OsLinkup: 155.198.8.241
[At this point, after the initial process has given up waiting, I close
the ppp connection]
09-21 21:42:17 [44] LCP: LayerDown
09-21 21:42:17 [44] OsLinkdown: 155.198.8.241
09-21 21:42:17 [44] LCP: SendTerminateReq.
09-21 21:42:17 [44] LCP: state change Opend --> Closing
09-21 21:42:17 [44] LCP: Received Terminate Ack (3) state = Closing (4)
09-21 21:42:17 [44] LCP: state change Closing --> Closed
09-21 21:42:17 [44] LCP: LayerFinish
=== end ppp.log ===
On the subject of log oddities, could anyone explain the following
behaviour of ppp:?
### start script ###
dmg% telnet localhost 3000
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
User Process PPP. Written by Toshiharu OHNO.
Warning: No password entry for this host in ppp.secret
Warning: All manipulation is allowed by anyone in the world
Working in auto mode.
[I've already been fiddling with it here - the default with the entry
in ppp.conf given below give just Link info]
ppp ON dmg> show debug
183: Phase Chat Link Connect
ppp ON dmg> set debug chat phase connect lcp ipcp ccp command tun
ppp ON dmg> show debug
10b: Phase Chat LCP Connect
ppp ON dmg> quit
Connection closed by foreign host.
dmg%
### end script ###
Now ppp.conf:
=== start of ppp.conf section ===
# Default setup. Always executed when PPP is invoked.
#
default:
set device /dev/cuaa1
set speed 57600
set debug chat phase connect lcp ipcp ccp command tun
# set debug phase carrier chat connect link
# set debug carrier link phase
set debug link
disable lqr
deny lqr
set redial 10 4
set dial "ABORT BUSY ABORT NO\\sCARRIER TIMEOUT 5 \"\" ATE1Q0M0 OK-AT-OK
\\dATDT\\T TIMEOUT 40 CONNECT"
[...]
pmdemand:
set phone 01715949988
set login "TIMEOUT 5 return \r sername:-\\r-sername: LUSERNAME word:
PASSWORD port
ppp"
set timeout 120
set ifaddr 155.198.8.0/8 155.198.8.0/8 255.255.255.0
delete 0 0
# add 0 0 155.198.8.0 # Commented out 20 Sep - this stopped boot msg
problem
# add 0 0 HISADDR # Commented out some time ago
set openmode active
[...]
=== end of ppp.conf section ===
Now a bit of ppp.linkup:
=== start of ppp.linkup section ===
[...]
MYADDR:
delete 0 0
add 0 0 HISADDR
[...]
pmdemand:
delete 0 0
add 0 0 HISADDR
# ! sh -c "/etc/ppp/ppp.etherup.pmdemand &"
=== end of ppp.linkup section ===
Finally, a bit of sysconfig:
=== start of sysconfig section ===
[...]
######################### Start Of Netconfig Section #######################
[...]
network_interfaces="tun0 lo0"
ifconfig_tun0=
ifconfig_lo0="inet 127.0.0.1"
[...]
static_routes=""
# Set to the host you'd like set as your default router, or NO for none.
# This is the same as adding a ``default'' entry to static_routes.
defaultrouter="155.198.8.0"
# This is the routing daemon you want to use. Possible options are
# currently NO (for none), `routed' and `gated'. Also see `routerflags'
# for startup flags.
router="NO"
=== end of sysconfig section ===
Finally, I *do* have a file /etc/start_if.tun0, containing the following
line:
ppp -auto pmdemand
Once again, thanks in advance to anyone who takes the time out to help me
solve what it probably a trivial problem but one that *I* can't work out.
Dave
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?3.0.1.16.19970921222835.238f44ce>