Frequent disconnection using Huawei MS2131i-8 3G USB dongle

Hi. We have released version 2.15.1+rev2 which has the fix for this issue.

Hi @floion,
I was just writing down an update for you. New testing is done with:

  • 2 x RPi running Resin OS 2.15.1+rev1 with Huawei MS2131i-8, no Ethernet, no WiFi
  • 1 x RPi running Resin OS 2.12.7+rev1 with Huawei MS2131i-8, no Ethernet, no WiFi

The 2.12.7 board is not giving problems, but the ones with 2.15.1 are giving the same problem as before, maybe just less frequently! Please, note that I’ve added that famous couple of lines to the udev rules on the host and rebooted.

One of the two 2.15.1 boards just got back online as soon as I’ve hooked up the Ethernet cable. I’ve been able to reset the modem with my own code here above (removing the Huawei kernel module, loading it again, then restarting ModemManager).
The second board with 2.15.1 will need a power cycle for sure, since hooking up the Ethernet cable produced to results.

Also, the two boards running 2.15.1 are running with RESIN_SUPERVISOR_PERSISTENT_LOGGING enable, but I think that this is of no help, just because they are logging too much in the case of problems, and the log seems to be limited to just 8 MB:

root@086c596:/var/log/journal# grep SystemMaxUse /etc/systemd/journald.conf
SystemMaxUse=8M

Having said that, I’ve just update one of the 2.15.1+rev1 boards to the new 2.15.1+rev2!

I’ve just power cycled my 2.15.1+rev1 board in order to examine its journal.
The board has been “patched” before by adding the famous two lines to the Huawei UDEV rules. But I’ve been able to reproduce the same problem after updating it to 2.15.1+rev2! :frowning:

From the NetworkManager unit:

Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.2599] modem["ttyUSB2"]: modem state changed, 'connected' --> 'registered' (reason: user-requested)
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.2602] device (ttyUSB2): state change: activated -> failed (reason 'modem-no-carrier', sys-iface-state: 'managed')
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.2653] manager: NetworkManager state is now CONNECTING
Sep 15 06:24:44 b651902 NetworkManager[688]: <warn>  [1536992684.2929] device (ttyUSB2): Activation: failed for connection 'h3g'
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3036] device (ttyUSB2): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3120] dns-mgr: Removing DNS information from /sbin/resolvconf
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3321] policy: auto-activating connection 'h3g' (09d0ce75-bf1b-4bed-aea4-6d1890f47d61)
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3352] device (ttyUSB2): Activation: starting connection 'h3g' (09d0ce75-bf1b-4bed-aea4-6d1890f47d61)
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3357] device (ttyUSB2): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3386] device (ttyUSB2): state change: prepare -> need-auth (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3466] device (ttyUSB2): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:44 b651902 NetworkManager[688]: <info>  [1536992684.3576] modem["ttyUSB2"]: modem state changed, 'registered' --> 'connecting' (reason: user-requested)
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.2866] modem["ttyUSB2"]: modem state changed, 'connecting' --> 'connected' (reason: user-requested)
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.2983] device (ttyUSB2): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3017] device (ttyUSB2): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3044] modem-broadband[ttyUSB2]: IPv4 static configuration:
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3047] modem-broadband[ttyUSB2]:   address 10.180.58.161/30
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3049] modem-broadband[ttyUSB2]:   gateway 10.180.58.162
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3050] modem-broadband[ttyUSB2]:   DNS 62.13.173.94
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3051] modem-broadband[ttyUSB2]:   DNS 62.13.173.95
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3130] device (ttyUSB2): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3157] device (ttyUSB2): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3166] device (ttyUSB2): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3322] policy: set 'h3g' (wwan0) as default for IPv4 routing and DNS
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3335] dns-mgr: Writing DNS information to /sbin/resolvconf
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3761] device (ttyUSB2): Activation: successful, device activated.
Sep 15 06:24:47 b651902 NetworkManager[688]: <info>  [1536992687.3783] manager: NetworkManager state is now CONNECTED_GLOBAL

From the ModemManager unit:

Sep 15 06:24:44 b651902 ModemManager[27941]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> registered)
Sep 15 06:24:44 b651902 ModemManager[27941]: Simple connect started...
Sep 15 06:24:44 b651902 ModemManager[27941]: Simple connect state (4/8): Wait to get fully enabled
Sep 15 06:24:44 b651902 ModemManager[27941]: Simple connect state (5/8): Register
Sep 15 06:24:44 b651902 ModemManager[27941]: Simple connect state (6/8): Bearer
Sep 15 06:24:44 b651902 ModemManager[27941]: Simple connect state (7/8): Connect
Sep 15 06:24:44 b651902 ModemManager[27941]: Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Sep 15 06:24:44 b651902 ModemManager[27941]: Couldn't find associated cdc-wdm port for 'net/wwan0'

Maybe the important line here above is “Couldn’t find associated cdc-wdm port for ‘net/wwan0’”.

Even if the 3G connection has been provided with an IP address, the board can’t access the Internet! I’ve hooked up an Ethernet cable to the board, added a route for a remote system via the gateway on the wwan0 interface within the container, but I can’t ping the remote system.

This seems to happen on any version after 2.12.7+rev1, including the newer 2.15.1+rev2.

I’m going to investigate on this further, but is seems that removing and reloading the Huawei kernel module and/ore restarting ModemManager can solve the problem, so I’ve implemented such a code in my application.

Aside from enabling persistente logging (as I have done), maybe it would help to be able to raise SystemMaxUse within /etc/systemd/journald.conf above its present 8 MB limit.

Hi @floion,
I can confirm that the problem persists even with 2.15.1+rev2, just as it was with 2.13.6+rev1 and 2.15.1+rev1.
The boards could be not able to connect to the internet for hours or even infinitely.
The boards could be ablet to get online as soon as an Ethernet cable is connected or not.
The problem does not show up on 2.12.7+rev1!

Hi. Can you also attach the dmesg log please?

Send via PM. Journal also. Both from the Host.

Hi. Unfortunately the dmesg is bloated with other warnings and can’t see what I am looking for.
Are you able to reboot the board, leave it running for 20 minutes or so and then grab the dmesg and send it over please?

Sure. Here it is: huaweiOnResin-dmesg-container.log (23.1 KB)
The board was connected via 3G at time of reboot and it is still connected via 3G right now.

Hi. When you use modem connectivity, one should disable udev in the container.
You do this by adding ENV UDEV off to your Dockerfile.
This will be added to our docs soon.
Can you push an update with the above, then reboot the board and check after this please?

New image uploaded yesterday in the evening. Still under testing, but things seem to get better.
Still no problem with the other boards stuck on 2.12.7+rev1 with UDEV enabled.

What “ENV UDEV off” actually does? I’m running a Python application on the board and I’m using pyudev to enumerate USB devices and reading some information from USB drives. Now the code is not working. Do you see any workaround for that in order to use pyudev?

Still the same problem with 2.15.1+rev2 with UDEV disabled.
And still no problem on other boards stuck on 2.12.7+rev1, even with UDEV enabled!

Hi @floion,
is there any other test that I can make? if not, I’ll move the board back to 2.17.7+rev1 and enable UDEV again.

Hi. On our side I could not replicate so it’s hard to say what the actual problem is.
Can you plug eth on one such device, then share the dashboard link to one of these devices and enable support access for it please?

Done. Link sent via PM.
I’ve created a new application. It installs minicom, vim, dbus and the speedtest Python module. The speedtest-cli python program is then run via crontab every hour in order to generate traffic on the 3G module, when active.
I’ve moved one device with both Ethernet and 3G USB dongle connected to the new application.