Device ttyUSB4 is locked while doing reconnection service

End-of-Life Product 3G-4G/LTE Base Shield
1

Hi, For Raspberrypi 3, we use Sixfab 3G-4G/LTE Base Shield v2. We selected the Auto-reconnect option. After booting up the raspberrypi, reconnect.service is executing and it calls reconnect.sh script which is checking for network by pinging 8.8.8.8 DNS server. We sometimes receiving “Could not determine remote IP address: defaulting to 10.64.64.64” error.

In script we actually runs "sudo pon "when there is problem in internet connection like above mentioned error. As script checks for network every 10 secs, script runs “sudo pon” again when there is any internet connection problem.That time i am receiving “System ttyUSB4 is locked by pid 633””. Can you make me understand how this reconnection works behind. Will this “pon” process exits itself after sometime or else we have to stop it manually.

Logs:

Apr 14 14:47:01 raspberrypi kernel: [ 7.451500] PPP generic driver version 2.4.2
Apr 14 14:47:01 raspberrypi pppd[503]: pppd options in effect:
Apr 14 14:47:01 raspberrypi pppd[503]: debug#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: updetach#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: dump#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: noauth#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: remotename 3gppp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: /dev/ttyUSB4#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: 115200#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: lock#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: connect chat -s -v -f /etc/chatscripts/chat-connect -T vzwinternet#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: disconnect chat -s -v -f /etc/chatscripts/chat-disconnect#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: nocrtscts#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: modem#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: asyncmap 0#011#011# (from /etc/ppp/options)
Apr 14 14:47:01 raspberrypi pppd[503]: lcp-echo-failure 4#011#011# (from /etc/ppp/options)
Apr 14 14:47:01 raspberrypi pppd[503]: lcp-echo-interval 30#011#011# (from /etc/ppp/options)
Apr 14 14:47:01 raspberrypi pppd[503]: hide-password#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: novj#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: novjccomp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: ipcp-accept-local#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: ipcp-accept-remote#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: ipparam 3gppp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: noipdefault#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: ipcp-max-failure 30#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: defaultroute#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: usepeerdns#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: noccp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:01 raspberrypi pppd[503]: noipx#011#011# (from /etc/ppp/options)
Apr 14 14:47:01 raspberrypi pppd[503]: pppd 2.4.7 started by root, uid 0
Apr 14 14:47:02 raspberrypi chat[554]: abort on (BUSY)
Apr 14 14:47:02 raspberrypi chat[554]: abort on (NO CARRIER)
Apr 14 14:47:02 raspberrypi chat[554]: abort on (NO DIALTONE)
Apr 14 14:47:02 raspberrypi chat[554]: abort on (ERROR)
Apr 14 14:47:02 raspberrypi chat[554]: abort on (NO ANSWER)
Apr 14 14:47:02 raspberrypi chat[554]: timeout set to 30 seconds
Apr 14 14:47:02 raspberrypi chat[554]: send (AT^M)
Apr 14 14:47:02 raspberrypi chat[554]: expect (OK)
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: OK
Apr 14 14:47:02 raspberrypi chat[554]: – got it
Apr 14 14:47:02 raspberrypi chat[554]: send (ATE0^M)
Apr 14 14:47:02 raspberrypi chat[554]: expect (OK)
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: OK
Apr 14 14:47:02 raspberrypi chat[554]: – got it
Apr 14 14:47:02 raspberrypi chat[554]: send (ATI;+CSUB;+CSQ;+COPS?;+CGREG?;&D2^M)
Apr 14 14:47:02 raspberrypi chat[554]: expect (OK)
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: Quectel^M
Apr 14 14:47:02 raspberrypi chat[554]: EC25^M
Apr 14 14:47:02 raspberrypi chat[554]: Revision: EC25VFAR02A11M4G^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: SubEdition: V06^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: +CSQ: 99,99^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: +COPS: 0^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: +CGREG: 0,2^M
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:02 raspberrypi chat[554]: OK
Apr 14 14:47:02 raspberrypi chat[554]: – got it
Apr 14 14:47:02 raspberrypi chat[554]: send (AT+CGDCONT=1,“IP”,“vzwinternet”,0,0^M)
Apr 14 14:47:02 raspberrypi chat[554]: expect (OK)
Apr 14 14:47:02 raspberrypi chat[554]: ^M
Apr 14 14:47:03 raspberrypi chat[554]: ^M
Apr 14 14:47:03 raspberrypi chat[554]: OK
Apr 14 14:47:03 raspberrypi chat[554]: – got it
Apr 14 14:47:03 raspberrypi chat[554]: send (ATD*99#^M)
Apr 14 14:47:03 raspberrypi chat[554]: expect (CONNECT)
Apr 14 14:47:03 raspberrypi chat[554]: ^M
Apr 14 14:47:03 raspberrypi chat[554]: ^M
Apr 14 14:47:03 raspberrypi chat[554]: CONNECT
Apr 14 14:47:03 raspberrypi chat[554]: – got it
Apr 14 14:47:03 raspberrypi pppd[503]: Script chat -s -v -f /etc/chatscripts/chat-connect -T vzwinternet finished (pid 553), status = 0x0
Apr 14 14:47:03 raspberrypi pppd[503]: Serial connection established.
Apr 14 14:47:03 raspberrypi pppd[503]: using channel 1
Apr 14 14:47:03 raspberrypi pppd[503]: Using interface ppp0
Apr 14 14:47:03 raspberrypi pppd[503]: Connect: ppp0 <–> /dev/ttyUSB4
Apr 14 14:47:04 raspberrypi pppd[503]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x80f178eb> ]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [LCP ConfReq id=0xc1 <asyncmap 0x0> <magic 0xb956112e> ]
Apr 14 14:47:04 raspberrypi pppd[503]: No auth is possible
Apr 14 14:47:04 raspberrypi pppd[503]: sent [LCP ConfRej id=0xc1 ]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x80f178eb> ]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [LCP ConfReq id=0xc2 <asyncmap 0x0> <magic 0xb956112e> ]
Apr 14 14:47:04 raspberrypi pppd[503]: sent [LCP ConfAck id=0xc2 <asyncmap 0x0> <magic 0xb956112e> ]
Apr 14 14:47:04 raspberrypi pppd[503]: sent [LCP EchoReq id=0x0 magic=0x80f178eb]
Apr 14 14:47:04 raspberrypi pppd[503]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [LCP DiscReq id=0xc3 magic=0xb956112e]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [LCP EchoRep id=0x0 magic=0xb956112e 80 f1 78 eb]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [IPCP ConfReq id=0xc6]
Apr 14 14:47:04 raspberrypi pppd[503]: sent [IPCP ConfNak id=0xc6 <addr 0.0.0.0>]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [IPCP ConfNak id=0x1 <addr 100.88.171.222> <ms-dns1 198.224.173.135> <ms-dns2 198.224.174.135>]
Apr 14 14:47:04 raspberrypi pppd[503]: sent [IPCP ConfReq id=0x2 <addr 100.88.171.222> <ms-dns1 198.224.173.135> <ms-dns2 198.224.174.135>]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [IPCP ConfReq id=0xc7]
Apr 14 14:47:04 raspberrypi pppd[503]: sent [IPCP ConfAck id=0xc7]
Apr 14 14:47:04 raspberrypi pppd[503]: rcvd [IPCP ConfAck id=0x2 <addr 100.88.171.222> <ms-dns1 198.224.173.135> <ms-dns2 198.224.174.135>]
Apr 14 14:47:04 raspberrypi pppd[503]: Could not determine remote IP address: defaulting to 10.64.64.64
Apr 14 14:47:04 raspberrypi pppd[503]: local IP address 100.88.171.222
Apr 14 14:47:04 raspberrypi pppd[503]: remote IP address 10.64.64.64
Apr 14 14:47:04 raspberrypi pppd[503]: primary DNS address 198.224.173.135
Apr 14 14:47:04 raspberrypi pppd[503]: secondary DNS address 198.224.174.135
Apr 14 14:47:04 raspberrypi pppd[633]: Script /etc/ppp/ip-up started (pid 634)
Apr 14 14:47:04 raspberrypi pppd[633]: Script /etc/ppp/ip-up finished (pid 634), status = 0x0

