pppd hangs on OCG-E G2 GP

[Michael Leatherman]

Hello,

I’m using the OCG-E to provide non-persistent Internet access when the OCG-E detects an event via Ethernet or an ADC line. I’m calling “pppd call gsm nodetach nopersist” from the command line. When I’m done, I call “killall pppd.” I pulled these commands directly from the MultiConnect SDK for Java.

pppd connects the first time without any problem. After the first run, however, I cannot connect again. The first reconnect hangs when it tries to dial out. Subsequent connections hang when sending the first AT command.

As a workaround, I’m calling “stty -F /dev/ttyS1 clocal 9600 && echo “AT^M” > /dev/ttyS1″ after each disconnect. I think data is getting stuck in the modem because if I bring up minicom and hit enter, I get an error. If I send “AT” after the initial error in minicom, it works fine. Running minicom with initialization also seems to clear it up.

This behavior is exhibited on two different OCG-Es. One is running CoreCDP 2.2.2 (from the MT website) and one is running CoreCDP 2.0.2 (pre-installed).

Has this behavior been seen anywhere else? Is there a better solution than resetting the serial port each time?

Thanks.

[Lonny Knudson]

Hi Michael,

This behavior is unusual, I can’t think of an explanation based on the information provided so far.

Could you post a copy of the gsm peer file, the chat script and some logs showing the events when you attempt to redial?

[Michael Leatherman]

/etc/ppp/peers/gsm:

linkname ppp0

230400

defaultroute

replacedefaultroute

usepeerdns

ipcp-max-failure 4

ipcp-restart 10

noauth

crtscts

novj

connect ‘/usr/sbin/chat -v -t 90 -f /etc/ppp/peers/gsm_chat’

/etc/ppp/peers/gsm_chat:

SAY “GSM chatn”

ECHO OFF

ABORT ‘NO DIAL TONE’

ABORT ‘NO DIALTONE’

ABORT ‘NO ANSWER’

ABORT ‘NO CARRIER’

ABORT ‘DELAYED’

ABORT ‘VOICE’

ABORT ‘BUSY’

” ‘AT’

OK ‘ATZ’

OK ‘AT+CSQ’

#OK ‘AT+CGDCONT=1,”IP”,”proxy”‘

#OK ‘AT+CGDCONT=1,”IP”,”ISP.CINGULAR”‘

#OK ‘AT+CGDCONT=1,”IP”,”internet2.voicestream.com”‘

#OK ‘AT+CGDCONT=1,”IP”,”internet”‘

SAY “Dialing…n”

#OK ‘ATD*99#’

OK ‘ATD*99***1#’

SAY “Waiting for CONNECT…n”

TIMEOUT 120

CONNECT ”

SAY “Connectedn”

/var/log/messages:

Nov 11 00:44:05 mt100eocg daemon.notice pppd[361]: pppd 2.4.5 started by root, uid 0

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (NO DIAL TONE)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (NO DIALTONE)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (NO ANSWER)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (NO CARRIER)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (DELAYED)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (VOICE)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: abort on (BUSY)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: send (AT^M)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: expect (OK)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: AT^M^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: OK

Nov 11 00:44:06 mt100eocg local2.info chat[365]: — got it

Nov 11 00:44:06 mt100eocg local2.info chat[365]: send (ATZ^M)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: expect (OK)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: ^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: ATZ^M^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: OK

Nov 11 00:44:06 mt100eocg local2.info chat[365]: — got it

Nov 11 00:44:06 mt100eocg local2.info chat[365]: send (AT+CSQ^M)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: expect (OK)

Nov 11 00:44:06 mt100eocg local2.info chat[365]: ^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: AT+CSQ^M^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: +CSQ: 6,1^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: ^M

Nov 11 00:44:06 mt100eocg local2.info chat[365]: OK

Nov 11 00:44:06 mt100eocg local2.info chat[365]: — got it

