IPCP: timeout sending Config-Requests

Hardware (and firmware) SDK
1

Hello,

I purchased my second Hologram Nova for a prototype project with a RPi, I am trying to establish a PPP session with this code:

    hologram = HologramCloud(dict(), network='cellular')
    result = hologram.network.connect()
    print "%s" % str(result)
    return result

When I run this, I this warning in the output logs and a failure to establish connection: IPCP: timeout sending Config-Requests, has anyone seen this before? Any known fixes?

One thing to note is I have tried swapping the SIM’s in my two Nova’s and saw that the first Nova I had that was originally working had the exact same issue as above, and the new Nova that was using my first SIM established connection successfully. Could this be a sign of a faulty SIM card? I’m not sure how to test more and where to go from there?

The full output logs are here:

05:23:04.849 [info]  [   84.525754] option 1-1.3:1.0: GSM modem (1-port) converter detected
                               
05:23:04.849 [info]  [   84.533218] usb 1-1.3: GSM modem (1-port) converter now attached to ttyUSB1
                               
05:23:04.859 [info]  [   84.541898] option 1-1.3:1.1: GSM modem (1-port) converter detected
                               
05:23:04.881 [info]  [   84.550016] option 1-1.3:1.2: GSM modem (1-port) converter detected
                               
05:23:04.882 [info]  [   84.558525] usb 1-1.3: GSM modem (1-port) converter now attached to ttyUSB3
                               
05:23:04.882 [info]  [   84.566540] option 1-1.3:1.3: GSM modem (1-port) converter detected
                               
05:23:04.901 [info]  [   84.574216] usb 1-1.3: GSM modem (1-port) converter now attached to ttyUSB4
                               
05:23:05.459 [info]  Nov 13 05:23:05 pppd[230]: pppd 2.4.7 started by root, uid 0
                               
05:23:05.461 [info]  [   85.142443] PPP generic driver version 2.4.2
                               
05:23:06.484 [info]  Nov 13 05:23:06 chat[233]: abort on (BUSY)
                               
05:23:06.484 [info]  Nov 13 05:23:06 chat[233]: abort on (NO CARRIER)
                               
05:23:06.484 [info]  Nov 13 05:23:06 chat[233]: abort on (VOICE)
                               
05:23:06.484 [info]  Nov 13 05:23:06 chat[233]: abort on (NO DIALTONE)
                               
05:23:06.484 [info]  Nov 13 05:23:06 chat[233]: abort on (NO DIAL TONE)
                               
05:23:06.484 [info]  Nov 13 05:23:06 chat[233]: abort on (NO ANSWER)
                               
05:23:06.485 [info]  Nov 13 05:23:06 chat[233]: abort on (DELAYED)
                               
05:23:06.485 [info]  Nov 13 05:23:06 chat[233]: timeout set to 12 seconds
                               
05:23:06.485 [info]  Nov 13 05:23:06 chat[233]: report (CONNECT)
                               
05:23:06.485 [info]  Nov 13 05:23:06 chat[233]: send (AT^M)
                               
05:23:06.514 [info]  Nov 13 05:23:06 chat[233]: expect (OK)
                               
05:23:06.516 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.516 [info]  Nov 13 05:23:06 chat[233]: OK
                               
05:23:06.516 [info]  Nov 13 05:23:06 chat[233]:  -- got it

                               
05:23:06.516 [info]  Nov 13 05:23:06 chat[233]: send (ATH^M)
                               
05:23:06.556 [info]  Nov 13 05:23:06 chat[233]: expect (OK)
                               
05:23:06.556 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.558 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.558 [info]  Nov 13 05:23:06 chat[233]: OK
                               
05:23:06.558 [info]  Nov 13 05:23:06 chat[233]:  -- got it

                               
05:23:06.558 [info]  Nov 13 05:23:06 chat[233]: send (ATZ^M)
                               
05:23:06.598 [info]  Nov 13 05:23:06 chat[233]: expect (OK)
                               
