Problems using Quectel EC20 Modem and SORACOM SIM Card

pendinguserresponse
#1

Hi,

I am using a Quectel EC20 mPCIe Modem card - inserted into the BalenaFin mPCIe-Carrier Slot. I have created a network configuration file - based on the following article:

But it does not seem to work - sometimes it says that it is connected and the WAN-Light is on. Also there are two IP-Addresses set in the Dashboard - but that disappears soon after the start.

Here’s what the Diagnostics say:

Apr 20 13:29:09 1dca7e1 ModemManager[727]: call end reason (2): 'generic-client-end'
Apr 20 13:29:09 1dca7e1 ModemManager[727]: verbose call end reason (3,2000): [cm] client-end
Apr 20 13:29:13 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:13 1dca7e1 ModemManager[727]: call end reason (1): 'generic-unspecified'
Apr 20 13:29:13 1dca7e1 ModemManager[727]: verbose call end reason (2,210): [internal] pdn-ipv6-call-disallowed
Apr 20 13:29:13 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
Apr 20 13:29:13 1dca7e1 NetworkManager[773]: <info>  [1555766953.9979] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 20 13:29:14 1dca7e1 ModemManager[727]: Simple connect started...
Apr 20 13:29:14 1dca7e1 ModemManager[727]: Simple connect state (4/8): Wait to get fully enabled
Apr 20 13:29:14 1dca7e1 ModemManager[727]: Simple connect state (5/8): Register
Apr 20 13:29:14 1dca7e1 ModemManager[727]: Simple connect state (6/8): Bearer
Apr 20 13:29:14 1dca7e1 ModemManager[727]: Simple connect state (7/8): Connect
Apr 20 13:29:14 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Apr 20 13:29:14 1dca7e1 NetworkManager[773]: <info>  [1555766954.0072] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Apr 20 13:29:15 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:15 1dca7e1 ModemManager[727]: call end reason (2): 'generic-client-end'
Apr 20 13:29:15 1dca7e1 ModemManager[727]: verbose call end reason (3,2000): [cm] client-end
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
Apr 20 13:29:15 1dca7e1 NetworkManager[773]: <info>  [1555766955.0520] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Simple connect started...
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Simple connect state (4/8): Wait to get fully enabled
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Simple connect state (5/8): Register
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Simple connect state (6/8): Bearer
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Simple connect state (7/8): Connect
Apr 20 13:29:15 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Apr 20 13:29:15 1dca7e1 NetworkManager[773]: <info>  [1555766955.0620] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Apr 20 13:29:19 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:19 1dca7e1 ModemManager[727]: call end reason (1): 'generic-unspecified'
Apr 20 13:29:19 1dca7e1 ModemManager[727]: verbose call end reason (2,210): [internal] pdn-ipv6-call-disallowed
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9486] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <warn>  [1555766959.9504] modem-broadband[cdc-wdm0]: failed to connect modem: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9506] device (cdc-wdm0): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <warn>  [1555766959.9556] device (cdc-wdm0): Activation: failed for connection 'Soracom'
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9575] device (cdc-wdm0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9629] policy: auto-activating connection 'Soracom' (189daef0-c949-358b-af4d-4b9f6323edd0)
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9695] device (cdc-wdm0): Activation: starting connection 'Soracom' (189daef0-c949-358b-af4d-4b9f6323edd0)
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9706] device (cdc-wdm0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Simple connect started...
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Simple connect state (4/8): Wait to get fully enabled
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Simple connect state (5/8): Register
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Simple connect state (6/8): Bearer
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Simple connect state (7/8): Connect
Apr 20 13:29:19 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Apr 20 13:29:19 1dca7e1 NetworkManager[773]: <info>  [1555766959.9776] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Apr 20 13:29:21 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:21 1dca7e1 ModemManager[727]: call end reason (2): 'generic-client-end'
Apr 20 13:29:21 1dca7e1 ModemManager[727]: verbose call end reason (3,2000): [cm] client-end
Apr 20 13:29:25 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:25 1dca7e1 ModemManager[727]: call end reason (1): 'generic-unspecified'
Apr 20 13:29:25 1dca7e1 ModemManager[727]: verbose call end reason (2,210): [internal] pdn-ipv6-call-disallowed
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
Apr 20 13:29:25 1dca7e1 NetworkManager[773]: <info>  [1555766965.4840] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Simple connect started...
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Simple connect state (4/8): Wait to get fully enabled
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Simple connect state (5/8): Register
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Simple connect state (6/8): Bearer
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Simple connect state (7/8): Connect
Apr 20 13:29:25 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Apr 20 13:29:25 1dca7e1 NetworkManager[773]: <info>  [1555766965.4949] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Apr 20 13:29:26 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:26 1dca7e1 ModemManager[727]: call end reason (2): 'generic-client-end'
Apr 20 13:29:26 1dca7e1 ModemManager[727]: verbose call end reason (3,2000): [cm] client-end
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
Apr 20 13:29:26 1dca7e1 NetworkManager[773]: <info>  [1555766966.5079] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Simple connect started...
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Simple connect state (4/8): Wait to get fully enabled
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Simple connect state (5/8): Register
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Simple connect state (6/8): Bearer
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Simple connect state (7/8): Connect
Apr 20 13:29:26 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Apr 20 13:29:26 1dca7e1 NetworkManager[773]: <info>  [1555766966.5178] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Apr 20 13:29:31 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:31 1dca7e1 ModemManager[727]: call end reason (1): 'generic-unspecified'
Apr 20 13:29:31 1dca7e1 ModemManager[727]: verbose call end reason (2,210): [internal] pdn-ipv6-call-disallowed
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5329] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'registered' (reason: user-requested)
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <warn>  [1555766971.5333] modem-broadband[cdc-wdm0]: failed to connect modem: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5335] device (cdc-wdm0): state change: prepare -> failed (reason 'unknown', sys-iface-state: 'managed')
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <warn>  [1555766971.5384] device (cdc-wdm0): Activation: failed for connection 'Soracom'
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5431] device (cdc-wdm0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5471] policy: auto-activating connection 'Soracom' (189daef0-c949-358b-af4d-4b9f6323edd0)
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5502] device (cdc-wdm0): Activation: starting connection 'Soracom' (189daef0-c949-358b-af4d-4b9f6323edd0)
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5508] device (cdc-wdm0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Simple connect started...
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Simple connect state (4/8): Wait to get fully enabled
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Simple connect state (5/8): Register
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Simple connect state (6/8): Bearer
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Simple connect state (7/8): Connect
Apr 20 13:29:31 1dca7e1 ModemManager[727]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Apr 20 13:29:31 1dca7e1 NetworkManager[773]: <info>  [1555766971.5587] modem["cdc-wdm0"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Apr 20 13:29:32 1dca7e1 ModemManager[727]: error: couldn't start network: QMI protocol error (14): 'CallFailed'
Apr 20 13:29:32 1dca7e1 ModemManager[727]: call end reason (2): 'generic-client-end'
Apr 20 13:29:32 1dca7e1 ModemManager[727]: verbose call end reason (3,2000): [cm] client-end

This goes on and on.

Anyone has an idea what could solve this?

Thanks,

Simon

#11

Hi Simon,

Can you give a try of this Fin image that has an upgraded version of ModemManager to 1.10 and corresponding libraries: https://drive.google.com/file/d/1teIDEPV2e4cZySCmvkxoBjcQ7IfTzNnF/view?usp=sharing

This is a development type of image: https://www.balena.io/docs/learn/welcome/production-plan/#development-images

Please let me know if that works for you. If not we will look into this further.

Thanks,
Zahari

#17

Hi @majorz - Thanks for the Tip! Before I try this out I have one question:

How to set this image up so that it registers with my Balena Application? I Think I just have to copy and paste those Config-JSON-Files, right? So which one?

Best,

Simon

#18

Hey @DatacakeGmbH,

That’s correct! You can fetch the config.json file from the first partition from the device you initially provisioned, and put it on the same location in the development image. Then you can flash the image and it should work fine!

Let us know if you run into any problems!

#21

@majorz @jviotti - I tried the dev-image but that did not solve the problem unfortunately - it goes on and on like in the production image and in the console dump of my initial post here. Any other ideas?

#22

@DatacakeGmbH we’ve been investigating this internally but it doesn’t seem like something that can be fixed quickly.

The current thinking is that it’s something to do with some APNs not supporting IPV6 connectivity; this is reflected in the logs you posted where you have Apr 20 13:29:13 1dca7e1 ModemManager[727]: verbose call end reason (2,210): [internal] pdn-ipv6-call-disallowed. However, our engineers were thinking that IPV6 shouldn’t be in use anyway.

If you have time to investigate further, it would be interesting to find out if your connection works using the Fin version of Raspbian, meanwhile we’ll continue to look into it.