Apr 14 14:47:34 raspberrypi sh[448]: PING 8.8.8.8 (8.8.8.8) from 100.88.171.222 ppp0: 0(28) bytes of data.
Apr 14 14:47:34 raspberrypi sh[448]: — 8.8.8.8 ping statistics —
Apr 14 14:47:34 raspberrypi sh[448]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms
Apr 14 14:47:34 raspberrypi sh[448]: Connection down, reconnecting…
Apr 14 14:47:34 raspberrypi sh[448]: ttyUSB4
Apr 14 14:47:34 raspberrypi sh[448]: else ttyUSB4
Apr 14 14:47:34 raspberrypi sh[448]: /dev/ttyUSB4
Apr 14 14:47:34 raspberrypi pppd[747]: pppd options in effect:
Apr 14 14:47:34 raspberrypi pppd[747]: debug#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: updetach#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: dump#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: noauth#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: remotename 3gppp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: /dev/ttyUSB4#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: 115200#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: lock#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: connect chat -s -v -f /etc/chatscripts/chat-connect -T vzwinternet#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: disconnect chat -s -v -f /etc/chatscripts/chat-disconnect#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: nocrtscts#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: modem#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: asyncmap 0#011#011# (from /etc/ppp/options)
Apr 14 14:47:34 raspberrypi pppd[747]: lcp-echo-failure 4#011#011# (from /etc/ppp/options)
Apr 14 14:47:34 raspberrypi pppd[747]: lcp-echo-interval 30#011#011# (from /etc/ppp/options)
Apr 14 14:47:34 raspberrypi pppd[747]: hide-password#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: novj#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: novjccomp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: ipcp-accept-local#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: ipcp-accept-remote#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: ipparam 3gppp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: noipdefault#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: ipcp-max-failure 30#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: defaultroute#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: usepeerdns#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: noccp#011#011# (from /etc/ppp/peers/provider)
Apr 14 14:47:34 raspberrypi pppd[747]: noipx#011#011# (from /etc/ppp/options)
Apr 14 14:47:34 raspberrypi pppd[747]: pppd 2.4.7 started by root, uid 0
Apr 14 14:47:34 raspberrypi pppd[747]: Device ttyUSB4 is locked by pid 633
Apr 14 14:47:34 raspberrypi pppd[747]: Exit.

