Announcement

Collapse
No announcement yet.

PPPD: No response from peer during IPCP negotiation.

Collapse
This topic is closed.
X
X
Collapse
 
  • Page of 1
  • Filter
  • Time
  • Show
Clear All
new posts
Previous template Next
    #1

    PPPD: No response from peer during IPCP negotiation.

    I'm having a problem with establishing PPP connection over GPRS (modem Telit GM862-QUAD) on embedded Linux (kernel 2.6.27.15) running on SAM9 processor. In most cases I can establish connection successfully, but in random cases during IPCP negotiation peer stops responding and after 3 LCP EchoReq timeouts serial link is assumed to be down. In all of these failed connection attempts the last message received from peer is always the same:
    May 17 15:20:36 abcd daemon.debug pppd[3732]: rcvd [IPCP ConfReq id=0x1 <addr 10.120.196.51>]

    This log looks always same:

    Code:
    May 18 08:13:37 abcd daemon.notice pppd[1117]: pppd 2.4.5 started by root, uid 0           
May 18 08:13:38 abcd local2.info chat[1131]: abort on (BUSY)
May 18 08:13:38 abcd local2.info chat[1131]: abort on (ERROR)
May 18 08:13:38 abcd local2.info chat[1131]: abort on (NO ANSWER)
May 18 08:13:38 abcd local2.info chat[1131]: abort on (NO CARRIER)
May 18 08:13:38 abcd local2.info chat[1131]: abort on (NO DIALTONE)
May 18 08:13:38 abcd local2.info chat[1131]: send (AT^M)
May 18 08:13:38 abcd local2.info chat[1131]: expect (OK)
May 18 08:13:38 abcd local2.info chat[1131]: ^M
May 18 08:13:38 abcd local2.info chat[1131]: OK
May 18 08:13:38 abcd local2.info chat[1131]: -- got it
May 18 08:13:38 abcd local2.info chat[1131]: send (AT+CGDCONT=1,"IP","erainternet"^M)
May 18 08:13:39 abcd local2.info chat[1131]: expect (OK)
May 18 08:13:39 abcd local2.info chat[1131]: ^M
May 18 08:13:39 abcd local2.info chat[1131]: ^M
May 18 08:13:39 abcd local2.info chat[1131]: OK
May 18 08:13:39 abcd local2.info chat[1131]: -- got it
May 18 08:13:39 abcd local2.info chat[1131]: send (ATD*99***1#^M)
May 18 08:13:39 abcd local2.info chat[1131]: expect (CONNECT)
May 18 08:13:39 abcd local2.info chat[1131]: ^M
May 18 08:13:39 abcd local2.info chat[1131]: ^M
May 18 08:13:39 abcd local2.info chat[1131]: CONNECT
May 18 08:13:39 abcd local2.info chat[1131]: -- got it
May 18 08:13:39 abcd local2.info chat[1131]: send (^M)
May 18 08:13:39 abcd daemon.debug pppd[1117]: Script chat -V -v -t 15 -T erainternet -f /etc/ppp/modem.chat finished (pid 1130), status = 0x0
May 18 08:13:39 abcd daemon.info pppd[1117]: Serial connection established.
May 18 08:13:39 abcd daemon.debug pppd[1117]: using channel 5
May 18 08:13:39 abcd daemon.info pppd[1117]: Using interface ppp0
May 18 08:13:39 abcd daemon.notice pppd[1117]: Connect: ppp0 <--> /dev/ttyS1
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x88128b5f> <pcomp> <accomp>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: rcvd [LCP ConfRej id=0x1 <pcomp> <accomp>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [LCP ConfReq id=0x2 <asyncmap 0x0> <magic 0x88128b5f>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0x7cd90400>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth pap> <magic 0x7cd90400>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <magic 0x88128b5f>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [LCP EchoReq id=0x0 magic=0x88128b5f]
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [PAP AuthReq id=0x1 user="erainternet" password=<hidden>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: rcvd [LCP EchoRep id=0x0 magic=0xcfd90400]
May 18 08:13:40 abcd daemon.debug pppd[1117]: rcvd [PAP AuthAck id=0x1 "Welcome!"]
May 18 08:13:40 abcd daemon.info pppd[1117]: Remote message: Welcome!
May 18 08:13:40 abcd daemon.notice pppd[1117]: PAP authentication succeeded
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: rcvd [IPCP ConfReq id=0x1 <addr 10.120.197.31>]
May 18 08:13:40 abcd daemon.debug pppd[1117]: sent [IPCP ConfAck id=0x1 <addr 10.120.197.31>]
May 18 08:13:43 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:13:46 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:13:49 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:13:50 abcd daemon.debug pppd[1117]: sent [LCP EchoReq id=0x1 magic=0x88128b5f]
May 18 08:13:52 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:13:55 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:13:58 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:14:00 abcd daemon.debug pppd[1117]: sent [LCP EchoReq id=0x2 magic=0x88128b5f]
May 18 08:14:01 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:14:04 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:14:07 abcd daemon.debug pppd[1117]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
May 18 08:14:10 abcd daemon.info pppd[1117]: No response to 2 echo-requests
May 18 08:14:10 abcd daemon.notice pppd[1117]: Serial link appears to be disconnected.
May 18 08:14:10 abcd daemon.debug pppd[1117]: sent [LCP TermReq id=0x3 "Peer not responding"]
May 18 08:14:13 abcd daemon.debug pppd[1117]: sent [LCP TermReq id=0x4 "Peer not responding"]
May 18 08:14:16 abcd daemon.notice pppd[1117]: Connection terminated.
May 18 08:14:17 abcd daemon.notice pppd[1117]: Modem hangup
May 18 08:14:17 abcd daemon.info pppd[1117]: Exit.
    I run pppd like this:
    Code:
    pppd /dev/ttyS1 115200 connect "chat -V -v -t 15 -T erainternet -f /etc/ppp/modem.chat" debug novj novjccomp lcp-echo-interval 20 lcp-echo-failure 3 nodetach maxfail 0 nocrtscts noccp defaultroute usepeerdns ipcp-accept-remote ipcp-accept-local noipdefault user erainternet password erainternet
    /etc/ppp/modem.chat:
    Code:
    # this script must be executed with -T argument to provide Access Point Name
ABORT "BUSY"
ABORT "ERROR"
ABORT "NO ANSWER"
ABORT "NO CARRIER"
ABORT "NO DIALTONE"
"" 'AT'
OK-\d\d+++\d\d\c-OK 'AT+CGDCONT=1,"IP","\T"'
OK 'ATD*99***1#'
CONNECT ' '

    I have prooved that described problem NEVER occurs when I try to establish connection on PC with Kubuntu 2.6.31-20-generic-pae. In both cases I used the same version of pppd, scripts and the same SIM card. I also used the same tty settings for serial devices (on PC modem is connected via USB-RS232 converter, whereas on SAM9 it is connected by UART). The only difference is that I have a slightly different modem (on PC Telit GT864-PY and on SAM9 GM862-QUAD).
    After more debugging I realized that I don't receive any more data from UART after this first sequence of IPCP messages.

    Does anyone know what could be the reason for such problem?
    Tags: None
    • Top
    • Bottom
Previous template Next
Working...
X