Fail for Check-In to DeviceHQ

[Damon Lora]

Good day
I am using MTCDT-LVW2-247A (MultiConnect Conduit).
It is already connect to internet with WiFi.
The device is already register into DevicHQ site and Access Configuration->Web Server->Node-Red->Via WAN is enable too.
When I enable Remote Server (Server Name: ds.devicehq.com App Store URL:https://www.devicehq.com), the current status is always show “failed to open connection with the remote server”.

If anyone have any suggestion, please advise me.
Thank you very much

[Jeff Hatch]

Damon,

Is DNS working on the Conduit? If you SSH into the device and do a “nslookup http://www.devicehq.com” does it resolve to an IP address.

Jeff

[Damon Lora]

I am using MTCDT-LVW2-247A [LTE Application Enablement Gateway GNSS & BT/Wi-Fi w/US Accessory Kit (Verizon)].

I have disable Cellular and using WiFi as Wan for connection.
In the first time boot up, it can show connected to deviceHQ.com, but it will go to idle status after a few minute.

Ready don’t know why?

Damon

[Jeff Hatch]

Damon,

The Conduit will only “check in” to Device HQ at regularly configured intervals. In the mean time it does not maintain an open connection to Device HQ (thus the “idle” status).

If you’re watching the status when it checks in on the configured interval, you should see it connect, check in, and then go back to idle.

Jeff

[Damon Lora]

Jeff,

Let me check more.
Thank you very much for you clarify.

Damon

[William Laing]

We just developed a similar issue with one of our IP67 gateways.

When I click on Administration->Remote Management->Check-In To DeviceHQ, I also receive Current Status: failed to open connection with the remote server.

It’s an IP67 running AEP 1.6.4.

It had been checking into DeviceHQ on a regular basis until we installed an AT&T Sim card and enabled cellular.

When we type “nslookup http://www.devicehq.com”, we get nslookup: can’t resolve ‘http://www.devicehq.com’

Any help appreciated – thanks!

[Jeff Hatch]

William,

With Cellular enabled, does your device have an IP address and a DNS server? The way to tell is to go the the “Home” page in the Web UI, and in the WAN pane on that page you should see the State and it should say “PPP Link is up”. Below that you should see an IP address and for DNS there should also be another IP.

If the WAN has a ppp connection and has both an IP and a DNS IP, and the DNS nslookup is still failing, check the WAN configuration under Setup and make sure that the Cellular WAN is at the top (Priority 1).

Also, are there any other WANs configured besides Cellular?

Jeff

[William Laing]

Jeff –

Cellular checkbox is enabled. There is no IP address. And DNS says ‘Not Acquired’.

As far as I can tell, Cellular Configuration is the same (APN, Authentication type, etc.) as the other Conduits.

William

[Jeff Hatch]

William,

Have you looked in /var/log/messages to see what the output is from the “chat” script? In the log you should see the execution of the chat script and if it is failing it may give us enough info to see why the connection is not working. If ppp is connecting, but no IP and no DNS are getting acquired, then there are some other things to check.

Jeff

[William Laing]

Jeff –

I did a grep on /var/log/messages for ‘chat’, and here’s what I got:

=========================================================================
2019-02-06T16:11:06.985220-05:00 mtcdt chat[4069]: info: Attempting Basic Radio Communication
2019-02-06T16:11:06.986689-05:00 mtcdt chat[4069]: send (AT^M)
2019-02-06T16:11:07.019134-05:00 mtcdt chat[4069]: expect (OK)
2019-02-06T16:11:07.026722-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.028274-05:00 mtcdt chat[4069]: OK
2019-02-06T16:11:07.029504-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:07.030604-05:00 mtcdt chat[4069]: info: Checking if SIM is inserted
2019-02-06T16:11:07.031824-05:00 mtcdt chat[4069]: send (AT#SIMDET?^M)
2019-02-06T16:11:07.145253-05:00 mtcdt chat[4069]: expect (#SIMDET: 2,1)
2019-02-06T16:11:07.145693-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.153013-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.153390-05:00 mtcdt chat[4069]: #SIMDET: 2,1
2019-02-06T16:11:07.153727-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:07.153973-05:00 mtcdt chat[4069]: info: Checking if SIM is locked
2019-02-06T16:11:07.154187-05:00 mtcdt chat[4069]: send (AT+CPIN?^M)
2019-02-06T16:11:07.246891-05:00 mtcdt chat[4069]: expect (READY)
2019-02-06T16:11:07.247286-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.247661-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.247954-05:00 mtcdt chat[4069]: OK^M
2019-02-06T16:11:07.254384-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.254882-05:00 mtcdt chat[4069]: +CPIN: READY
2019-02-06T16:11:07.255093-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:07.255328-05:00 mtcdt chat[4069]: info: SIM was unlocked
2019-02-06T16:11:07.255624-05:00 mtcdt chat[4069]: info: Waiting for minimum signal strength
2019-02-06T16:11:07.255845-05:00 mtcdt chat[4069]: send (AT+CSQ^M)
2019-02-06T16:11:07.328009-05:00 mtcdt chat[4069]: expect (+CSQ: )
2019-02-06T16:11:07.328341-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.328708-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.329063-05:00 mtcdt chat[4069]: OK^M
2019-02-06T16:11:07.335433-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.335863-05:00 mtcdt chat[4069]: +CSQ:
2019-02-06T16:11:07.336070-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:07.336312-05:00 mtcdt chat[4069]: expect (99,99)
2019-02-06T16:11:07.336724-05:00 mtcdt chat[4069]: 30,99^M
2019-02-06T16:11:07.336988-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:07.337258-05:00 mtcdt chat[4069]: OK^M
2019-02-06T16:11:08.337102-05:00 mtcdt chat[4069]: alarm
2019-02-06T16:11:08.337984-05:00 mtcdt chat[4069]: send (AT^M)
2019-02-06T16:11:08.369840-05:00 mtcdt chat[4069]: expect (OK)
2019-02-06T16:11:08.376257-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.376736-05:00 mtcdt chat[4069]: OK
2019-02-06T16:11:08.376956-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:08.377212-05:00 mtcdt chat[4069]: send (AT^M)
2019-02-06T16:11:08.408573-05:00 mtcdt chat[4069]: abort on (NO CARRIER)
2019-02-06T16:11:08.408866-05:00 mtcdt chat[4069]: abort on (BUSY)
2019-02-06T16:11:08.409111-05:00 mtcdt chat[4069]: abort on (ERROR)
2019-02-06T16:11:08.409351-05:00 mtcdt chat[4069]: expect (OK)
2019-02-06T16:11:08.409750-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.413375-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.413794-05:00 mtcdt chat[4069]: OK
2019-02-06T16:11:08.414020-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:08.414285-05:00 mtcdt chat[4069]: send (AT+CSQ^M)
2019-02-06T16:11:08.486822-05:00 mtcdt chat[4069]: expect (OK)
2019-02-06T16:11:08.487164-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.494379-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.494911-05:00 mtcdt chat[4069]: +CSQ: 30,99^M
2019-02-06T16:11:08.495186-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.495524-05:00 mtcdt chat[4069]: OK
2019-02-06T16:11:08.495751-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:08.496014-05:00 mtcdt chat[4069]: send (AT+CGDCONT=1,\”IP\”,\”m2m.com.attz\”^M)
2019-02-06T16:11:08.852902-05:00 mtcdt chat[4069]: expect (OK)
2019-02-06T16:11:08.853241-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.887378-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:08.887807-05:00 mtcdt chat[4069]: OK
2019-02-06T16:11:08.888022-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:08.888270-05:00 mtcdt chat[4069]: send (ATDT*99***1#^M)
2019-02-06T16:11:09.021994-05:00 mtcdt chat[4069]: expect (CONNECT)
2019-02-06T16:11:09.022334-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:09.061938-05:00 mtcdt chat[4069]: ^M
2019-02-06T16:11:09.062339-05:00 mtcdt chat[4069]: CONNECT
2019-02-06T16:11:09.062549-05:00 mtcdt chat[4069]: — got it
2019-02-06T16:11:09.062863-05:00 mtcdt chat[4069]: send (^M)
admin@mtcdt:/var/log#

[Jeff Hatch]

William,

The logging right after that last send is probably what we need to see. There should be something coming out of ppp. The following is what I have on a device that is successfully connecting with an AT&T SIM:

2019-02-06T10:59:39.507415-06:00 mtcdt pppd[6389]: Script chat -v -c -t 90 -f /var/run/config/ppp_chat f
2019-02-06T10:59:39.507718-06:00 mtcdt pppd[6389]: Serial connection established.
2019-02-06T10:59:39.541663-06:00 mtcdt pppd[6389]: using channel 1
2019-02-06T10:59:39.549870-06:00 mtcdt pppd[6389]: Using interface ppp0
2019-02-06T10:59:39.552644-06:00 mtcdt pppd[6389]: Connect: ppp0 <--> /dev/modem_at0
2019-02-06T10:59:40.529326-06:00 mtcdt pppd[6389]: rcvd [LCP ConfReq id=0x1 ]
2019-02-06T10:59:40.557541-06:00 mtcdt pppd[6389]: rcvd [LCP ConfAck id=0x1 ]
2019-02-06T10:59:40.582318-06:00 mtcdt pppd[6389]: rcvd [IPCP ConfRej id=0x1 ]
2019-02-06T10:59:40.582668-06:00 mtcdt pppd[6389]: sent [IPCP ConfReq id=0x2

[William Laing]

Jeff –

It looks like it’s connecting, but there are Hangups (SIGHUP). Here’s a snippet:

2019-02-06T16:21:09.493206-05:00 mtcdt pppd[2169]: Serial connection established.
2019-02-06T16:21:09.505894-05:00 mtcdt pppd[2169]: Using interface ppp0
2019-02-06T16:21:09.511016-05:00 mtcdt pppd[2169]: Connect: ppp0 <–> /dev/modem_at0
2019-02-06T16:21:10.545968-05:00 mtcdt pppd[2169]: CHAP authentication succeeded
2019-02-06T16:21:10.546194-05:00 mtcdt pppd[2169]: CHAP authentication succeeded
2019-02-06T16:21:10.592697-05:00 mtcdt pppd[2169]: Hangup (SIGHUP)
2019-02-06T16:21:10.592978-05:00 mtcdt pppd[2169]: Modem hangup
2019-02-06T16:21:10.593349-05:00 mtcdt pppd[2169]: Connection terminated.
2019-02-06T16:29:05.926188-05:00 mtcdt annexcd: [INFO] aep_interface.cc:getNetworkInterface:244: Gathering info for interface ppp0
2019-02-06T16:29:07.050238-05:00 mtcdt annexcd: [INFO] aep_interface.cc:getNetworkInterface:409: error reading /sys/class/net/ppp0/statistics/multicast
2019-02-06T16:29:07.055600-05:00 mtcdt annexcd: [ERR] delivery_agent.cc:FillNetworkInterface:228: network_interface(ppp0): invalid field ‘flags’
2019-02-06T16:29:07.057902-05:00 mtcdt annexcd: [INFO] delivery_agent.cc:SendNetworkInterfaceStats:526: failed to fill NetworkInterface message (ppp0) – sending empty interface
2019-02-06T16:36:08.777469-05:00 mtcdt pppd[2169]: Serial connection established.
2019-02-06T16:36:08.786231-05:00 mtcdt pppd[2169]: Using interface ppp0
2019-02-06T16:36:08.788172-05:00 mtcdt pppd[2169]: Connect: ppp0 <–> /dev/modem_at0
2019-02-06T16:36:09.843501-05:00 mtcdt pppd[2169]: CHAP authentication succeeded
2019-02-06T16:36:09.844607-05:00 mtcdt pppd[2169]: CHAP authentication succeeded
2019-02-06T16:36:09.888602-05:00 mtcdt pppd[2169]: Hangup (SIGHUP)
2019-02-06T16:36:09.888884-05:00 mtcdt pppd[2169]: Modem hangup
2019-02-06T16:36:09.889155-05:00 mtcdt pppd[2169]: Connection terminated.
2019-02-06T16:50:25.730084-05:00 mtcdt annexcd: [INFO] aep_interface.cc:getNetworkInterface:244: Gathering info for interface ppp0
2019-02-06T16:50:26.998180-05:00 mtcdt annexcd: [INFO] aep_interface.cc:getNetworkInterface:409: error reading /sys/class/net/ppp0/statistics/multicast
2019-02-06T16:50:27.001144-05:00 mtcdt annexcd: [ERR] delivery_agent.cc:FillNetworkInterface:228: network_interface(ppp0): invalid field ‘flags’
2019-02-06T16:50:27.002422-05:00 mtcdt annexcd: [INFO] delivery_agent.cc:SendNetworkInterfaceStats:526: failed to fill NetworkInterface message (ppp0) – sending empty interface

[Jeff Hatch]

William,

First thing to do is to make sure that the IMEI is valid with AT&T. This should have been taken care of in Production, but every once in a while something gets messed up on one end or the other. I found a site that can verify that the IMEI is compatible with AT&T here:

https://www.att.com/shop/wireless/imeivalidation.html

If the device is compatible, then check the registration in the Radio Terminal on the Debug Options UI page:

AT+CREG? -> the response should be “+CREG: 0,1” if the radio is registered. If it is “+CREG: 0,0” there is something wrong with the registration with that radio/SIM combination.

If the radio is registered, and you are still seeing the SIGHUP, that means that something is most likely terminating the connection from the provider side. For more help you will need to talk with Multitech support at https://support.multitech.com where they will be able to give you more support.

Jeff

[William Laing]

Hi Jeff –

I used that AT&T webpage to enter the IMEI, and it says device is compatible.

I reinserted the SIM card. It appears that we’re no longer getting SIGHUPs.

But AT+CREG? returns +CREG: 0,2

We also see a failure in the chat script:

2019-02-07T17:03:23.387425-05:00 mtcdt chat[7496]: send (AT+CSQ^M)
2019-02-07T17:03:23.470118-05:00 mtcdt chat[7496]: expect (OK)
2019-02-07T17:03:23.470456-05:00 mtcdt chat[7496]: ^M
2019-02-07T17:03:23.475383-05:00 mtcdt chat[7496]: ^M
2019-02-07T17:03:23.475775-05:00 mtcdt chat[7496]: +CSQ: 23,99^M
2019-02-07T17:03:23.476136-05:00 mtcdt chat[7496]: ^M
2019-02-07T17:03:23.476425-05:00 mtcdt chat[7496]: OK
2019-02-07T17:03:23.476642-05:00 mtcdt chat[7496]: — got it
2019-02-07T17:03:23.477081-05:00 mtcdt chat[7496]: send (AT+CGDCONT=1,\”IP\”,\”m2m.com.attz\”^M)
2019-02-07T17:03:23.828354-05:00 mtcdt chat[7496]: expect (OK)
2019-02-07T17:03:23.828682-05:00 mtcdt chat[7496]: ^M
2019-02-07T17:03:23.833898-05:00 mtcdt chat[7496]: ^M
2019-02-07T17:03:23.834367-05:00 mtcdt chat[7496]: ERROR
2019-02-07T17:03:23.834594-05:00 mtcdt chat[7496]: — failed
2019-02-07T17:03:23.834887-05:00 mtcdt chat[7496]: Failed (ERROR)

[Jeff Hatch]

William,

It now seems that it is having difficulty registering and appears to be still trying. The RSSI appears to be fine (+CSQ: 23,99). The dial out won’t work until there is a successful registration. I recommend that you open a support portal case with Multitech. They have a better handle on the different issues that might be happening that could cause registration problems.

Jeff

[William Laing]

Okay, Jeff –

We appreciate your efforts as always – thank you!

We have half-a-dozen Conduits with cellular service but have never seen this issue before.

Best,
William

[mjl]

Any resolution on this issue? We are having a nearly identical issue after installing firmware version 1.7.4. The issue affects our roaming gateways primarily. Support has been utterly unhelpful in our case..

[Author]

Posts