2

Hi @sai.charitha,
Can I ask why you have not set the device communication port to ttyUSB3?
Can you see ppp0 in ifconfig output?
If yes, Did you try to ping using ppp0 interface?

3

Hi @ensar,

  1. Actually ttyusb0 is connected to another serial device. so sixfab is connected to ttyUSB4

Logs: add [ 3.034278] ftdi_sio 1-1.2:1.0: FTDI USB Serial Device converter detected[ 3.034431] usb 1-1.2: Detected FT232RL
[ 3.073429] usb 1-1.2: FTDI USB Serial Device converter now attached to ttyUSB0
[ 3.168540] usbcore: registered new interface driver option
[ 3.168621] usbserial: USB Serial support registered for GSM modem (1-port)
[ 3.169337] option 1-1.5:1.0: GSM modem (1-port) converter detected
[ 3.174178] usb 1-1.5: GSM modem (1-port) converter now attached to ttyUSB1
[ 3.174593] option 1-1.5:1.1: GSM modem (1-port) converter detected
[ 3.177218] usb 1-1.5: GSM modem (1-port) converter now attached to ttyUSB2
[ 3.177642] option 1-1.5:1.2: GSM modem (1-port) converter detected
[ 3.178057] usb 1-1.5: GSM modem (1-port) converter now attached to ttyUSB3
[ 3.188099] option 1-1.5:1.3: GSM modem (1-port) converter detected
[ 3.189194] usb 1-1.5: GSM modem (1-port) converter now attached to ttyUSB4

  1. Actually, Raspberrypi is connected remotely, we are not capturing the config ppp0 output in our logs. And after a restart of raspberry pi it got connected to the internet. we actually want to know what is the reason for the below output.
    Logs: Apr 14 14:47:02 raspberrypi chat[554]: +CSQ: 99,99^M
    Apr 14 14:47:02 raspberrypi chat[554]: ^M
    Apr 14 14:47:02 raspberrypi chat[554]: +COPS: 0^M
    Apr 14 14:47:02 raspberrypi chat[554]: ^M
    Apr 14 14:47:02 raspberrypi chat[554]: +CGREG: 0,2^M
    Apr 14 14:47:02 raspberrypi chat[554]: ^M

  2. In reconnect.sh script, we tried to ping the with ppp0 interface.

Logs: Apr 14 14:47:34 raspberrypi sh[448]: PING 8.8.8.8 (8.8.8.8) from 100.88.171.222 ppp0: 0(28) bytes of data.
Apr 14 14:47:34 raspberrypi sh[448]: — 8.8.8.8 ping statistics —
Apr 14 14:47:34 raspberrypi sh[448]: 1 packets transmitted, 0 received, 100% packet loss, time 0ms
Apr 14 14:47:34 raspberrypi sh[448]: Connection down, reconnecting…

4

Oops!
Firstly,

+CGREG: 0,2 / +CGREG: 0,0
+COPS: 0

indicates, you are not registered on the network. Make sure your ISP supports EG25.

The signal strength is unknown or undetectable.Please try with different antenna.

0 -113dBm or less
1 -111dBm
2…30 -109dBm… -53dBm
31 -51dBm or greater
99 Not known or not detectable
100 -116dBm or less
101-115dBm
…

More details: EC25 AT Commands Manual