05:23:06.598 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.601 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.601 [info]  Nov 13 05:23:06 chat[233]: OK
                               
05:23:06.601 [info]  Nov 13 05:23:06 chat[233]:  -- got it

                               
05:23:06.601 [info]  Nov 13 05:23:06 chat[233]: send (ATQ0^M)
                               
05:23:06.651 [info]  Nov 13 05:23:06 chat[233]: expect (OK)
                               
05:23:06.651 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.653 [info]  Nov 13 05:23:06 chat[233]: ATQ0^M^M
                               
05:23:06.653 [info]  Nov 13 05:23:06 chat[233]: OK
                               
05:23:06.653 [info]  Nov 13 05:23:06 chat[233]:  -- got it

                               
05:23:06.653 [info]  Nov 13 05:23:06 chat[233]: send (AT+CGDCONT=1,"IP","hologram"^M)
                               
05:23:06.946 [info]  Nov 13 05:23:06 chat[233]: expect (OK)
                               
05:23:06.946 [info]  Nov 13 05:23:06 chat[233]: ^M
                               
05:23:06.965 [info]  Nov 13 05:23:06 chat[233]: AT+CGDCONT=1,"IP","hologram"^M^M
                               
05:23:06.965 [info]  Nov 13 05:23:06 chat[233]: OK
                               
