IPCP:发送配置请求超时

IPCP:发送配置请求超时

我们的部分设备在使用 ppp 连接美国 3G 调制解调器的互联网时出现了问题。这个问题看起来很奇怪,因为只有少数设备有这个问题,但这是一个永久性的问题(从未建立连接)。以下是设备上打开调试模式后出现超时的日志:

May  9 18:49:06 AppName1 kernel: [  810.365121] 
May  9 18:49:07 AppName1 pppd[1640]: pppd 2.4.6 started by root, uid 0
May  9 18:49:07 AppName1 pppd[1640]: using channel 1
May  9 18:49:07 AppName1 pppd[1640]: Using interface ppp0
May  9 18:49:07 AppName1 pppd[1640]: Connect: ppp0 <--> /dev/ttyUSB3
May  9 18:49:07 AppName1 pppd[1640]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xa1e27395> <pcomp> <accomp>]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x45291790> <pcomp> <accomp>]
May  9 18:49:07 AppName1 pppd[1640]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x45291790> <pcomp> <accomp>]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xa1e27395> <pcomp> <accomp>]
May  9 18:49:07 AppName1 pppd[1640]: sent [LCP EchoReq id=0x0 magic=0xa1e27395]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [LCP DiscReq id=0x1 magic=0x45291790]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [CHAP Challenge id=0x1 <9ee875714217fbf3306bb4e92e94e943>, name = "UMTS_CHAP_SRVR"]
May  9 18:49:07 AppName1 pppd[1640]: sent [CHAP Response id=0x1 <c1fe100b1636f52bf0cf44bbe34210b1>, name = "AppName1"]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [LCP EchoRep id=0x0 magic=0x45291790 a1 e2 73 95]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [CHAP Success id=0x1 ""]
May  9 18:49:07 AppName1 pppd[1640]: CHAP authentication succeeded
May  9 18:49:07 AppName1 pppd[1640]: CHAP authentication succeeded
May  9 18:49:07 AppName1 pppd[1640]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
May  9 18:49:07 AppName1 pppd[1640]: 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>]
May  9 18:49:07 AppName1 pppd[1640]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
May  9 18:49:07 AppName1 pppd[1640]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
May  9 18:49:10 AppName1 pppd[1640]: 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>]
May  9 18:49:13 AppName1 pppd[1640]: 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>]
May  9 18:49:16 AppName1 pppd[1640]: 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>]
May  9 18:49:19 AppName1 pppd[1640]: 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>]
May  9 18:49:22 AppName1 pppd[1640]: 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>]
May  9 18:49:25 AppName1 pppd[1640]: 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>]
May  9 18:49:28 AppName1 pppd[1640]: 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>]
May  9 18:49:31 AppName1 pppd[1640]: 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>]
May  9 18:49:32 AppName1 dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 7
May  9 18:49:34 AppName1 pppd[1640]: 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>]
May  9 18:49:37 AppName1 pppd[1640]: sent [LCP EchoReq id=0x1 magic=0xa1e27395]
May  9 18:49:37 AppName1 pppd[1640]: IPCP: timeout sending Config-Requests
May  9 18:49:37 AppName1 pppd[1640]: sent [LCP TermReq id=0x2 "No network protocols running"]
May  9 18:49:39 AppName1 dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 14
May  9 18:49:40 AppName1 pppd[1640]: sent [LCP TermReq id=0x3 "No network protocols running"]
May  9 18:49:43 AppName1 pppd[1640]: Connection terminated.
May  9 18:49:43 AppName1 pppd[1640]: Modem hangup

为了进行比较,以下是正常工作的设备的日志:

