Date: Mon, 17 Jan 2005 10:49:51 -0500 From: Timothy Luoma <lists@tntluoma.com> To: FreeBSD-Questions Questions <freebsd-questions@freebsd.org> Subject: More info (Re: ppp dialin problems: mgetty and ppp.conf) Message-ID: <6CC0CF09-689F-11D9-942B-000D93AD26C8@tntluoma.com> In-Reply-To: <0E13E623-681B-11D9-B497-000D93AD26C8@tntluoma.com> References: <0E13E623-681B-11D9-B497-000D93AD26C8@tntluoma.com>
next in thread | previous in thread | raw e-mail | index | archive | help
[more information on the problems originally outlined at http://lists.freebsd.org/pipermail/freebsd-questions/2005-January/ 072284.html ] updated summary: dialing into FreeBSD box sometimes fails to provide a connection to the Internet, however, it appears that if I maintain the connection long enough, the problem will solve itself after awhile (~10 minutes). I hope that the netstat and ppp log information below will help someone smarter than me figure out what is going on. More information: I am using my Powerbook to dial in via Airport Extreme to a FreeBSD 5.3 machine running mgetty and ppp. I am having occasional problems connecting. Sometimes when I connect, I can only ping/ssh to the IP address of the FreeBSD machine. (ssh often fails to connect, although it will say it is connected, it will time out.) I am trying to diagnose whether the problem is on the dial in end (Airport Extreme/Powerbook) or the FreeBSD end. I believe that something is not being correctly configured for my routing, but I could be wrong. In an attempt to diagnose this, I ran 'netstat -rn -f inet' from my Powerbook when the Airport Extreme was connected and when the connection was working perfectly: [NOTE: when 192.168.2.1 is the Airport Extreme IP address, and shows up on 'en1'] Routing tables [when working] Internet: Destination Gateway Flags Refs Use Netif Expire default 192.168.2.1 UGSc 5 10 en1 127 127.0.0.1 UCS 0 0 lo0 127.0.0.1 127.0.0.1 UH 23 8498 lo0 169.254 link#5 UCS 0 0 en1 192.168.2 link#5 UCS 1 0 en1 192.168.2.1 0:3:93:df:e7:6a UHLW 5 1292 en1 1178 192.168.2.2 127.0.0.1 UHS 0 3 lo0 And then, later, I ran it again when it was connected but NOT working Routing tables [when NOT working] Internet: Destination Gateway Flags Refs Use Netif Expire default 192.168.2.1 UGSc 11 10 en1 127 127.0.0.1 UCS 0 0 lo0 127.0.0.1 127.0.0.1 UH 46 64040 lo0 169.254 link#5 UCS 0 0 en1 192.168.2 link#5 UCS 2 0 en1 192.168.2.1 0:3:93:df:e7:6a UHLW 11 281 en1 1059 192.168.2.2 127.0.0.1 UHS 1 47 lo0 192.168.2.255 link#5 UHLWb 1 3 en1 Now while I was writing this, the connection seems to have "healed itself" automagically, and I ran netstat again (not long after the previous NOT working example) and saw this: Routing tables [when suddenly working again] Internet: Destination Gateway Flags Refs Use Netif Expire default 192.168.2.1 UGSc 17 13 en1 127 127.0.0.1 UCS 0 0 lo0 127.0.0.1 127.0.0.1 UH 77 66575 lo0 169.254 link#5 UCS 0 0 en1 192.168.2 link#5 UCS 2 0 en1 192.168.2.1 0:3:93:df:e7:6a UHLW 16 1464 en1 1059 192.168.2.2 127.0.0.1 UHS 1 93 lo0 192.168.2.255 link#5 UHLWb 1 6 en1 Here is the relevant ppp log data from when that connection was first made: Jan 17 10:18:56 freebsd ppp[2027]: Phase: Using interface: tun0 Jan 17 10:18:56 freebsd ppp[2027]: Phase: deflink: Created in closed state Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: default: enable passwdauth Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: default: set speed 115200 Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: default: set dial ABORT BUSY ABORT NO\sCARRIER TIMEOUT 5 "" AT OK-AT-OK ATE1Q0 OK \dATDT\TTIMEOUT 40 CONNECT Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: default: set timeout 120 Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: default: set ifaddr 192.168.1.1/0 192.168.1.2/0 255.255.255.0 0.0.0.0 Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: default: add default HISADDR Jan 17 10:18:56 freebsd ppp[2027]: tun0: Warning: Add route failed: 0.0.0.0/0 already exists Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: pap: enable pap Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: pap: set ifaddr 192.168.1.3 192.168.1.4-192.168.1.9 Jan 17 10:18:56 freebsd ppp[2027]: tun0: IPCP: Selected IP address 192.168.1.8 Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: pap: enable proxy Jan 17 10:18:56 freebsd ppp[2027]: tun0: Command: pap: enable passwdauth Jan 17 10:18:56 freebsd ppp[2027]: tun0: Phase: PPP Started (direct mode). Jan 17 10:18:56 freebsd ppp[2027]: tun0: Phase: bundle: Establish Jan 17 10:18:56 freebsd ppp[2027]: tun0: Phase: deflink: closed -> opening Jan 17 10:18:56 freebsd ppp[2027]: tun0: Phase: deflink: Connected! Jan 17 10:18:56 freebsd ppp[2027]: tun0: Phase: deflink: opening -> carrier Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: deflink: /dev/ttyd0: CD detected Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: deflink: carrier -> lcp Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: FSM: Using "deflink" as a transport Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: State change Initial --> Closed Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: State change Closed --> Stopped Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: RecvConfigReq(235) state = Stopped Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: MAGICNUM[6] 0x00000001 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: ACFCOMP[2] Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: PROTOCOMP[2] Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: MRU[4] 1500 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: MAGICNUM[6] 0xcb118bb6 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP) Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: SendConfigAck(235) state = Stopped Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: MAGICNUM[6] 0x00000001 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: LayerStart Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: State change Stopped --> Ack-Sent Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: RecvConfigAck(1) state = Ack-Sent Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: ACFCOMP[2] Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: PROTOCOMP[2] Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: ACCMAP[6] 0x00000000 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: MRU[4] 1500 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: MAGICNUM[6] 0xcb118bb6 Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: AUTHPROTO[4] 0xc023 (PAP) Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: State change Ack-Sent --> Opened Jan 17 10:18:57 freebsd ppp[2027]: tun0: LCP: deflink: LayerUp Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: bundle: Authenticate Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: deflink: his = none, mine = PAP Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: Pap Input: REQUEST (ppp) Jan 17 10:18:57 freebsd ppp[2027]: tun0: Warning: OpenSecret: Can't open /etc/ppp/ppp.secret. Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: Pap Output: SUCCESS Jan 17 10:18:57 freebsd ppp[2027]: tun0: Warning: OpenSecret: Can't open /etc/ppp/ppp.secret. [now it is my understanding that it should NOT be looking for /etc/ppp/ppp.secret if I am using passwdauth, so something seems to be going wrong there] Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: FSM: Using "deflink" as a transport Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: deflink: State change Initial --> Closed Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: deflink: LayerStart. Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: MPPE: Not usable without CHAP81 Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: deflink: SendConfigReq(1) state = Closed Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: DEFLATE[4] win 15 Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: PRED1[2] Jan 17 10:18:57 freebsd ppp[2027]: tun0: CCP: deflink: State change Closed --> Req-Sent Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: deflink: lcp -> open Jan 17 10:18:57 freebsd ppp[2027]: tun0: Phase: bundle: Network Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: FSM: Using "deflink" as a transport Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: deflink: State change Initial --> Closed Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: deflink: LayerStart. Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: deflink: SendConfigReq(1) state = Closed Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 192.168.1.3 Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 17 10:18:57 freebsd ppp[2027]: tun0: IPCP: deflink: State change Closed --> Req-Sent Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: RecvConfigReq(1) state = Req-Sent Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 0.0.0.0 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: 0.0.0.0: Address invalid or already in use Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: PRIDNS[6] 0.0.0.0 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: SECDNS[6] 0.0.0.0 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: SendConfigRej(1) state = Req-Sent Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: PRIDNS[6] 0.0.0.0 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: SECDNS[6] 0.0.0.0 Jan 17 10:18:58 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(236) state = Opened Jan 17 10:18:58 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x80fd (Compression Control Protocol) was rejected! Jan 17 10:18:58 freebsd ppp[2027]: tun0: CCP: deflink: State change Req-Sent --> Stopped Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: RecvConfigAck(1) state = Req-Sent Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 192.168.1.3 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: State change Req-Sent --> Ack-Rcvd Jan 17 10:18:58 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(237) state = Opened Jan 17 10:18:58 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Jan 17 10:18:58 freebsd ppp[2027]: tun0: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: RecvConfigReq(2) state = Ack-Rcvd Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 0.0.0.0 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: 0.0.0.0: Address invalid or already in use Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: SendConfigNak(2) state = Ack-Rcvd Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 192.168.1.8 Jan 17 10:18:58 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(238) state = Opened Jan 17 10:18:58 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Jan 17 10:18:58 freebsd ppp[2027]: tun0: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: RecvConfigReq(3) state = Ack-Rcvd Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 192.168.1.8 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: SendConfigAck(3) state = Ack-Rcvd Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: IPADDR[6] 192.168.1.8 Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: State change Ack-Rcvd --> Opened Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: deflink: LayerUp. Jan 17 10:18:58 freebsd ppp[2027]: tun0: IPCP: myaddr 192.168.1.3 hisaddr = 192.168.1.8 Jan 17 10:18:58 freebsd ppp[2027]: tun0: Warning: ff02:5::/32: Change route failed: errno: Network is unreachable Jan 17 10:19:01 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(239) state = Opened Jan 17 10:19:01 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Jan 17 10:19:01 freebsd ppp[2027]: tun0: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Jan 17 10:19:04 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(240) state = Opened Jan 17 10:19:04 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Jan 17 10:19:04 freebsd ppp[2027]: tun0: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Jan 17 10:19:07 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(241) state = Opened Jan 17 10:19:07 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Jan 17 10:19:07 freebsd ppp[2027]: tun0: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! Jan 17 10:19:10 freebsd ppp[2027]: tun0: LCP: deflink: RecvProtocolRej(242) state = Opened Jan 17 10:19:10 freebsd ppp[2027]: tun0: LCP: deflink: -- Protocol 0x8057 (Internet Protocol V6 Control Protocol) was rejected! Jan 17 10:19:10 freebsd ppp[2027]: tun0: Phase: deflink: IPV6CP protocol reject closes IPV6CP ! [that is the end of the log] it was approximately 10:30 when the connection "healed itself" but there was no log data to explain what happened.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?6CC0CF09-689F-11D9-942B-000D93AD26C8>