Nov 11 00:44:06 mt100eocg local2.info chat[365]: send (ATD*99***1#^M)

Nov 11 00:44:07 mt100eocg local2.info chat[365]: timeout set to 120 seconds

Nov 11 00:44:07 mt100eocg local2.info chat[365]: expect (CONNECT)

Nov 11 00:44:07 mt100eocg local2.info chat[365]: ^M

Nov 11 00:44:07 mt100eocg local2.info chat[365]: ATD*99***1#^M^M

Nov 11 00:44:07 mt100eocg local2.info chat[365]: CONNECT

Nov 11 00:44:07 mt100eocg local2.info chat[365]: — got it

Nov 11 00:44:07 mt100eocg local2.info chat[365]: send (^M)

Nov 11 00:44:07 mt100eocg daemon.info pppd[361]: Serial connection established.

Nov 11 00:44:07 mt100eocg daemon.info pppd[361]: Using interface ppp0

Nov 11 00:44:07 mt100eocg daemon.notice pppd[361]: Connect: ppp0 <–> /dev/ttyS1

Nov 11 00:44:11 mt100eocg daemon.info pppd[361]: Remote message: Welcome!

Nov 11 00:44:11 mt100eocg daemon.notice pppd[361]: PAP authentication succeeded

Nov 11 00:44:11 mt100eocg daemon.warn pppd[361]: kernel does not support PPP filtering

Nov 11 00:44:11 mt100eocg daemon.notice pppd[361]: local IP address 32.178.80.137

Nov 11 00:44:11 mt100eocg daemon.notice pppd[361]: remote IP address 192.168.111.111

Nov 11 00:44:11 mt100eocg daemon.notice pppd[361]: primary DNS address 209.183.33.23

Nov 11 00:44:11 mt100eocg daemon.notice pppd[361]: secondary DNS address 209.183.35.23

Nov 11 00:44:24 mt100eocg daemon.info pppd[361]: Terminating on signal 2

Nov 11 00:44:24 mt100eocg daemon.info pppd[361]: Connect time 0.3 minutes.

Nov 11 00:44:24 mt100eocg daemon.info pppd[361]: Sent 0 bytes, received 0 bytes.

Nov 11 00:44:24 mt100eocg daemon.notice pppd[361]: Connection terminated.

Nov 11 00:44:25 mt100eocg daemon.info pppd[361]: Exit.

Nov 11 00:44:28 mt100eocg daemon.notice pppd[394]: pppd 2.4.5 started by root, uid 0

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (NO DIAL TONE)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (NO DIALTONE)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (NO ANSWER)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (NO CARRIER)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (DELAYED)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (VOICE)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: abort on (BUSY)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: send (AT^M)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: expect (OK)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: ^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: OK

Nov 11 00:44:29 mt100eocg local2.info chat[398]: — got it

Nov 11 00:44:29 mt100eocg local2.info chat[398]: send (ATZ^M)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: expect (OK)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: HxAT^M^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: OK

Nov 11 00:44:29 mt100eocg local2.info chat[398]: — got it

Nov 11 00:44:29 mt100eocg local2.info chat[398]: send (AT+CSQ^M)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: expect (OK)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: ^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: ATZ^MAT+CSQ^M^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: OK

Nov 11 00:44:29 mt100eocg local2.info chat[398]: — got it

Nov 11 00:44:29 mt100eocg local2.info chat[398]: send (ATD*99***1#^M)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: timeout set to 120 seconds

Nov 11 00:44:29 mt100eocg local2.info chat[398]: expect (CONNECT)

Nov 11 00:44:29 mt100eocg local2.info chat[398]: ^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: AT^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: +CSQ: 6,1^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: ^M

Nov 11 00:44:29 mt100eocg local2.info chat[398]: OK^M

Nov 11 00:46:29 mt100eocg local2.info chat[398]: alarm

Nov 11 00:46:29 mt100eocg local2.info chat[398]: Failed

Nov 11 00:46:29 mt100eocg daemon.err pppd[394]: Connect script failed

Nov 11 00:46:30 mt100eocg daemon.info pppd[394]: Exit.

Nov 11 00:46:34 mt100eocg daemon.notice pppd[399]: pppd 2.4.5 started by root, uid 0

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (NO DIAL TONE)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (NO DIALTONE)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (NO ANSWER)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (NO CARRIER)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (DELAYED)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (VOICE)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: abort on (BUSY)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: send (AT^M)

Nov 11 00:46:35 mt100eocg local2.info chat[403]: expect (OK)

Nov 11 00:48:05 mt100eocg local2.info chat[403]: alarm

Nov 11 00:48:05 mt100eocg local2.info chat[403]: Failed

Nov 11 00:48:05 mt100eocg daemon.err pppd[399]: Connect script failed

Nov 11 00:48:06 mt100eocg daemon.info pppd[399]: Exit.

stdout:

# pppd call gsm nodetach nopersist

GSM chat

Dialing…

Waiting for CONNECT…

Connected

Serial connection established.

Using interface ppp0

Connect: ppp0 <–> /dev/ttyS1

Remote message: Welcome!

PAP authentication succeeded

kernel does not support PPP filtering

local IP address 32.178.80.137

remote IP address 192.168.111.111

primary DNS address 209.183.33.23

secondary DNS address 209.183.35.23

Terminating on signal 2

Connect time 0.3 minutes.

Sent 0 bytes, received 0 bytes.

Connection terminated.

# pppd call gsm nodetach nopersist

GSM chat

Dialing…

Waiting for CONNECT…

Connect script failed

# pppd call gsm nodetach nopersist

GSM chat

Connect script failed

#

[Michael Leatherman]

I updated the gsm file to use 115200 as the baud rate and it’s working better so far. I’m getting disconnected by the remote peer every so often, but I’m not hanging.

[Lonny Knudson]

Hi Michael,

I see in the chat log that the +CSQ command is reporting a pretty low signal strength, this may be why the link is disconnecting. An idle timer or a session timer implemented by the carrier would cause a disconnection as well.

I’m not sure why changing the serial baud rate appears to correct the no response condition. Could you use a terminal program and issue AT&V to the modem and post the response ?

[Michael Leatherman]

From minicom:

 

 

AT&V

Q:0 V:1 S0:000 S2:043 S3:013 S4:010 S5:008

+CR:0 +CRC:0 +CMEE:0 +CBST:0,0,1

+SPEAKER:1 +ECHO:0 &C:1 &D:2 %C:0

+IPR:0 +ICF:3,4 +IFC:2,2

OK

[Lonny Knudson]

Hi Michael,

You may want to try to disable autobaud on the cell modem. This is done with the +IPR command (AT+IPR=230400). If you want to give this a try don’t forget to change the baud rate option in the /etc/ppp/peers/gsm file back to 230400.

[Michael Leatherman]

That seems to have done the trick. I’ve started it repeatedly about 10 times with no hangs.

Thanks for the help.

[Author]

Posts