I have been using Nova modems for at least 2 years now, and I have to say that while the U201 was very reliable, the R410M has been giving me a headache.
My product is a custom linux PC powering the nova over USB. I have verified the supply can source the 2.4 amps that is supposedly needed.
I frequently see several issues, but the top concern for me right now is that I see the following in my PPPD logs:
Jun 25 20:08:24 daemon.notice pppd[218]: pppd 2.4.7 started by root, uid 0
Jun 25 20:08:24 local2.info chat[220]: abort on (BUSY)
Jun 25 20:08:24 local2.info chat[220]: abort on (NO CARRIER)
Jun 25 20:08:24 local2.info chat[220]: abort on (VOICE)
Jun 25 20:08:24 local2.info chat[220]: abort on (NO DIALTONE)
Jun 25 20:08:24 local2.info chat[220]: abort on (NO ANSWER)
Jun 25 20:08:24 local2.info chat[220]: abort on (DELAYED)
Jun 25 20:08:24 local2.info chat[220]: timeout set to 200 seconds
Jun 25 20:08:24 local2.info chat[220]: report (CONNECT)
Jun 25 20:08:24 local2.info chat[220]: send (AT^M)
Jun 25 20:08:24 local2.info chat[220]: expect (OK)
Jun 25 20:08:24 local2.info chat[220]: AT^M^M
Jun 25 20:08:24 local2.info chat[220]: OK
Jun 25 20:08:24 local2.info chat[220]: â got it
Jun 25 20:08:24 local2.info chat[220]: send (ATDT991#^M)
Jun 25 20:08:25 local2.info chat[220]: expect (CONNECT)
Jun 25 20:08:25 local2.info chat[220]: ^M
Jun 25 20:08:25 local2.info chat[220]: ATDT99**1#^M^M
Jun 25 20:08:25 local2.info chat[220]: CONNECT
Jun 25 20:08:25 local2.info chat[220]: â got it
Jun 25 20:08:25 local2.info chat[220]: send (^M)
Jun 25 20:08:25 daemon.debug pppd[218]: Script /sbin/chat -v -s -f /ps/pppd/chat_final finished (pid 220), status = 0x0
Jun 25 20:08:25 daemon.info pppd[218]: Serial connection established.
Jun 25 20:08:25 daemon.debug pppd[218]: using channel 1
Jun 25 20:08:25 daemon.info pppd[218]: Using interface ppp0
Jun 25 20:08:25 daemon.notice pppd[218]: Connect: ppp0 <â> /dev/ttyUSB1
Jun 25 20:08:26 daemon.debug pppd[218]: sent [LCP ConfReq id=0x1 <mru 296> <asyncmap 0x0> <magic 0xe0c72923> ]
Jun 25 20:08:26 daemon.debug pppd[218]: rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <magic 0xd0600ac5> ]
Jun 25 20:08:26 daemon.debug pppd[218]: sent [LCP ConfAck id=0x0 <asyncmap 0x0> <magic 0xd0600ac5> ]
Jun 25 20:08:26 daemon.debug pppd[218]: rcvd [LCP ConfAck id=0x1 <mru 296> <asyncmap 0x0> <magic 0xe0c72923> ]
Jun 25 20:08:26 daemon.debug pppd[218]: rcvd [LCP DiscReq id=0x1 magic=0xd0600ac5]
Jun 25 20:08:26 daemon.debug pppd[218]: rcvd [CHAP Challenge id=0x1 <5d6cfc71a5e68c63e73db0eebf5a26b0>, name = âUMTS_CHAP_SRVRâ]
Jun 25 20:08:26 daemon.debug pppd[218]: sent [CHAP Response id=0x1 <48741a5918ae9de6f5f55337726cf33d>, name = âuâ]
Jun 25 20:08:26 daemon.debug pppd[218]: rcvd [CHAP Success id=0x1 ââ]
Jun 25 20:08:26 daemon.info pppd[218]: CHAP authentication succeeded
Jun 25 20:08:26 daemon.notice pppd[218]: CHAP authentication succeeded
Jun 25 20:08:26 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:26 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:29 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:29 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:32 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:32 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:35 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:35 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:38 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:38 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:41 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:41 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:44 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:44 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:47 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:47 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:50 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:50 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:53 daemon.debug pppd[218]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 25 20:08:53 daemon.debug pppd[218]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 25 20:08:56 daemon.warn pppd[218]: CCP: timeout sending Config-Requests
Jun 25 20:08:56 daemon.warn pppd[218]: IPCP: timeout sending Config-Requests
Jun 25 20:08:56 daemon.debug pppd[218]: sent [LCP TermReq id=0x2 âNo network protocols runningâ]
Jun 25 20:08:59 daemon.debug pppd[218]: sent [LCP TermReq id=0x3 âNo network protocols runningâ]
Jun 25 20:09:02 daemon.notice pppd[218]: Connection terminated.
Jun 25 20:09:02 daemon.debug pppd[218]: Script /ps/pppd/disconnect finished (pid 392), status = 0x7f
Jun 25 20:09:02 daemon.warn pppd[218]: disconnect script failed
Jun 25 20:09:02 daemon.notice pppd[218]: Modem hangup
Jun 25 20:09:12 local2.info chat[393]: abort on (BUSY)
Jun 25 20:09:12 local2.info chat[393]: abort on (NO CARRIER)
Jun 25 20:09:12 local2.info chat[393]: abort on (VOICE)
Jun 25 20:09:12 local2.info chat[393]: abort on (NO DIALTONE)
Jun 25 20:09:12 local2.info chat[393]: abort on (NO ANSWER)
Jun 25 20:09:12 local2.info chat[393]: abort on (DELAYED)
Jun 25 20:09:12 local2.info chat[393]: timeout set to 200 seconds
Jun 25 20:09:12 local2.info chat[393]: report (CONNECT)
Jun 25 20:09:12 local2.info chat[393]: send (AT^M)
Jun 25 20:09:12 local2.info chat[393]: expect (OK)
Jun 25 20:12:32 local2.info chat[393]: alarm
Jun 25 20:12:32 local2.info chat[393]: Failed
Jun 25 20:12:32 daemon.debug pppd[218]: Script /sbin/chat -v -s -f /ps/pppd/chat_final finished (pid 393), status = 0x3
Jun 25 20:12:32 daemon.err pppd[218]: Connect script failed
The timeout sending requests has happened on both firmware versions of the modem, and at seemingly random times.
Interestingly, on the new firmware, I have found that after the first PPPD attempt, the tty will lock up and PPPD is no longer able to talk to the modem. Killing PPPD and connecting manually with microcom shows that the AT command tty port is entirely locked up.
Let me know what other information I need to share to get some help with this.
Has anyone experienced this before?
I also see the following error after failing to connect, at seemingly random times.
I was asked to add this by Sara on our troubleshooting call so she can direct the support team to the right post.
The modem properly instantiates at first, with this dmesg output:
[ 13.554357] usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2
[ 13.561516] usb 1-1: New USB device strings: Mfr=3, Product=2, SerialNumber=4
[ 13.568765] usb 1-1: Product: Qualcomm CDMA Technologies MSM
[ 13.574658] usb 1-1: Manufacturer: Qualcomm, Incorporated
[ 13.580202] usb 1-1: SerialNumber: 2bfa96bc
[ 13.640057] option 1-1:1.0: GSM modem (1-port) converter detected
[ 13.659201] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
[ 13.675465] option 1-1:1.2: GSM modem (1-port) converter detected
[ 13.684944] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
But later, it disconnects and reconnects only one port. As I can only use /dev/ttyUSB1 for AT commands, the modem effectively requires a reboot of our device to work since we cannot directly control the USB power.
[ 2028.082414] usb 1-1: USB disconnect, device number 2
[ 2028.113254] option1 ttyUSB0: GSM modem (1-port) converter now disconnected from ttyUSB0
[ 2028.122926] option 1-1:1.0: device disconnected
[ 2028.140914] option1 ttyUSB1: GSM modem (1-port) converter now disconnected from ttyUSB1
[ 2028.149640] option 1-1:1.2: device disconnected
[ 2029.194991] usb 1-1: new high-speed USB device number 3 using ci_hdrc
[ 2029.388723] usb 1-1: New USB device found, idVendor=05c6, idProduct=90b2
[ 2029.395668] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2029.403020] usb 1-1: Product: QHSUSB__BULK
[ 2029.407334] usb 1-1: Manufacturer: Qualcomm CDMA Technologies MSM
[ 2029.413491] usb 1-1: SerialNumber: 2bfa96bc
[ 2029.433967] option 1-1:1.0: GSM modem (1-port) converter detected
[ 2029.443897] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
You may need to set the MNO profile back to whatever you had it at before after running that. Weâve just found that resetting that stuff after a firmware update helps for some reason
Its random how long it takes, but it usually takes around 30-45 minutes.
My application sets the configuration every time it boots, I set the UMNOPROF to be 100 if using a hologram sim, or 1 if using a third party sim.
Would I need to switch the umnoprof to something else, reboot, then switch back to the one I want? or is simply calling the command enough to get it working?
Most important to me is the first issue however, as this typically doesnât occur when we are successfully connected.
I believe you do have to reboot the modem after setting UMNOPROF. If you look at the UBlox AT command docs, they have a suggested procedure for doing that.
That is related to the first issue. We have occasionally seen this happen with the R410 after doing a firmware update though not usually before the update. Usually that one troubleshooting step of resetting the profile and rebooting with CFUN=15 after doing the upgrade does fix the issue as from that point, the modem will stay stable.
It appears you might already be doing that though.
How are you powering the raspberry pi? Is it possible it could be browning out due to a low power state?
I think we may just want to swap out one of them and see if that helps. The newer ones have the new firmware preinstalled and itâs possible that leads to a more stable outcome than the update process. Can you reach out to support@hologram.io and weâll get that arranged?
This is consistent across every modem I have tried though, I donât think swapping them will help. This happens with ones that came out of the box on the new firmware and updated ones all the same.
Could it be related to the timeouts sending Config-Requests? Is that due to some misconfiguration?
It wouldnât be as big an issue if the modem wouldnât lock up. Any ideas why that may be happening?
Hmm interesting. So this is probably a different thing then. When it locks up, are the LEDs on? If they are, then it might not really be locked up, but just the serial port might still be stuck in PPP/data mode instead of AT command mode. That could be related to it getting kicked off PPP. You can try sending â+++â the serial port which is the universal string for getting back to command mode. Maybe PPP isnât cleaning up properly after it fails? Did you write your chatscripts from scratch or did you use ours? I havenât seen this problem with the ones we use.
If you wait a few minutes does it eventually come back? We have seen that the R410 can take a minute or two for certain operations to time out and the port might be held up during that time, but it does usually come back.
I originally used yours, but now I do it slightly differently, based on the commands you used but with the suggestions added in.
On boot, using a custom C application I send the following commands to identify what the modem is (since we support many other modems) with these commands:
ATZ
AT+CGMI
AT+CGMM
AT+CCID
AT+CGSN
AT+CSQ
AT+CGMR
Then, configure the modem depending on its destination:
ATH
ATZ
AT+CFUN=0
AT+UMNOPROF=100 (for hologram, 1 for other carriers)
AT+CFUN=15
(close serial port, sleep 10 seconds, re-open)
AT+CFUN=0
AT+UBANDMASK=0,185473183
AT+UBANDMASK=1,185473183
AT+URAT=7,8
ATQ0
AT+CGDCONT=1,âIPâ,âhologramâ
AT+CFUN=15
(close serial port, sleep 10 seconds, start pppd)
My chat script is this:
ABORT âBUSYâ
ABORT âNO CARRIERâ
ABORT âVOICEâ
ABORT âNO DIALTONEâ
ABORT âNO ANSWERâ
ABORT âDELAYEDâ
TIMEOUT 200
REPORT CONNECT
ââ AT
OK ATDT99**1#
CONNECT ââ
If the first connect fails, then the first âATâ in the chat script never receives a response on subsequent attempts, and if I kill pppd I still canât manually talk to the modem with microcom. +++ does not bring back the normal operation, and the LED on the modem indicates connectivity.
How long have you tried waiting for the port to be available? I donât have the docs up at the moment, but I feel like it could be several minutes for that to timeout
It retries every 30 seconds, and eventually it resets to the QHUSB bulk device (the second post in this thread)
That usually happens after around 30 minutes of this.
Ok got it. Thatâs not something weâve seen here. Weâll try to play around with it and reproduce and reach out ublox to see if theyâve seen that behavior. Sounds like itâs getting stuck in data mode and canât get out.
Update on this: ublox hasnât seen this issue but weâre discussing with them. I think I got my board to get into the state you mentioned where it no longer responds to commands, however mine doesnât remount as the bulk device. It only stays in this unresponsive mode. Weâll keep looking at it.