May  9 20:00:15 AppName1 kernel: [   72.451218] 
May  9 20:00:16 AppName1 pppd[1406]: pppd 2.4.6 started by root, uid 0
May  9 20:00:16 AppName1 pppd[1406]: using channel 1
May  9 20:00:16 AppName1 pppd[1406]: Using interface ppp0
May  9 20:00:16 AppName1 pppd[1406]: Connect: ppp0 <--> /dev/ttyUSB3
May  9 20:00:16 AppName1 pppd[1406]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x21e96b39> <pcomp> <accomp>]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x451c1623> <pcomp> <accomp>]
May  9 20:00:16 AppName1 pppd[1406]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x451c1623> <pcomp> <accomp>]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x21e96b39> <pcomp> <accomp>]
May  9 20:00:16 AppName1 pppd[1406]: sent [LCP EchoReq id=0x0 magic=0x21e96b39]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [LCP DiscReq id=0x1 magic=0x451c1623]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [CHAP Challenge id=0x1 <38f21dc5a29f0931d45dcf6e204219f0>, name = "UMTS_CHAP_SRVR"]
May  9 20:00:16 AppName1 pppd[1406]: sent [CHAP Response id=0x1 <c50702c97f49e37f8e9b519ed363086e>, name = "AppName1"]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [LCP EchoRep id=0x0 magic=0x451c1623 21 e9 6b 39]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [CHAP Success id=0x1 ""]
May  9 20:00:16 AppName1 pppd[1406]: CHAP authentication succeeded
May  9 20:00:16 AppName1 pppd[1406]: CHAP authentication succeeded
May  9 20:00:16 AppName1 pppd[1406]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
May  9 20:00:16 AppName1 pppd[1406]: 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>]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
May  9 20:00:16 AppName1 pppd[1406]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
May  9 20:00:16 AppName1 pppd[1406]: rcvd [IPCP ConfReq id=0x0]
May  9 20:00:16 AppName1 pppd[1406]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
May  9 20:00:16 AppName1 pppd[1406]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [IPCP ConfReq id=0x1]
May  9 20:00:16 AppName1 pppd[1406]: sent [IPCP ConfAck id=0x1]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [IPCP ConfNak id=0x2 <addr 100.77.21.211> <ms-dns1 130.244.127.161> <ms-dns2 130.244.127.169>]
May  9 20:00:16 AppName1 pppd[1406]: sent [IPCP ConfReq id=0x3 <addr 100.77.21.211> <ms-dns1 130.244.127.161> <ms-dns2 130.244.127.169>]
May  9 20:00:16 AppName1 pppd[1406]: rcvd [IPCP ConfAck id=0x3 <addr 100.77.21.211> <ms-dns1 130.244.127.161> <ms-dns2 130.244.127.169>]
May  9 20:00:16 AppName1 pppd[1406]: Could not determine remote IP address: defaulting to 10.64.64.64
May  9 20:00:16 AppName1 pppd[1406]: local  IP address 100.77.21.211
May  9 20:00:16 AppName1 pppd[1406]: remote IP address 10.64.64.64
May  9 20:00:16 AppName1 pppd[1406]: primary   DNS address 130.244.127.161
May  9 20:00:16 AppName1 pppd[1406]: secondary DNS address 130.244.127.169
May  9 20:00:16 AppName1 pppd[1406]: Script /etc/ppp/ip-up started (pid 1413)
May  9 20:00:16 AppName1 pppd[1406]: Script /etc/ppp/ip-up finished (pid 1413), status = 0x0
May  9 20:00:18 AppName1 ntpd_intres[1222]: DNS 0.debian.pool.ntp.org -> 91.209.0.17
May  9 20:00:18 AppName1 ntpd_intres[1222]: DNS 1.debian.pool.ntp.org -> 83.251.208.60
May  9 20:00:18 AppName1 ntpd_intres[1222]: DNS 2.debian.pool.ntp.org -> 91.216.111.52
May  9 20:00:18 AppName1 dhclient: No DHCPOFFERS received.
May  9 20:00:18 AppName1 dhclient: No working leases in persistent database - sleeping.
May  9 20:00:18 AppName1 ifplugd(eth0)[946]: client: No DHCPOFFERS received.
May  9 20:00:18 AppName1 ifplugd(eth0)[946]: client: No working leases in persistent database - sleeping.
May  9 20:00:18 AppName1 ntpd[1214]: Listen normally on 3 ppp0 100.77.21.211 UDP 123
May  9 20:00:18 AppName1 ntpd[1214]: 91.216.111.52 interface 10.0.0.18 -> 100.77.21.211
May  9 20:00:18 AppName1 ntpd[1214]: 83.251.208.60 interface 10.0.0.18 -> 100.77.21.211
May  9 20:00:18 AppName1 ntpd[1214]: 91.209.0.17 interface 10.0.0.18 -> 100.77.21.211
May  9 20:00:18 AppName1 ntpd[1214]: peers refreshed
May  9 20:00:18 AppName1 ntpd_intres[1222]: DNS 3.debian.pool.ntp.org -> 31.220.5.58
May  9 20:00:19 AppName1 ntpdate[1441]: the NTP socket is in use, exiting
May  9 20:00:19 AppName1 ifplugd(eth0)[946]: Program executed successfully.

有什么线索可能导致此问题吗?

相关内容