Modem hangup immediately after sending IPCP ConfReq after CHAP authentication succeeded, only occurs sometimes

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hello,

Have been trying to debug this issue for a while and am completely out of idea what to check or google, so I'll ask if anyone here has any idea.

The issue appear like this in /var/log/messages (I don't think it is important, but timestamp is ~9 minutes behind actual time):

                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: pppd options in effect:
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: debug debug             # (from /etc/ppp/peers/wvdial)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: -detach         # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: idle 0          # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: logfd 12                # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: dump            # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: noauth          # (from /etc/ppp/peers/wvdial)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: name .......os            # (from /etc/ppp/peers/wvdial)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: user dummy              # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: usehostname             # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: 115200          # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: lock            # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: crtscts         # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: modem           # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: novj            # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: novjccomp               # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: ipcp-accept-local               # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: ipcp-accept-remote              # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: noipdefault             # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: defaultroute            # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: usepeerdns              # (from command line)
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: noccp           # (from /etc/ppp/options)
                             Aug 14 05:02:06 .......os daemon.notice pppd[4595]: pppd 2.4.7 started by root, uid 0
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: using channel 4
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: Using interface ppp0
                             Aug 14 05:02:06 .......os daemon.notice pppd[4595]: Connect: ppp0 <--> /dev/ttyUSB3
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xf4c49356> <pcomp> <accomp>]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: rcvd [LCP ConfReq id=0x6 <asyncmap 0x0> <auth chap MD5> <magic 0xd0ea135c> <pcomp> <accomp>]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: sent [LCP ConfAck id=0x6 <asyncmap 0x0> <auth chap MD5> <magic 0xd0ea135c> <pcomp> <accomp>]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xf4c49356> <pcomp> <accomp>]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: rcvd [LCP DiscReq id=0x7 magic=0xd0ea135c]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: rcvd [CHAP Challenge id=0x1 <................................>, name = "UMTS_CHAP_SRVR"]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: sent [CHAP Response id=0x1 <................................>, name = "dummy"]
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: rcvd [CHAP Success id=0x1 ""]
                             Aug 14 05:02:06 .......os daemon.info pppd[4595]: CHAP authentication succeeded
                             Aug 14 05:02:06 .......os daemon.notice pppd[4595]: CHAP authentication succeeded
                             Aug 14 05:02:06 .......os daemon.debug pppd[4595]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
                             Aug 14 05:02:07 .......os daemon.notice pppd[4595]: Modem hangup
                             Aug 14 05:02:07 .......os daemon.notice pppd[4595]: Connection terminated.

For this device pppd is being started by wvdial, and I've confirmed APN is set correctly. Came across some forums posts saying to check the PDP context, but I haven't been able to figure out what about it I should check other than APN.
I've seen the issue occur very intermittently after moving the device (between different buildings which are couple hundred meters apart).
Recently it has occurred much more often on devices which are first powered and set up over ethernet without ppp being started, and then a few months later when devices are powered on again this issue occurs and LTE doesn't come up sometimes for hours. Sometimes I have been able to get LTE to connect by resetting the modem and rebooting, but sometimes that doesn't work. Usually this issue seems to go away after a few days, or shortly after a boot after a few few days.

In journald, the same problem appears like this:

                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: --> Initializing modem.
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: --> Sending: ATZ
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: ATZ
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: OK
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: --> Sending: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: OK
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: --> Sending: AT+CGDCONT=1,"IP","konecranes.com"
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: AT+CGDCONT=1,"IP","konecranes.com"
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: OK
                             Aug 14 06:18:48 .......os lte-starter.sh[37607]: --> Modem initialized.
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Initializing modem.
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Sending: ATZ
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: ATZ
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: OK
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Sending: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: ATQ0 V1 E1 S0=0 &C1 &D2 +FCLASS=0
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: OK
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Sending: AT+CGDCONT=1,"IP","konecranes.com"
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: AT+CGDCONT=1,"IP","konecranes.com"
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: OK
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Modem initialized.
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Sending: ATDT*99#
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Waiting for carrier.
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: ATDT*99#
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: CONNECT 115200
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Carrier detected.  Starting PPP immediately.
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Starting pppd at Wed Aug 14 06:18:58 2024
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Pid of pppd: 38303
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Using interface ppp0
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Authentication (CHAP) started
                             Aug 14 06:18:58 .......os lte-starter.sh[37607]: --> Authentication (CHAP) successful
                             Aug 14 06:18:59 .......os lte-starter.sh[37607]: --> Disconnecting at Wed Aug 14 06:18:59 2024
                             Aug 14 06:18:59 .......os lte-starter.sh[37607]: --> The PPP daemon has died: A modem hung up the phone (exit code = 16)
                             Aug 14 06:18:59 .......os lte-starter.sh[37607]: --> man pppd explains pppd error codes in more detail.
                             Aug 14 06:18:59 .......os lte-starter.sh[37607]: --> Try again and look into /var/log/messages and the wvdial and pppd man pages for more information.
                             Aug 14 06:18:59 .......os lte-starter.sh[37607]: --> Auto Reconnect will be attempted in 20 seconds