05:23:06.965 [info]  Nov 13 05:23:06 chat[233]:  -- got it

                               
05:23:06.965 [info]  Nov 13 05:23:06 chat[233]: send (ATDT*99***1#^M)
                               
05:23:07.097 [info]  Nov 13 05:23:07 chat[233]: expect (CONNECT)
                               
05:23:07.098 [info]  Nov 13 05:23:07 chat[233]: ^M
                               
05:23:07.101 [info]  Nov 13 05:23:07 chat[233]: ATDT*99***1#^M^M
                               
05:23:07.102 [info]  Nov 13 05:23:07 chat[233]: CONNECT
                               
05:23:07.102 [info]  Nov 13 05:23:07 chat[233]:  -- got it

                               
05:23:07.102 [info]  Nov 13 05:23:07 chat[233]: send (^M)
                               
05:23:07.113 [info]  Nov 13 05:23:07 pppd[230]: Serial connection established.
                               
05:23:07.142 [info]  nerves_network_interface received :ifadded and %{ifname: "ppp0", index: 5}
                               
05:23:07.150 [info]  Nov 13 05:23:07 pppd[230]: Using interface ppp0
                               
05:23:07.150 [info]  Nov 13 05:23:07 pppd[230]: Connect: ppp0 <--> /dev/ttyUSB3
                               
05:23:07.152 [info]  nerves_network_interface received :ifchanged and %{ifname: "ppp0", index: 5, is_broadcast: false, is_lower_up: false, is_multicast: true, is_running: false, is_up: false, mtu: 1500, operstate: :down, stats: %{collisions: 0, multicast: 0, rx_bytes: 0, rx_dropped: 0, rx_errors: 0, rx_packets: 0, tx_bytes: 0, tx_dropped: 0, tx_errors: 0, tx_packets: 0}, type: :other}
                               
05:23:08.181 [info]  [   87.854581] PPP BSD Compression module registered
                               
05:23:08.182 [info]  [   87.868241] PPP Deflate Compression module registered
                               
05:23:38.215 [warn]  Nov 13 05:23:38 pppd[230]: IPCP: timeout sending Config-Requests

                               
05:23:44.223 [info]  Nov 13 05:23:44 pppd[230]: Connection terminated.
                               
05:23:44.227 [info]  nerves_network_interface received :ifchanged and %{ifname: "ppp0", index: 5, is_broadcast: false, is_lower_up: false, is_multicast: true, is_running: false, is_up: false, mtu: 1500, operstate: :down, stats: %{collisions: 0, multicast: 0, rx_bytes: 0, rx_dropped: 0, rx_errors: 0, rx_packets: 0, tx_bytes: 295, tx_dropped: 0, tx_errors: 0, tx_packets: 11}, type: :other}
                               
05:23:44.227 [info]  nerves_network_interface received :ifremoved and %{ifname: "ppp0", index: 5}
                               
05:23:45.258 [info]  Nov 13 05:23:45 pppd[230]: Modem hangup
False
2

Hi, which type of Nova is this? 201?

3

I believe Nova-R410, that is what is on the box.

This is the Hologram Nova Cat-M1 & NB IoT, on the actual Nova it has Model: SARA-R410M on the ublox component.

I tried a separate Hologram Industrial SIM I had laying around from a while back, using this SIM also worked in the second Nova I bought. With the SIM that came with the Nova this warning came up on every attempt to connect. At the same time, I have seen this same warning come up randomly from time-to-time when using both of my Nova’s with the working SIM’s, so confused about what could be causing this.

4

Ok yeah if you search around on here you’ll see some other threads with some similar issues and workarounds that they’ve found. Cat-M is still in kind of early stages on some networks and can be a little buggy with PPP. We also have some fixes to get into our software to help a bit and are working on those. We’ll try to get some more info posted soon.

5

Has there been any progrees on this?

Similarly running a Pi Zero w/ Hologram Nova US 4G LTE Cat-M1 Cellular USB Modem (R410)

and no ability to connect :frowning:

sudo hologram network connect -vv
DEBUG: checking for vid_pid: (‘12d1’, ‘1506’)
DEBUG: checking for vid_pid: (‘12d1’, ‘1001’)
DEBUG: checking for vid_pid: (‘05c6’, ‘90b2’)
INFO: Detected modem NovaM
DEBUG: checking port ttyUSB0
DEBUG: checking port ttyUSB1
DEBUG: [AT]
DEBUG: {AT}
DEBUG: {OK}
INFO: found working port at ttyUSB1
INFO: chatscript file: /usr/local/lib/python2.7/dist-packages/Hologram/Network/Modem/chatscripts/default-script
DEBUG: [ATE0]
DEBUG: {ATE0}
DEBUG: {OK}
DEBUG: [AT+CMEE=2]
DEBUG: {}
DEBUG: {OK}
DEBUG: [AT+CPIN?]
DEBUG: {}
DEBUG: {+CPIN: READY}
DEBUG: {}
DEBUG: {OK}
DEBUG: [AT+CPMS=“ME”,“ME”,“ME”]
DEBUG: {}
DEBUG: {+CPMS: 0,23,0,23,0,23}
DEBUG: {}
DEBUG: {OK}
DEBUG: [AT+CMGF=0]
DEBUG: {}
DEBUG: {OK}
DEBUG: [AT+CNMI=2,1]
DEBUG: {}
DEBUG: {OK}
DEBUG: [AT+CEREG=2]
DEBUG: {}
DEBUG: {OK}
INFO: Instantiated a NovaM interface with device name of /dev/ttyUSB1
DEBUG: [AT+CGMM]
DEBUG: {}
DEBUG: {SARA-R410M-02B}
DEBUG: {}
DEBUG: {OK}
INFO: Connecting to cell network with timeout of 200 seconds
INFO: Checking for existing PPP sessions
INFO: Starting pppd
ERROR: Modem hangup - possibly due to an unregistered SIM
DEBUG: Killing pppd
INFO: Failed to connect to cell network
Failed to start PPP

Feb 11 17:25:26 raspberrypi pppd[655]: pppd 2.4.7 started by pi, uid 0
Feb 11 17:25:27 raspberrypi chat[657]: abort on (BUSY)
Feb 11 17:25:27 raspberrypi chat[657]: abort on (NO CARRIER)
Feb 11 17:25:27 raspberrypi chat[657]: abort on (VOICE)
Feb 11 17:25:27 raspberrypi chat[657]: abort on (NO DIALTONE)
Feb 11 17:25:27 raspberrypi chat[657]: abort on (NO DIAL TONE)
Feb 11 17:25:27 raspberrypi chat[657]: abort on (NO ANSWER)
Feb 11 17:25:27 raspberrypi chat[657]: abort on (DELAYED)
Feb 11 17:25:27 raspberrypi chat[657]: timeout set to 12 seconds
Feb 11 17:25:27 raspberrypi chat[657]: report (CONNECT)
Feb 11 17:25:27 raspberrypi chat[657]: send (AT^M)
Feb 11 17:25:27 raspberrypi chat[657]: expect (OK)
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: OK
Feb 11 17:25:27 raspberrypi chat[657]: – got it
Feb 11 17:25:27 raspberrypi chat[657]: send (ATH^M)
Feb 11 17:25:27 raspberrypi chat[657]: expect (OK)
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: OK
Feb 11 17:25:27 raspberrypi chat[657]: – got it
Feb 11 17:25:27 raspberrypi chat[657]: send (ATZ^M)
Feb 11 17:25:27 raspberrypi chat[657]: expect (OK)
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: OK
Feb 11 17:25:27 raspberrypi chat[657]: – got it
Feb 11 17:25:27 raspberrypi chat[657]: send (ATQ0^M)
Feb 11 17:25:27 raspberrypi chat[657]: expect (OK)
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: ATQ0^M^M
Feb 11 17:25:27 raspberrypi chat[657]: OK
Feb 11 17:25:27 raspberrypi chat[657]: – got it
Feb 11 17:25:27 raspberrypi chat[657]: send (AT+CGDCONT=1,“IP”,“hologram”^M)
Feb 11 17:25:27 raspberrypi chat[657]: expect (OK)
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: AT+CGDCONT=1,“IP”,“hologram”^M^M
Feb 11 17:25:27 raspberrypi chat[657]: OK
Feb 11 17:25:27 raspberrypi chat[657]: – got it
Feb 11 17:25:27 raspberrypi chat[657]: send (ATDT99*1#^M)
Feb 11 17:25:27 raspberrypi chat[657]: expect (CONNECT)
Feb 11 17:25:27 raspberrypi chat[657]: ^M
Feb 11 17:25:27 raspberrypi chat[657]: ATDT99***1#^M^M
Feb 11 17:25:27 raspberrypi chat[657]: CONNECT
Feb 11 17:25:27 raspberrypi chat[657]: – got it
Feb 11 17:25:27 raspberrypi chat[657]: send (^M)
Feb 11 17:25:27 raspberrypi pppd[655]: Serial connection established.
Feb 11 17:25:27 raspberrypi pppd[655]: Using interface ppp0
Feb 11 17:25:27 raspberrypi pppd[655]: Connect: ppp0 <–> /dev/ttyUSB1
Feb 11 17:25:28 raspberrypi pppd[655]: PAP authentication succeeded
Feb 11 17:25:58 raspberrypi pppd[655]: IPCP: timeout sending Config-Requests
Feb 11 17:26:04 raspberrypi pppd[655]: Connection terminated.
Feb 11 17:26:05 raspberrypi pppd[655]: Modem hangup
Feb 11 17:26:07 raspberrypi pppd[655]: Terminating on signal 15
Feb 11 17:26:07 raspberrypi pppd[655]: Exit.

6

Are you on the latest SDK version?

You may want to take a look at our R410 megathread: Nova R410 (Cat-M) Issues (Troubleshooting tips and tricks and known issues on the R410 Nova + user feedback on issues) - #26 by Safa_Vakili

7

A change from at+cops=1 to at+cops=0 did the trick now I’m connected…

I assume the put the modem in “Auto” as oppose to “Manual” mode.

OK
at+cops?
+cops: 0,0,“Verizon Wireless Hologram”,8

OK

8

Oh did you set that yourself on the modem? Yeah the sdk assumes you left it at the default auto mode

9

I don’t recall setting it, but apparently I must have :confused: oh well glad it’s working now.