问题描述
我使用的是 ublox SARA-R410 调制解调器，并pppd通过 UART 与 Linux 主机连接。我有时会看到连接间隔非常短，似乎pppd在没有记录原因的情况下强制重新连接。最终（在 IPCP 超时后重新启动）pppd实现了稳定的 IPv4 连接。
调试
这是启动时的系统日志pppd，问题发生时，最终超时重新启动（成功）：
Mar 06 17:13:16 pppd[4467]: Serial connection established.
Mar 06 17:13:16 pppd[4467]: using channel 21
Mar 06 17:13:16 pppd[4467]: Using interface ppp0
Mar 06 17:13:16 pppd[4467]: Connect: ppp0 <--> /dev/mux0
Mar 06 17:13:16 chat[4470]: expect (OK)
Mar 06 17:13:16 chat[4470]: ^M
Mar 06 17:13:16 chat[4470]: AT+CSQ^M^M
Mar 06 17:13:16 chat[4470]: +CSQ: 31,99^M
Mar 06 17:13:16 chat[4470]: ^M
Mar 06 17:13:16 chat[4470]: OK
Mar 06 17:13:16 chat[4470]: -- got it
Mar 06 17:13:16 chat[4470]: send (ATS0=1^M^M)
Mar 06 17:13:16 chat[4470]: expect (OK)
Mar 06 17:13:16 chat[4470]: ^M
Mar 06 17:13:16 chat[4470]: ATS0=1^M^M
Mar 06 17:13:16 chat[4470]: OK
Mar 06 17:13:16 chat[4470]: -- got it
Mar 06 17:13:16 chat[4470]: send (ATDT*99***1#^M^M)
Mar 06 17:13:16 chat[4470]: expect (CONNECT)
Mar 06 17:13:16 chat[4470]: ^M
Mar 06 17:13:16 chat[4470]: ATDT*99***1#^M^M
Mar 06 17:13:16 chat[4470]: CONNECT
Mar 06 17:13:16 chat[4470]: -- got it
Mar 06 17:13:16 chat[4470]: send (^M)
Mar 06 17:13:16 pppd[4467]: Script /usr/sbin/chat -v -e -t 180 -f /etc/ppp/chat-isp finished (pid 4468), status = 0x0
Mar 06 17:13:16 pppd[4467]: Serial connection established.
Mar 06 17:13:16 pppd[4467]: using channel 21
Mar 06 17:13:16 pppd[4467]: Using interface ppp0
Mar 06 17:13:16 pppd[4467]: Connect: ppp0 <--> /dev/mux0
Mar 06 17:13:17 pppd[4467]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf8e9941f> <pcomp> <accomp>]
Mar 06 17:13:17 pppd[4467]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf8e9941f> <pcomp> <accomp>]
Mar 06 17:13:17 pppd[4467]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:17 pppd[4467]: No auth is possible
Mar 06 17:13:17 pppd[4467]: sent [LCP ConfRej id=0x0 <auth chap MD5>]
Mar 06 17:13:17 pppd[4467]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf8e9941f> <pcomp> <accomp>]
Mar 06 17:13:17 pppd[4467]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:17 pppd[4467]: No auth is possible
Mar 06 17:13:17 pppd[4467]: sent [LCP ConfRej id=0x0 <auth chap MD5>]
Mar 06 17:13:17 pppd[4467]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf8e9941f> <pcomp> <accomp>]
Mar 06 17:13:19 pppd[4467]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:19 pppd[4467]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:19 pppd[4467]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:19 pppd[4467]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:19 pppd[4467]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:19 pppd[4467]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:20 pppd[4467]: rcvd [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:20 pppd[4467]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x8d12075b> <pcomp> <accomp>]
Mar 06 17:13:20 pppd[4467]: sent [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:20 pppd[4467]: rcvd [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:20 pppd[4467]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x8d12075b> <pcomp> <accomp>]
Mar 06 17:13:20 pppd[4467]: sent [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: rcvd [LCP ConfReq id=0x3 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: sent [LCP ConfAck id=0x3 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0x8d12075b> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: rcvd [LCP ConfReq id=0x3 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: sent [LCP ConfAck id=0x3 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0x8d12075b> <pcomp> <accomp>]
Mar 06 17:13:21 pppd[4467]: sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:21 pppd[4467]: sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:22 pppd[4467]: rcvd [LCP ConfReq id=0x4 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:22 pppd[4467]: sent [LCP ConfReq id=0x3 <asyncmap 0x0> <magic 0xec8d3bf0> <pcomp> <accomp>]
Mar 06 17:13:22 pppd[4467]: sent [LCP ConfAck id=0x4 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:22 pppd[4467]: rcvd [LCP ConfReq id=0x4 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:22 pppd[4467]: sent [LCP ConfReq id=0x3 <asyncmap 0x0> <magic 0xec8d3bf0> <pcomp> <accomp>]
Mar 06 17:13:22 pppd[4467]: sent [LCP ConfAck id=0x4 <asyncmap 0x0> <magic 0xf03d27ed> <pcomp> <accomp>]
Mar 06 17:13:23 pppd[4467]: rcvd [LCP ConfAck id=0x3 <asyncmap 0x0> <magic 0xec8d3bf0> <pcomp> <accomp>]
Mar 06 17:13:23 pppd[4467]: rcvd [LCP ConfAck id=0x3 <asyncmap 0x0> <magic 0xec8d3bf0> <pcomp> <accomp>]
Mar 06 17:13:23 pppd[4467]: sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:23 pppd[4467]: sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:23 pppd[4467]: rcvd [LCP DiscReq id=0x5 magic=0xf03d27ed]
Mar 06 17:13:23 pppd[4467]: rcvd [LCP DiscReq id=0x5 magic=0xf03d27ed]
Mar 06 17:13:24 pppd[4467]: rcvd [IPCP ConfReq id=0x0]
Mar 06 17:13:24 pppd[4467]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
Mar 06 17:13:24 pppd[4467]: rcvd [IPCP ConfRej id=0x3 <compress VJ 0f 01>]
Mar 06 17:13:24 pppd[4467]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:24 pppd[4467]: rcvd [IPCP ConfReq id=0x0]
Mar 06 17:13:24 pppd[4467]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
Mar 06 17:13:24 pppd[4467]: rcvd [IPCP ConfRej id=0x3 <compress VJ 0f 01>]
Mar 06 17:13:24 pppd[4467]: sent [IPCP ConfReq id=0x4 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:25 pppd[4467]: rcvd [IPCP ConfReq id=0x1]
Mar 06 17:13:25 pppd[4467]: sent [IPCP ConfAck id=0x1]
Mar 06 17:13:25 pppd[4467]: rcvd [IPCP ConfNak id=0x4 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:25 pppd[4467]: sent [IPCP ConfReq id=0x5 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:25 pppd[4467]: rcvd [IPCP ConfReq id=0x1]
Mar 06 17:13:25 pppd[4467]: sent [IPCP ConfAck id=0x1]
Mar 06 17:13:25 pppd[4467]: rcvd [IPCP ConfNak id=0x4 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:25 pppd[4467]: sent [IPCP ConfReq id=0x5 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:26 pppd[4467]: rcvd [IPCP ConfReq id=0x2]
Mar 06 17:13:26 pppd[4467]: sent [IPCP ConfAck id=0x2]
Mar 06 17:13:26 pppd[4467]: rcvd [IPCP ConfAck id=0x5 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:26 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:26 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:26 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:26 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:26 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:26 pppd[4467]: rcvd [IPCP ConfReq id=0x2]
Mar 06 17:13:26 pppd[4467]: sent [IPCP ConfAck id=0x2]
Mar 06 17:13:26 pppd[4467]: rcvd [IPCP ConfAck id=0x5 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:26 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:26 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:26 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:26 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:26 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:28 pppd[4467]: rcvd [IPCP ConfReq id=0x3]
Mar 06 17:13:28 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:28 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:28 pppd[4467]: sent [IPCP ConfReq id=0x6 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:28 pppd[4467]: sent [IPCP ConfNak id=0x3 <addr 0.0.0.0>]
Mar 06 17:13:28 pppd[4467]: rcvd [IPCP ConfReq id=0x3]
Mar 06 17:13:28 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:28 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:28 pppd[4467]: sent [IPCP ConfReq id=0x6 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:28 pppd[4467]: sent [IPCP ConfNak id=0x3 <addr 0.0.0.0>]
Mar 06 17:13:29 pppd[4467]: rcvd [IPCP ConfReq id=0x4]
Mar 06 17:13:29 pppd[4467]: sent [IPCP ConfAck id=0x4]
Mar 06 17:13:29 pppd[4467]: rcvd [IPCP ConfRej id=0x6 <compress VJ 0f 01>]
Mar 06 17:13:29 pppd[4467]: sent [IPCP ConfReq id=0x7 <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:29 pppd[4467]: rcvd [IPCP ConfReq id=0x4]
Mar 06 17:13:29 pppd[4467]: sent [IPCP ConfAck id=0x4]
Mar 06 17:13:29 pppd[4467]: rcvd [IPCP ConfRej id=0x6 <compress VJ 0f 01>]
Mar 06 17:13:29 pppd[4467]: sent [IPCP ConfReq id=0x7 <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:30 pppd[4467]: rcvd [IPCP ConfReq id=0x5]
Mar 06 17:13:30 pppd[4467]: sent [IPCP ConfAck id=0x5]
Mar 06 17:13:30 pppd[4467]: rcvd [IPCP ConfNak id=0x7 <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:30 pppd[4467]: sent [IPCP ConfReq id=0x8 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:30 pppd[4467]: rcvd [IPCP ConfReq id=0x5]
Mar 06 17:13:30 pppd[4467]: sent [IPCP ConfAck id=0x5]
Mar 06 17:13:30 pppd[4467]: rcvd [IPCP ConfNak id=0x7 <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:30 pppd[4467]: sent [IPCP ConfReq id=0x8 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:32 pppd[4467]: rcvd [IPCP ConfReq id=0x6]
Mar 06 17:13:32 pppd[4467]: sent [IPCP ConfAck id=0x6]
Mar 06 17:13:32 pppd[4467]: rcvd [IPCP ConfAck id=0x8 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:32 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:32 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:32 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:32 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:32 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:31 pppd[4467]: rcvd [IPCP ConfReq id=0x6]
Mar 06 17:13:31 pppd[4467]: sent [IPCP ConfAck id=0x6]
Mar 06 17:13:31 pppd[4467]: rcvd [IPCP ConfAck id=0x8 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:31 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:32 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:32 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:32 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:32 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:33 pppd[4467]: rcvd [IPCP ConfReq id=0x7]
Mar 06 17:13:33 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:33 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:33 pppd[4467]: sent [IPCP ConfReq id=0x9 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:33 pppd[4467]: sent [IPCP ConfNak id=0x7 <addr 0.0.0.0>]
Mar 06 17:13:33 pppd[4467]: rcvd [IPCP ConfReq id=0x7]
Mar 06 17:13:33 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:33 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:33 pppd[4467]: sent [IPCP ConfReq id=0x9 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:33 pppd[4467]: sent [IPCP ConfNak id=0x7 <addr 0.0.0.0>]
Mar 06 17:13:34 pppd[4467]: rcvd [IPCP ConfReq id=0x8]
Mar 06 17:13:34 pppd[4467]: sent [IPCP ConfAck id=0x8]
Mar 06 17:13:34 pppd[4467]: rcvd [IPCP ConfRej id=0x9 <compress VJ 0f 01>]
Mar 06 17:13:34 pppd[4467]: sent [IPCP ConfReq id=0xa <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:34 pppd[4467]: rcvd [IPCP ConfReq id=0x8]
Mar 06 17:13:34 pppd[4467]: sent [IPCP ConfAck id=0x8]
Mar 06 17:13:34 pppd[4467]: rcvd [IPCP ConfRej id=0x9 <compress VJ 0f 01>]
Mar 06 17:13:34 pppd[4467]: sent [IPCP ConfReq id=0xa <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:35 pppd[4467]: rcvd [IPCP ConfReq id=0x9]
Mar 06 17:13:35 pppd[4467]: sent [IPCP ConfAck id=0x9]
Mar 06 17:13:35 pppd[4467]: rcvd [IPCP ConfNak id=0xa <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:35 pppd[4467]: sent [IPCP ConfReq id=0xb <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:35 pppd[4467]: rcvd [IPCP ConfReq id=0x9]
Mar 06 17:13:35 pppd[4467]: sent [IPCP ConfAck id=0x9]
Mar 06 17:13:35 pppd[4467]: rcvd [IPCP ConfNak id=0xa <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:35 pppd[4467]: sent [IPCP ConfReq id=0xb <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:37 pppd[4467]: rcvd [IPCP ConfReq id=0xa]
Mar 06 17:13:37 pppd[4467]: sent [IPCP ConfAck id=0xa]
Mar 06 17:13:37 pppd[4467]: rcvd [IPCP ConfAck id=0xb <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:37 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:37 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:37 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:37 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:37 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:37 pppd[4467]: rcvd [IPCP ConfReq id=0xa]
Mar 06 17:13:37 pppd[4467]: sent [IPCP ConfAck id=0xa]
Mar 06 17:13:37 pppd[4467]: rcvd [IPCP ConfAck id=0xb <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:37 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:37 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:37 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:37 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:37 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:38 pppd[4467]: rcvd [IPCP ConfReq id=0xb]
Mar 06 17:13:38 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:38 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:38 pppd[4467]: sent [IPCP ConfReq id=0xc <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:38 pppd[4467]: sent [IPCP ConfNak id=0xb <addr 0.0.0.0>]
Mar 06 17:13:38 pppd[4467]: rcvd [IPCP ConfReq id=0xb]
Mar 06 17:13:38 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:38 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:38 pppd[4467]: sent [IPCP ConfReq id=0xc <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:38 pppd[4467]: sent [IPCP ConfNak id=0xb <addr 0.0.0.0>]
Mar 06 17:13:39 pppd[4467]: rcvd [IPCP ConfReq id=0xc]
Mar 06 17:13:39 pppd[4467]: sent [IPCP ConfAck id=0xc]
Mar 06 17:13:39 pppd[4467]: rcvd [IPCP ConfRej id=0xc <compress VJ 0f 01>]
Mar 06 17:13:39 pppd[4467]: sent [IPCP ConfReq id=0xd <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:39 pppd[4467]: rcvd [IPCP ConfReq id=0xc]
Mar 06 17:13:39 pppd[4467]: sent [IPCP ConfAck id=0xc]
Mar 06 17:13:39 pppd[4467]: rcvd [IPCP ConfRej id=0xc <compress VJ 0f 01>]
Mar 06 17:13:39 pppd[4467]: sent [IPCP ConfReq id=0xd <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:40 pppd[4467]: rcvd [IPCP ConfReq id=0xd]
Mar 06 17:13:40 pppd[4467]: sent [IPCP ConfAck id=0xd]
Mar 06 17:13:40 pppd[4467]: rcvd [IPCP ConfNak id=0xd <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:40 pppd[4467]: sent [IPCP ConfReq id=0xe <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:40 pppd[4467]: rcvd [IPCP ConfReq id=0xd]
Mar 06 17:13:40 pppd[4467]: sent [IPCP ConfAck id=0xd]
Mar 06 17:13:40 pppd[4467]: rcvd [IPCP ConfNak id=0xd <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:40 pppd[4467]: sent [IPCP ConfReq id=0xe <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:42 pppd[4467]: rcvd [IPCP ConfReq id=0xe]
Mar 06 17:13:42 pppd[4467]: sent [IPCP ConfAck id=0xe]
Mar 06 17:13:42 pppd[4467]: rcvd [IPCP ConfAck id=0xe <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:42 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:42 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:42 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:42 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:42 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:42 pppd[4467]: rcvd [IPCP ConfReq id=0xe]
Mar 06 17:13:42 pppd[4467]: sent [IPCP ConfAck id=0xe]
Mar 06 17:13:42 pppd[4467]: rcvd [IPCP ConfAck id=0xe <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:42 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:42 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:42 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:42 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:42 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:43 pppd[4467]: rcvd [IPCP ConfReq id=0xf]
Mar 06 17:13:43 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:43 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:43 pppd[4467]: sent [IPCP ConfReq id=0xf <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:43 pppd[4467]: sent [IPCP ConfNak id=0xf <addr 0.0.0.0>]
Mar 06 17:13:43 pppd[4467]: rcvd [IPCP ConfReq id=0xf]
Mar 06 17:13:43 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:43 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:43 pppd[4467]: sent [IPCP ConfReq id=0xf <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:43 pppd[4467]: sent [IPCP ConfNak id=0xf <addr 0.0.0.0>]
Mar 06 17:13:44 pppd[4467]: rcvd [IPCP ConfReq id=0x10]
Mar 06 17:13:44 pppd[4467]: sent [IPCP ConfAck id=0x10]
Mar 06 17:13:44 pppd[4467]: rcvd [IPCP ConfRej id=0xf <compress VJ 0f 01>]
Mar 06 17:13:44 pppd[4467]: sent [IPCP ConfReq id=0x10 <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:44 pppd[4467]: rcvd [IPCP ConfReq id=0x10]
Mar 06 17:13:44 pppd[4467]: sent [IPCP ConfAck id=0x10]
Mar 06 17:13:44 pppd[4467]: rcvd [IPCP ConfRej id=0xf <compress VJ 0f 01>]
Mar 06 17:13:44 pppd[4467]: sent [IPCP ConfReq id=0x10 <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:46 pppd[4467]: rcvd [IPCP ConfReq id=0x11]
Mar 06 17:13:46 pppd[4467]: sent [IPCP ConfAck id=0x11]
Mar 06 17:13:46 pppd[4467]: rcvd [IPCP ConfNak id=0x10 <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:46 pppd[4467]: sent [IPCP ConfReq id=0x11 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:46 pppd[4467]: rcvd [IPCP ConfReq id=0x11]
Mar 06 17:13:46 pppd[4467]: sent [IPCP ConfAck id=0x11]
Mar 06 17:13:46 pppd[4467]: rcvd [IPCP ConfNak id=0x10 <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:46 pppd[4467]: sent [IPCP ConfReq id=0x11 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:47 pppd[4467]: rcvd [IPCP ConfReq id=0x12]
Mar 06 17:13:47 pppd[4467]: sent [IPCP ConfAck id=0x12]
Mar 06 17:13:47 pppd[4467]: rcvd [IPCP ConfAck id=0x11 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:47 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:47 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:47 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:47 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:47 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:47 pppd[4467]: rcvd [IPCP ConfReq id=0x12]
Mar 06 17:13:47 pppd[4467]: sent [IPCP ConfAck id=0x12]
Mar 06 17:13:47 pppd[4467]: rcvd [IPCP ConfAck id=0x11 <addr 10.67.100.135> <ms-dns1 8.8.8.8> <ms-dns2 8.8.4.4>]
Mar 06 17:13:47 pppd[4467]: Could not determine remote IP address: defaulting to 10.64.64.64
Mar 06 17:13:47 pppd[4467]: local IP address 10.67.100.135
Mar 06 17:13:47 pppd[4467]: remote IP address 10.64.64.64
Mar 06 17:13:47 pppd[4467]: primary DNS address 8.8.8.8
Mar 06 17:13:47 pppd[4467]: secondary DNS address 8.8.4.4
Mar 06 17:13:48 pppd[4467]: rcvd [IPCP ConfReq id=0x13]
Mar 06 17:13:48 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:48 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:48 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:48 pppd[4467]: sent [IPCP ConfNak id=0x13 <addr 0.0.0.0>]
Mar 06 17:13:48 pppd[4467]: rcvd [IPCP ConfReq id=0x13]
Mar 06 17:13:48 pppd[4467]: Connect time 0.1 minutes.
Mar 06 17:13:48 pppd[4467]: Sent 0 bytes, received 4 bytes.
Mar 06 17:13:48 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:48 pppd[4467]: sent [IPCP ConfNak id=0x13 <addr 0.0.0.0>]
Mar 06 17:13:51 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:51 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:54 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:54 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:57 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:13:57 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:00 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:00 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:03 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:03 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:06 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:06 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:09 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:09 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:12 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:12 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:15 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:15 pppd[4467]: sent [IPCP ConfReq id=0x12 <compress VJ 0f 01> <addr 10.67.100.135> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Mar 06 17:14:18 pppd[4467]: IPCP: timeout sending Config-Requests
Mar 06 17:14:18 pppd[4467]: IPCP: timeout sending Config-Requests
Mar 06 17:14:18 pppd[4467]: sent [LCP TermReq id=0x4 "No network protocols running"]
Mar 06 17:14:18 pppd[4467]: sent [LCP TermReq id=0x4 "No network protocols running"]
Mar 06 17:14:21 pppd[4467]: sent [LCP TermReq id=0x5 "No network protocols running"]
Mar 06 17:14:21 pppd[4467]: sent [LCP TermReq id=0x5 "No network protocols running"]
Mar 06 17:14:24 pppd[4467]: Connection terminated.
Mar 06 17:14:24 pppd[4467]: Connection terminated.
Mar 06 17:14:24 chat[4635]: abort on (BUSY)
Mar 06 17:14:24 chat[4635]: abort on (ERROR)
Mar 06 17:14:24 chat[4635]: abort on (NO DIALTONE)
Mar 06 17:14:24 chat[4635]: send (+++)
Mar 06 17:14:24 pppd[4467]: Sending break
Mar 06 17:14:24 chat[4635]: send (\dATH^M)
Mar 06 17:14:25 pppd[4467]: [4B blob data]
Mar 06 17:14:25 pppd[4467]: Querying CSQ
Mar 06 17:14:25 pppd[4467]: [1B blob data]
Mar 06 17:14:26 pppd[4467]: OK
Mar 06 17:14:26 pppd[4467]: AT+CSQ
Mar 06 17:14:26 pppd[4467]: +CSQ: 31,99
Mar 06 17:14:26 pppd[4467]: OK
Mar 06 17:14:26 pppd[4467]: AT+COPS=2
Mar 06 17:14:26 pppd[4467]: OK
Mar 06 17:14:26 pppd[4467]: PDP context detached
Mar 06 17:14:26 pppd[4467]: [1B blob data]
Mar 06 17:14:26 pppd[4467]: Script /usr/sbin/chat -v -e -t 10 -f /etc/ppp/disconnect-chat finished (pid 4633), status = 0x0
Mar 06 17:14:26 pppd[4467]: Serial link disconnected.
Mar 06 17:14:26 pppd[4467]: Modem hangup
Mar 06 17:14:25 chat[4635]: expect (^M)
Mar 06 17:14:25 chat[4635]: ATH^M
Mar 06 17:14:25 chat[4635]: -- got it
Mar 06 17:14:25 chat[4635]: send (AT+CSQ^M^M)
Mar 06 17:14:25 chat[4635]: expect (OK)
Mar 06 17:14:25 chat[4635]: ^M
Mar 06 17:14:25 chat[4635]: OK
Mar 06 17:14:25 chat[4635]: -- got it
Mar 06 17:14:25 chat[4635]: send (AT+COPS=2^M^M)
Mar 06 17:14:26 chat[4635]: expect (OK)
Mar 06 17:14:26 chat[4635]: ^M
Mar 06 17:14:26 chat[4635]: AT+CSQ^M^M
Mar 06 17:14:26 chat[4635]: +CSQ: 31,99^M
Mar 06 17:14:26 chat[4635]: ^M
Mar 06 17:14:26 chat[4635]: OK
Mar 06 17:14:26 chat[4635]: -- got it
Mar 06 17:14:26 chat[4635]: send (AT+CPSMS?^M^M)
Mar 06 17:14:26 chat[4635]: expect (OK)
Mar 06 17:14:26 chat[4635]: ^M
Mar 06 17:14:26 chat[4635]: AT+COPS=2^M^M
Mar 06 17:14:26 chat[4635]: OK
Mar 06 17:14:26 chat[4635]: -- got it
Mar 06 17:14:26 chat[4635]: send (AT&F^M^M)
Mar 06 17:14:26 pppd[4467]: Script /usr/sbin/chat -v -e -t 10 -f /etc/ppp/disconnect-chat finished (pid 4633), status = 0x0
Mar 06 17:14:26 pppd[4467]: Serial link disconnected.
Mar 06 17:14:26 pppd[4467]: Modem hangup
Mar 06 17:14:26 pppd[4467]: Exit.
... restarts here and obtains stable IPv4 address right away...
如果我观察ifconfig上述过程，就会发现ppp0获得 IPv4 地址然后又丢失，如此反复。接口仅在几分之一秒内拥有 IPv4 地址。
这是我的 pppdoptions文件：
debug
/dev/mux0
460800
mtu 1500
mru 1500
modem
local
crtscts
lock
idle 60
connect "/usr/sbin/chat -v -e -t 180 -f /etc/ppp/chat-isp"
disconnect "/usr/sbin/chat -v -e -t 10 -f /etc/ppp/disconnect-chat"
asyncmap 0
#noipdefault
noauth
nobsdcomp
#novjccomp
#noaccomp
#noccp
#nodeflate
#nopcomp
#nopredictor1
#novj
defaultroute
usepeerdns
:
如上面的注释行所示，我尝试禁用各种压缩选项，但没有成功。对于任何单身的压缩选项被禁用，问题仍然存在。
问题
我真的希望链接启动能够以一致的方式进行，而不会超时和重新启动。
除了更多 pppd 组合之外，我还应该尝试其他什么吗options？除了 syslog 之外，我还应该研究其他什么来进行调试？
答案1
经过几个小时的挖掘和添加打印后pppd，我确定我在最初的帖子中描述的拆卸发生pppd/fsm.c在函数中fsm_rconfreq()
static void
fsm_rconfreq(f, id, inp, len)
fsm *f;
u_char id;
u_char *inp;
int len;
{
int code, reject_if_disagree;
switch( f->state ){
case CLOSED:
/* Go away, we're closed */
fsm_sdata(f, TERMACK, id, NULL, 0);
return;
case CLOSING:
case STOPPING:
return;
case OPENED:
/* Go down and restart negotiation */
//////// BEGIN EDIT /////////
// if( f->callbacks->down )
// (*f->callbacks->down)(f); /* Inform upper layers */
// fsm_sconfreq(f, 0); /* Send initial Configure-Request */
// f->state = REQSENT;
// break;
//////// END EDIT /////////
case STOPPED:
/* Negotiation started by our peer */
fsm_sconfreq(f, 0); /* Send initial Configure-Request */
f->state = REQSENT;
break;
}
代码的注释部分ipcp_down()通过函数指针调用，打印链接统计信息。
通过如图所示的注释掉的代码，我看到了更加稳定的链接启动。
不确定这是否是pppd调制解调器的一个错误。如果出现问题，请使用 pppd-2.4.7。