On another of the same device where LTE is functioning, output in /var/log/messages looks like:

                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: pppd 2.4.7 started by root, uid 0
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: using channel 1
                             Aug 13 23:21:23 .......os daemon.info pppd[3440]: Using interface ppp0
                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: Connect: ppp0 <--> /dev/ttyUSB3
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x665384a3> <pcomp> <accomp>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x8dfc8a02> <pcomp> <accomp>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x8dfc8a02> <pcomp> <accomp>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x665384a3> <pcomp> <accomp>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [LCP DiscReq id=0x1 magic=0x8dfc8a02]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [CHAP Challenge id=0x1 <................................>, name = "UMTS_CHAP_SRVR"]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [CHAP Response id=0x1 <................................>, name = "dummy"]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [CHAP Success id=0x1 ""]
                             Aug 13 23:21:23 .......os daemon.info pppd[3440]: CHAP authentication succeeded
                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: CHAP authentication succeeded
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: 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>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [IPCP ConfReq id=0x0]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [IPCP ConfReq id=0x1]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [IPCP ConfAck id=0x1]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [IPCP ConfNak id=0x2 <addr ..............> <ms-dns1 ..............> <ms-dns2 ..............>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: sent [IPCP ConfReq id=0x3 <addr ..............> <ms-dns1 ..............> <ms-dns2 ..............>]
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: rcvd [IPCP ConfAck id=0x3 <addr ..............> <ms-dns1 ..............> <ms-dns2 ..............>]
                             Aug 13 23:21:23 .......os daemon.warn pppd[3440]: Could not determine remote IP address: defaulting to ...........
                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: local  IP address ..............
                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: remote IP address ...........
                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: primary   DNS address ..............
                             Aug 13 23:21:23 .......os daemon.notice pppd[3440]: secondary DNS address ..............
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: Script /etc/ppp/ip-up started (pid 3448)
                             Aug 13 23:21:23 .......os daemon.debug pppd[3440]: Script /etc/ppp/ip-up finished (pid 3448), status = 0x0

Though here there are different options in /etc/ppp/options (the only options there are debug and lock for this device which is working), including lack of dump option. With the device where LTE isn't starting I tried copying some settings from another device because I thought it might have some relation to the failure to negotiate the compression.
Comparable /var/log/messages contents of the other device, which is also using quectel-ppp (becaues of using a different modem) to start pppd intead of wvdial:

                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: pppd options in effect:
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: debug debug             # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: nodetach                # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: dump            # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: noauth          # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: user $LTE_USERNAME              # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: password ??????         # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: remotename 3gppp                # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: /dev/ttyUSB3            # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: 115200          # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: lock            # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: connect /usr/sbin/chat -E -s -v -f /etc/ppp/peers/quectel-chat-connect          # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: disconnect /usr/sbin/chat -E -s -v -f /etc/ppp/peers/quectel-chat-disconnect            # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: crtscts         # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: local           # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: hide-password           # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: novj            # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: novjccomp               # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: ipcp-accept-local               # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: ipcp-accept-remote              # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: ipparam 3gppp           # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: noipdefault             # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: defaultroute            # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: replacedefaultroute             # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: usepeerdns              # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.info pppd[1507]: noccp           # (from /etc/ppp/peers/quectel-ppp)
                             Aug 13 22:02:10 .......os daemon.notice pppd[1507]: pppd 2.4.7 started by root, uid 0
                             Aug 13 22:02:10 .......os local2.info chat[1512]: abort on (BUSY)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: abort on (NO CARRIER)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: abort on (NO DIALTONE)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: abort on (ERROR)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: abort on (NO ANSWER)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: timeout set to 180 seconds
                             Aug 13 22:02:10 .......os local2.info chat[1512]: send (AT^M)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: AT^M^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:10 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:10 .......os local2.info chat[1512]: send (ATE0^M)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ATE0^M^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:10 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:10 .......os local2.info chat[1512]: send (ATI^M)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: Quectel^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: .....^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: Revision: ............^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:10 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:10 .......os local2.info chat[1512]: send (AT+CSQ^M)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: +CSQ: 23,99^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:10 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:10 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:10 .......os local2.info chat[1512]: send (AT+CPIN?^M)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: +CPIN: READY^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:11 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:11 .......os local2.info chat[1512]: send (AT+COPS?^M)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: +COPS: 0,2,"24405",7^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:11 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:11 .......os local2.info chat[1512]: send (AT+CGREG?^M)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: +CGREG: 0,5^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:11 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:11 .......os local2.info chat[1512]: send (ATZ^M)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:11 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:11 .......os local2.info chat[1512]: send (AT+CGDCONT=1,"IP","konecranes.com",,0,0^M)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: expect (OK)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: AT+CGDCONT=1,"IP","konecranes.com",,0,0^M^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: OK
                             Aug 13 22:02:11 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:11 .......os local2.info chat[1512]: send (ATDT*99#^M)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: expect (CONNECT)
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: ATDT*99#^M^M
                             Aug 13 22:02:11 .......os local2.info chat[1512]: CONNECT
                             Aug 13 22:02:11 .......os local2.info chat[1512]:  -- got it
                             Aug 13 22:02:11 .......os daemon.debug pppd[1507]: Script /usr/sbin/chat -E -s -v -f /etc/ppp/peers/quectel-chat-connect finished (pid 1512), status = 0x0
                             Aug 13 22:02:11 .......os daemon.info pppd[1507]: Serial connection established.
                             Aug 13 22:02:11 .......os daemon.debug pppd[1507]: using channel 1
                             Aug 13 22:02:11 .......os daemon.info pppd[1507]: Using interface ppp0
                             Aug 13 22:02:11 .......os daemon.notice pppd[1507]: Connect: ppp0 <--> /dev/ttyUSB3
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xb5ac4cf6> <pcomp> <accomp>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [LCP ConfReq id=0x4 <asyncmap 0x0> <auth chap MD5> <magic 0x8dde940b> <pcomp> <accomp>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [LCP ConfAck id=0x4 <asyncmap 0x0> <auth chap MD5> <magic 0x8dde940b> <pcomp> <accomp>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xb5ac4cf6> <pcomp> <accomp>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [LCP DiscReq id=0x5 magic=0x8dde940b]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [CHAP Challenge id=0x1 <................................>, name = "UMTS_CHAP_SRVR"]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [CHAP Response id=0x1 <................................>, name = "$LTE_USERNAME"]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [CHAP Success id=0x1 ""]
                             Aug 13 22:02:12 .......os daemon.info pppd[1507]: CHAP authentication succeeded
                             Aug 13 22:02:12 .......os daemon.notice pppd[1507]: CHAP authentication succeeded
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [IPCP ConfReq id=0x4]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [IPCP ConfNak id=0x4 <addr 0.0.0.0>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [IPCP ConfNak id=0x1 <addr ..............> <ms-dns1 ..............> <ms-dns2 ..............>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [IPCP ConfReq id=0x2 <addr ..............> <ms-dns1 ..............> <ms-dns2 ..............>]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [IPCP ConfReq id=0x5]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: sent [IPCP ConfAck id=0x5]
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: rcvd [IPCP ConfAck id=0x2 <addr ..............> <ms-dns1 ..............> <ms-dns2 ..............>]
                             Aug 13 22:02:12 .......os daemon.warn pppd[1507]: Could not determine remote IP address: defaulting to ...........
                             Aug 13 22:02:12 .......os daemon.notice pppd[1507]: local  IP address ..............
                             Aug 13 22:02:12 .......os daemon.notice pppd[1507]: remote IP address ...........
                             Aug 13 22:02:12 .......os daemon.notice pppd[1507]: primary   DNS address ..............
                             Aug 13 22:02:12 .......os daemon.notice pppd[1507]: secondary DNS address ..............
                             Aug 13 22:02:12 .......os daemon.debug pppd[1507]: Script /etc/ppp/ip-up started (pid 1542)
                             Aug 13 22:02:13 .......os daemon.debug pppd[1507]: Script /etc/ppp/ip-up finished (pid 1542), status = 0x0
                             
Also, all three device are currently in the same area, and should be connecting to the same operator, but I wasn't able to check which operator the problematic device was connecting too, they are set to automatically select an operator and AT+COPS? just returns "+COPS: 0".

Thanks for any help or suggestions,

Scott Threet







[Index of Archives]     [Linux Audio Users]     [Linux for Hams]     [Kernel Newbies]     [Security]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Samba]     [Video 4 Linux]     [Fedora Users]

  Powered by Linux