GSM module crash on boot

mhe_lorenz · January 16, 2018, 3:08pm

I am in the process of moving a functional application from a regular RPI3 running raspbian jessie and utilizing a cellular modem. The application is thus working.

I use a simple test app to test the modem in resin and have followed the cellular guide. When the modem is plugged in during boot it crashes and reboots short after displaying the screen below. When the modem is plugged in after the container has started it is registrered by ModemManager, the connection is brought up by NetworkManager and becomes visible as an interface in ifconfig (wwan0) and on the dashboard with the correct ip.

The modem is a Huawei E3372, and I am aware that it is not among the officially supported modems by either resin or NetworkManager. It has however worked flawlessly for 6 months outside resin. I have tested with and without specifying max_usb_current=1 and safe_mode_gpio=4 in config.txt.

Error screen

IMG_20180116_140238

Dockerfile

FROM resin/%%RESIN_MACHINE_NAME%%-buildpack-deps

# Switch on systemd init system in container and set various other variables
ENV INITSYSTEM="on" \
    TERM="xterm" \
    PYTHONIOENCODING="UTF-8"

WORKDIR /usr

CMD ["bash"]

/resin-boot/system-connections/gsm

[connection]
id=resin-cellular
type=gsm
autoconnect=true

[gsm]
apn=internet
number=*99#

[serial]
baud=115200

[ipv4]
method=auto

[ipv6]
addr-gen-mode=stable-privacy
method=auto

shaunmulligan · January 16, 2018, 3:18pm

Hey @mhe_lorenz , What version of resinOS are you using. It looks like you have a kernel panic. I had something similar with my Huawei MS3121i modem. It is a bug in the kernel. In resinOS v2.9.1+rev1 we bumped the kernel up to 4.9.59, which fixed this panic for me. I believe the 2.9.1 version is in testing now, so you can test this out on our staging environment at dashboard.resinstaging.io , but it should make it to production this week.

For more info on the issue. It appears that when your application container starts, it issues a udevadm trigger which replugs all USB device, this cause the modem to replugged and for some reason the kernel can’t handle that well. One other way to work around this on production is to use FROM arm32v7/debian:jessie instead of the base image you have above, this will prevent your container from triggering udev and replugging the modem, so you shouldn’t hit the issue. You can check out this branch of my test project here; https://github.com/shaunmulligan/soracom-resin-modemAT/tree/stripaway

Let me know if you need more info or if neither of these suggestions fix your issue.

mhe_lorenz · January 16, 2018, 3:24pm

Thanks for the quick response @shaunmulligan!
Resin OS 2.7.8+rev1 (dev)
Supervisor 6.4.2

You are correct, as I have simultaneously been playing around with udev rules (https://forums.balena.io/t/custom-udev-rules/2415).

I am quite new to resin and not fully aware of the differences between the official resin images and e.g arm32v7/debian:jessie. What will the consequences in regards to limited functionality in resin or the like be, if I chose to go with a non-offical resin image?

shaunmulligan · January 16, 2018, 3:31pm

@mhe_lorenz , the main differences in the resin base images are implemented in this entry.sh script. The highlights are that it allows you to optionally enable/disable systemd init system in your container and adds the udev functionality. There are also a number of useful packages preinstalled, things like i2c-tools etc. These images are mostly designed for prototyping, similarity to “regular linux” and easy of use, but if you know exactly what you want in your runtime, then I often find it easier to start from the official ones, since many of the official base images form the base of the resin.io base images. Just in case you aren’t familiar with how the resin.io base images tree works, have a look at https://docs.resin.io/runtime/resin-base-images/#resin-base-images-docs

mhe_lorenz · January 16, 2018, 5:40pm

I tried 3 things:

I tested using the same image and Resin OS 2.7.8+rev1 (dev) as before just without without playing with udev. It failed as expected.
Using arm32v7/debian:jessie and Resin OS 2.7.8+rev1 (dev) the modem worked but it took several minutes (compared to normally 1) to initialize the modem.
Using the original image and Resin OS 2.9.6+rev1 (dev). This seems to work as the device gets an ip on the dashboard no matter whether I use ethernet, wifi or cellular. It can however not test whether it actually works, as the container is inaccessible though I use the exact same dockerfile as earlier. Any idea why this would be happening @shaunmulligan?

Dockerfile

FROM resin/%%RESIN_MACHINE_NAME%%-buildpack-deps

ENV INITSYSTEM="on" \
    TERM="xterm" \
    PYTHONIOENCODING="UTF-8"

WORKDIR /usr

CMD ["bash"]

jviotti · January 16, 2018, 5:51pm

Hey there!

Can you elaborate on why the container is inaccessible? Is the device showing up in the dashboard as “online”? Are you using the web terminal? If so, what error do you get?

If the device is on the local network, you can try pinging it and see whether it responds. Also notice that if you’re using a development image, you can SSH to the host OS from within the same network, so that’s could be another way forward to continue the investigation.

shaunmulligan · January 16, 2018, 5:56pm

Hey @mhe_lorenz, what do you mean by “the container is not accessible” ? can you not access it from the webdashboard or did it not download at all? One thing I usually do in cases when trying to debug GSM modems is that I connect the device both to ethernet and GSM. Then since you have a .dev device you can SSH into the host (either from the resin UI, or by doing ssh root@<Device IP> -p22222) .

Once you are in the hostOS you can do a number of things. Some useful commands are:

list all modems:

mmcli -L

Check modem status:

mmcli -m 0

list running containers:

balena ps -a

enter a running APP:

balena exec -it <containerID> /bin/bash

with the last command there you should be able to enter your running app in the same way the webterminal works from the resin dashboard.

mhe_lorenz · January 16, 2018, 6:20pm

@jviotti and @shaunmulligan I apologize that was unclear.

I can enter the host and the container on my local network with ssh but it is displayed as offline in the dashboard all though it has an ip for both wifi, lan, and cellular, and they even disappear/change in the dashboard as expected if it plug e.g. the ethernet cable out and put it back in after a while.

The modem works as expected but it takes several before it is detected by the host OS.

The host os:

root@34d43b0:~# mmcli -L

Found 1 modems:
/org/freedesktop/ModemManager1/Modem/0 [huawei] E3372

root@34d43b0:~# mmcli -m 0

/org/freedesktop/ModemManager1/Modem/0 (device id 'c03442eb1febc02230e829e7933d771ab778563e')
 -------------------------
Hardware |   manufacturer: 'huawei'
         |          model: 'E3372'
         |       revision: '21.318.01.00.104'
         |      supported: 'gsm-umts'
         |        current: 'gsm-umts'
         |   equipment id: '861821036486782'

System   |         device: '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4'
         |        drivers: 'huawei_cdc_ncm, option1'
         |         plugin: 'Huawei'
         |   primary port: 'ttyUSB0'
         |          ports: 'ttyUSB0 (at), ttyUSB1 (at), wwan0 (net)'
-------------------------
Numbers  |           own : 'unknown'
-------------------------
Status   |           lock: 'none'
         | unlock retries: 'sim-pin (3), sim-pin2 (3), sim-puk (10), sim-puk2 (10)'
         |          state: 'connected'
         |    power state: 'on'
         |    access tech: 'lte'
         | signal quality: '54' (recent)
-------------------------
Modes    |      supported: 'allowed: 2g; preferred: none
         |                  allowed: 3g; preferred: none
         |                  allowed: 4g; preferred: none
         |                  allowed: 2g, 3g, 4g; preferred: none'
         |        current: 'allowed: 2g, 3g, 4g; preferred: none'
-------------------------
Bands    |      supported: 'unknown'
         |        current: 'unknown'
-------------------------
IP       |      supported: 'ipv4, ipv6, ipv4v6'
-------------------------
3GPP     |           imei: '861821036486782'
         |  enabled locks: 'none'
         |    operator id: '23801'
         |  operator name: 'TDC'
         |   subscription: 'unknown'
         |   registration: 'home'
-------------------------
SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

  -------------------------
Bearers  |          paths: '/org/freedesktop/ModemManager1/Bearer/1, /org/freedesktop/ModemManager1/Bearer/0'

The cointainer:

root@34d43b0:~# balena ps -a
CONTAINER ID        IMAGE                                                                       COMMAND                  CREATED             STATUS                            PORTS               NAMES
35a4ae5b8376        registry2.resinstaging.io/testos/05b55c9f6ae62310446dca8418e05b6f6edecd2c   "/usr/bin/entry.sh..."   28 minutes ago      Up 6 minutes                                          testOS_c45cf439b748499fb7132ae51ecaec9e131a9e47c8b9713fee436f5947803c7b
fbe524a56b39        resin/armv7hf-supervisor:v6.5.9                                             "/sbin/init"             6 days ago          Up 6 minutes (health: starting)                       resin_supervisor

root@34d43b0:~# balena exec -it 35a4ae5b8376 /bin/bash
root@34d43b0:/usr# ls
bin  games  include  lib  local  sbin  share  src

shaunmulligan · January 16, 2018, 6:25pm

hey @mhe_lorenz , it sounds like the device’s VPN can’t connect to resin. This can happen for a number of reasons. Can you please check that you can ping google.com from the hostOS, then check if there is anything odd in resin supervisor logs, the resin vpn logs. this can be done with the following commands:

journalctl -u resin-supervisor --no-pager

and

journalctl -u openvpn-resin -n40

mhe_lorenz · January 16, 2018, 6:37pm

Hi again @shaunmulligan,

I am able to ping google.com from the hostOS.

I note that the application is already running in the supervisor:

root@34d43b0:~# journalctl -u resin-supervisor --no-pager
-- Logs begin at Wed 2018-01-10 13:59:29 UTC, end at Tue 2018-01-16 18:32:05 UTC. --
Jan 16 18:01:20 34d43b0 systemd[1]: Starting Resin supervisor...
Jan 16 18:01:20 34d43b0 balena[1042]: resin_supervisor
Jan 16 18:01:20 34d43b0 systemd[1]: Started Resin supervisor.
Jan 16 18:01:23 34d43b0 healthdog[1070]: [56B blob data]
Jan 16 18:01:23 34d43b0 healthdog[1070]: [59B blob data]
Jan 16 18:01:23 34d43b0 healthdog[1070]: [88B blob data]
Jan 16 18:01:23 34d43b0 healthdog[1070]: [79B blob data]
Jan 16 18:01:23 34d43b0 healthdog[1070]: 2018/01/16 18:01:23 main.go:65: Resin Go Supervisor starting
Jan 16 18:01:23 34d43b0 healthdog[1070]: 2018/01/16 18:01:23 main.go:45: Changing oom_score_adj for the supervisor container to -800
Jan 16 18:01:23 34d43b0 healthdog[1070]: 2018/01/16 18:01:23 main.go:50: Changing oom_score_adj for openvpn and connmand to -1000 if 0, every 5 minutes
Jan 16 18:01:23 34d43b0 healthdog[1070]: 2018/01/16 18:01:23 main.go:35: Starting HTTP server on /var/run/resin/gosuper.sock
Jan 16 18:01:28 34d43b0 healthdog[1070]: [2018-01-16T18:01:28.221Z] Event: Supervisor start {}
Jan 16 18:01:28 34d43b0 healthdog[1070]: [2018-01-16T18:01:28.264Z] Starting connectivity check..
Jan 16 18:01:28 34d43b0 healthdog[1070]: [2018-01-16T18:01:28.330Z] Internet Connectivity: OK
Jan 16 18:01:28 34d43b0 healthdog[1070]: Tue, 16 Jan 2018 18:01:28 GMT body-parser deprecated bodyParser: use individual json/urlencoded middlewares at eval at f (/usr/src/app/dist/app.js:1:796867), <anonymous>:14:44
Jan 16 18:01:28 34d43b0 healthdog[1070]: Tue, 16 Jan 2018 18:01:28 GMT body-parser deprecated undefined extended: provide extended option at eval at wrapfunction (/usr/src/app/dist/app.js:1:116788), <anonymous>:4:11
Jan 16 18:01:28 34d43b0 healthdog[1070]: [2018-01-16T18:01:28.811Z] Starting API server..
Jan 16 18:01:28 34d43b0 healthdog[1070]: [2018-01-16T18:01:28.816Z] Starting Apps..
Jan 16 18:01:29 34d43b0 healthdog[1070]: [2018-01-16T18:01:29.115Z] Starting periodic check for IP addresses..
Jan 16 18:01:29 34d43b0 healthdog[1070]: [2018-01-16T18:01:29.139Z] Updating supervisor version and api info
Jan 16 18:01:29 34d43b0 healthdog[1070]: [2018-01-16T18:01:29.640Z] Event: Application start {"app":{"appId":"44156","imageId":"registry2.resinstaging.io/testos/05b55c9f6ae62310446dca8418e05b6f6edecd2c","commit":"05b55c9f6ae62310446dca8418e05b6f6edecd2c","name":"testOS"}}
Jan 16 18:01:29 34d43b0 healthdog[1070]: Tue, 16 Jan 2018 18:01:29 GMT body-parser deprecated bodyParser: use individual json/urlencoded middlewares at usr/src/app/dist/app.js:1:362641
Jan 16 18:01:29 34d43b0 healthdog[1070]: [2018-01-16T18:01:29.736Z] Event: Application already running {"app":{"appId":"44156","imageId":"registry2.resinstaging.io/testos/05b55c9f6ae62310446dca8418e05b6f6edecd2c","commit":"05b55c9f6ae62310446dca8418e05b6f6edecd2c","name":"testOS"}}
Jan 16 18:01:29 34d43b0 healthdog[1070]: [2018-01-16T18:01:29.743Z] Event: Start application update poll {"interval":60000}

I am not able to see anything in the openvpn log etiher. Maybe the undef in local is of importance?:

-- Logs begin at Wed 2018-01-10 13:59:29 UTC, end at Tue 2018-01-16 18:29:59 UTC. --
Jan 16 18:29:35 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link remote: [AF_INET]52.21.208.53:443[[0m
Jan 16 18:29:35 34d43b0 openvpn[714]: [[0;1;31mConnection reset, restarting [0][[0m
Jan 16 18:29:35 34d43b0 openvpn[714]: [[0;1;39mSIGUSR1[soft,connection-reset] received, process restarting[[0m
Jan 16 18:29:35 34d43b0 openvpn[714]: [[0;1;39mRestart pause, 5 second(s)[[0m
Jan 16 18:29:40 34d43b0 openvpn[714]: [[0;1;39mNOTE: the current --script-security setting may allow this configuration to call user-defined scripts[[0m
Jan 16 18:29:40 34d43b0 openvpn[714]: [[0;1;39mSocket Buffers: R=[87380->87380] S=[16384->16384][[0m
Jan 16 18:29:40 34d43b0 openvpn[714]: [[0;1;39mAttempting to establish TCP connection with [AF_INET]52.72.182.240:443 [nonblock][[0m
Jan 16 18:29:41 34d43b0 openvpn[714]: [[0;1;39mTCP connection established with [AF_INET]52.72.182.240:443[[0m
Jan 16 18:29:41 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link local: [undef][[0m
Jan 16 18:29:41 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link remote: [AF_INET]52.72.182.240:443[[0m
Jan 16 18:29:41 34d43b0 openvpn[714]: [[0;1;31mConnection reset, restarting [0][[0m
Jan 16 18:29:41 34d43b0 openvpn[714]: [[0;1;39mSIGUSR1[soft,connection-reset] received, process restarting[[0m
Jan 16 18:29:41 34d43b0 openvpn[714]: [[0;1;39mRestart pause, 5 second(s)[[0m
Jan 16 18:29:46 34d43b0 openvpn[714]: [[0;1;39mNOTE: the current --script-security setting may allow this configuration to call user-defined scripts[[0m
Jan 16 18:29:46 34d43b0 openvpn[714]: [[0;1;39mSocket Buffers: R=[87380->87380] S=[16384->16384][[0m
Jan 16 18:29:46 34d43b0 openvpn[714]: [[0;1;39mAttempting to establish TCP connection with [AF_INET]52.21.208.53:443 [nonblock][[0m
Jan 16 18:29:47 34d43b0 openvpn[714]: [[0;1;39mTCP connection established with [AF_INET]52.21.208.53:443[[0m
Jan 16 18:29:47 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link local: [undef][[0m
Jan 16 18:29:47 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link remote: [AF_INET]52.21.208.53:443[[0m
Jan 16 18:29:47 34d43b0 openvpn[714]: [[0;1;31mConnection reset, restarting [0][[0m
Jan 16 18:29:47 34d43b0 openvpn[714]: [[0;1;39mSIGUSR1[soft,connection-reset] received, process restarting[[0m
Jan 16 18:29:47 34d43b0 openvpn[714]: [[0;1;39mRestart pause, 5 second(s)[[0m
Jan 16 18:29:52 34d43b0 openvpn[714]: [[0;1;39mNOTE: the current --script-security setting may allow this configuration to call user-defined scripts[[0m
Jan 16 18:29:52 34d43b0 openvpn[714]: [[0;1;39mSocket Buffers: R=[87380->87380] S=[16384->16384][[0m
Jan 16 18:29:52 34d43b0 openvpn[714]: [[0;1;39mAttempting to establish TCP connection with [AF_INET]52.72.182.240:443 [nonblock][[0m
Jan 16 18:29:53 34d43b0 openvpn[714]: [[0;1;39mTCP connection established with [AF_INET]52.72.182.240:443[[0m
Jan 16 18:29:53 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link local: [undef][[0m
Jan 16 18:29:53 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link remote: [AF_INET]52.72.182.240:443[[0m
Jan 16 18:29:53 34d43b0 openvpn[714]: [[0;1;31mConnection reset, restarting [0][[0m
Jan 16 18:29:53 34d43b0 openvpn[714]: [[0;1;39mSIGUSR1[soft,connection-reset] received, process restarting[[0m
Jan 16 18:29:53 34d43b0 openvpn[714]: [[0;1;39mRestart pause, 5 second(s)[[0m
Jan 16 18:29:58 34d43b0 openvpn[714]: [[0;1;39mNOTE: the current --script-security setting may allow this configuration to call user-defined scripts[[0m
Jan 16 18:29:58 34d43b0 openvpn[714]: [[0;1;39mSocket Buffers: R=[87380->87380] S=[16384->16384][[0m
Jan 16 18:29:58 34d43b0 openvpn[714]: [[0;1;39mAttempting to establish TCP connection with [AF_INET]52.21.208.53:443 [nonblock][[0m
Jan 16 18:29:59 34d43b0 openvpn[714]: [[0;1;39mTCP connection established with [AF_INET]52.21.208.53:443[[0m
Jan 16 18:29:59 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link local: [undef][[0m
Jan 16 18:29:59 34d43b0 openvpn[714]: [[0;1;39mTCPv4_CLIENT link remote: [AF_INET]52.21.208.53:443[[0m
Jan 16 18:29:59 34d43b0 openvpn[714]: [[0;1;31mConnection reset, restarting [0][[0m
Jan 16 18:29:59 34d43b0 openvpn[714]: [[0;1;39mSIGUSR1[soft,connection-reset] received, process restarting[[0m
Jan 16 18:29:59 34d43b0 openvpn[714]: [[0;1;39mRestart pause, 5 second(s)[[0m

shaunmulligan · January 16, 2018, 6:43pm

yeah, its seems like the resin VPN keeps restarting over and over. Not sure what the cause of that is. I have pinged some of the other guys who know about this kinda stuff, hopefully they will have some clever ideas.

If you have a second SD card, it might be a good idea to try provision a second device and see if it behaves in the same way.

mhe_lorenz · January 18, 2018, 4:32pm

I tested again today and had no errors with the Resin OS 2.9.6+rev1 (dev). I also did a fresh flash of the image, and it also worked.

mhe_lorenz · January 18, 2018, 5:22pm

Further testing have revealed that the modem is recognized correctly and gets an ip but the host OS is unable to ping.

root@ef35cd3:/mnt/data/resin-data/resin-supervisor# ifconfig 
balena0   Link encap:Ethernet  HWaddr 02:42:DB:85:F3:28  
      inet addr:10.114.101.1  Bcast:0.0.0.0  Mask:255.255.255.0
      UP BROADCAST MULTICAST  MTU:1500  Metric:1
      RX packets:0 errors:0 dropped:0 overruns:0 frame:0
      TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:0 
      RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

eth0      Link encap:Ethernet  HWaddr B8:27:EB:E7:47:31  
      UP BROADCAST MULTICAST  MTU:1500  Metric:1
      RX packets:191 errors:0 dropped:0 overruns:0 frame:0
      TX packets:189 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:1000 
      RX bytes:30431 (29.7 KiB)  TX bytes:29267 (28.5 KiB)

lo        Link encap:Local Loopback  
      inet addr:127.0.0.1  Mask:255.0.0.0
      inet6 addr: ::1/128 Scope:Host
      UP LOOPBACK RUNNING  MTU:65536  Metric:1
      RX packets:3693 errors:0 dropped:0 overruns:0 frame:0
      TX packets:3693 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:1 
      RX bytes:297569 (290.5 KiB)  TX bytes:297569 (290.5 KiB)

resin-dns Link encap:Ethernet  HWaddr A6:4C:23:CC:7D:EE  
      inet addr:10.114.102.1  Bcast:0.0.0.0  Mask:255.255.255.0
      inet6 addr: fe80::a44c:23ff:fecc:7dee/64 Scope:Link
      UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
      RX packets:0 errors:0 dropped:0 overruns:0 frame:0
      TX packets:44 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:1000 
      RX bytes:0 (0.0 B)  TX bytes:6035 (5.8 KiB)

resin-vpn Link encap:UNSPEC  HWaddr 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  
      inet addr:10.2.0.89  P-t-P:52.73.237.197  Mask:255.255.255.255
      inet6 addr: fe80::db46:1729:491b:b686/64 Scope:Link
      UP POINTOPOINT RUNNING NOARP MULTICAST  MTU:1500  Metric:1
      RX packets:0 errors:0 dropped:0 overruns:0 frame:0
      TX packets:6 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:100 
      RX bytes:0 (0.0 B)  TX bytes:288 (288.0 B)

wlan0     Link encap:Ethernet  HWaddr 2A:8F:04:02:39:7F  
      UP BROADCAST MULTICAST  MTU:1500  Metric:1
      RX packets:0 errors:0 dropped:0 overruns:0 frame:0
      TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:1000 
      RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

wwan0     Link encap:Ethernet  HWaddr 00:1E:10:1F:00:00  
      inet addr:10.7.223.196  Bcast:10.7.223.199  Mask:255.255.255.248
      UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
      RX packets:0 errors:237 dropped:0 overruns:0 frame:0
      TX packets:513 errors:0 dropped:0 overruns:0 carrier:0
      collisions:0 txqueuelen:1000 
      RX bytes:0 (0.0 B)  TX bytes:23850 (23.2 KiB)

route:

root@ef35cd3:/mnt/data/resin-data/resin-supervisor# route
Kernel IP routing table
Destination     Gateway         Genmask         Flags Metric Ref    Use Iface
default         10.7.223.193    0.0.0.0         UG    700    0        0 wwan0
10.7.223.192    *               255.255.255.248 U     700    0        0 wwan0
10.114.101.0    *               255.255.255.0   U     0      0        0 balena0
10.114.102.0    *               255.255.255.0   U     0      0        0 resin-dns
10.114.102.0    *               255.255.255.0   U     425    0        0 resin-dns
52.73.237.197   *               255.255.255.255 UH    0      0        0 resin-vpn

I think the error might be in the routing as none of it point to the modem? Am I somewhat correct? And if so why is this not correct by default?

nmcli c
NAME                UUID                                  TYPE      DEVICE    
[[32mresin-cellular[[0m      [[32m7890c280-8824-3f47-b394-10b6dd3c562e[[0m  [[32mgsm[[0m       [[32mttyUSB0[[0m   
[[32mresin-dns[[0m           [[32m1eeed5a8-0ca0-485f-8cf9-60e327f5afb6[[0m  [[32mbridge[[0m    [[32mresin-dns[[0m 
Wired connection 1  51b5b205-2bbd-3858-94a5-0867f7b27972  ethernet  -- 

nmcli d
DEVICE     TYPE      STATE         CONNECTION     
[[32mttyUSB0[[0m    [[32mgsm[[0m       [[32mconnected[[0m     [[32mresin-cellular[[0m 
[[32mresin-dns[[0m  [[32mbridge[[0m    [[32mconnected[[0m     [[32mresin-dns[[0m      
[[31mwlan0[[0m      [[31mwifi[[0m      [[31mdisconnected[[0m  [[31m--[[0m             
[[2meth0[[0m       [[2methernet[[0m  [[2munavailable[[0m   [[2m--[[0m             
[[2mbalena0[[0m    [[2mbridge[[0m    [[2munmanaged[[0m     [[2m--[[0m             
[[2mlo[[0m         [[2mloopback[[0m  [[2munmanaged[[0m     [[2m--[[0m             
[[2mresin-vpn[[0m  [[2mtun[[0m       [[2munmanaged[[0m     [[2m--[[0m

mmcli -L
root@ef35cd3:/mnt/data/resin-data/resin-supervisor# mmcli -L

Found 1 modems:
        /org/freedesktop/ModemManager1/Modem/0 [huawei] E3372

Once in a while the following message is also reported:

root@ef35cd3:/mnt/data/resin-data/resin-supervisor# [  676.567927] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready

Do you have any ideas @shaunmulligan or @jviotti?

floion · February 12, 2018, 1:39pm

Can you paste the output of “dmesg” and “mmcli -m 0” please?

mhe_lorenz · February 12, 2018, 2:01pm

Sure @floion. Here they are!

root@aab36ea:~# dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.9.59 (oe-user@oe-host) (gcc version 6.3.0 (GCC) ) #2 SMP Wed Feb 7 10:31:49 UTC 2018
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt:Machine model: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] cma: Reserved 8 MiB at 0x3dc00000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] On node 0 totalpages: 255488
[    0.000000] free_area_init_node: node 0, pgdat 80f74400, node_mem_map bd336000
[    0.000000]   Normal zone: 2246 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 255488 pages, LIFO batch:31
[    0.000000] percpu: Embedded 14 pages/cpu @be5b0000 s26060 r8192 d23092 u57344
[    0.000000] pcpu-alloc: s26060 r8192 d23092 u57344 alloc=14*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 253242
[    0.000000] Kernel command line: 8250.nr_uarts=1 bcm2708_fb.fbwidth=1824 bcm2708_fb.fbheight=984 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000  dwc_otg.lpm_enable=0 console=tty1 console=ttyS0,115200 root=/dev/mmcblk0p2 rootfstype=ext4 rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 987992K/1021952K available (7168K kernel code, 507K rwdata, 2244K rodata, 4096K init, 781K bss, 25768K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xbe800000 - 0xff800000   (1040 MB)
                   lowmem  : 0x80000000 - 0xbe600000   ( 998 MB)
                   modules : 0x7f000000 - 0x80000000   (  16 MB)
                     .text : 0x80008000 - 0x80800000   (8160 kB)
                     .init : 0x80b00000 - 0x80f00000   (4096 kB)
                     .data : 0x80f00000 - 0x80f7ec14   ( 508 kB)
                      .bss : 0x80f80000 - 0x810437ec   ( 782 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] 	Build-time adjustment of leaf fanout to 32.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] arm_arch_timer: Architected cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000023] Switching to timer-based delay loop, resolution 52ns
[    0.000280] Console: colour dummy device 80x30
[    0.001140] console [tty1] enabled
[    0.001189] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001255] pid_max: default: 32768 minimum: 301
[    0.001584] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001626] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002649] CPU: Testing write buffer coherency: ok
[    0.002713] ftrace: allocating 24632 entries in 73 pages
[    0.055929] CPU0: update cpu_capacity 1024
[    0.055980] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.056041] Setting up static identity map for 0x100000 - 0x100034
[    0.057930] CPU1: update cpu_capacity 1024
[    0.057937] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.058598] CPU2: update cpu_capacity 1024
[    0.058605] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.059245] CPU3: update cpu_capacity 1024
[    0.059252] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.059342] Brought up 4 CPUs
[    0.059516] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.059545] CPU: All CPU(s) started in HYP mode.
[    0.059571] CPU: Virtualization extensions available.
[    0.060404] devtmpfs: initialized
[    0.071349] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.071655] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.071717] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.072296] pinctrl core: initialized pinctrl subsystem
[    0.073232] NET: Registered protocol family 16
[    0.075352] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.084081] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.084130] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.084294] Serial: AMBA PL011 UART driver
[    0.086159] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.086693] uart-pl011 3f201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[    0.087254] irq: no irq domain found for /soc/aux@0x7e215000 !
[    0.156814] bcm2835-dma 3f007000.dma: DMA legacy API manager at be80f000, dmachans=0x1
[    0.158692] SCSI subsystem initialized
[    0.158870] usbcore: registered new interface driver usbfs
[    0.158979] usbcore: registered new interface driver hub
[    0.159097] usbcore: registered new device driver usb
[    0.165724] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-08-08 12:02
[    0.167101] clocksource: Switched to clocksource arch_sys_counter
[    0.214229] VFS: Disk quotas dquot_6.6.0
[    0.214342] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.214582] FS-Cache: Loaded
[    0.214852] CacheFiles: Loaded
[    0.227150] NET: Registered protocol family 2
[    0.228064] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.228203] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.228413] TCP: Hash tables configured (established 8192 bind 8192)
[    0.228526] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.228594] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.228830] NET: Registered protocol family 1
[    0.229272] RPC: Registered named UNIX socket transport module.
[    0.229305] RPC: Registered udp transport module.
[    0.229332] RPC: Registered tcp transport module.
[    0.229360] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.528268] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    0.530704] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.546309] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.546852] FS-Cache: Netfs 'nfs' registered for caching
[    0.547916] NFS: Registering the id_resolver key type
[    0.547968] Key type id_resolver registered
[    0.547996] Key type id_legacy registered
[    0.549617] aufs 4.9-20171030
[    0.551015] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    0.551216] io scheduler noop registered
[    0.551246] io scheduler deadline registered
[    0.551532] io scheduler cfq registered (default)
[    0.557284] BCM2708FB: allocated DMA memory fdd10000
[    0.557339] BCM2708FB: allocated DMA channel 0 @ be80f000
[    0.583810] Console: switching to colour frame buffer device 228x61
[    0.676920] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    0.677779] bcm2835-aux-uart 3f215040.serial: could not get clk: -517
[    0.678937] bcm2835-rng 3f104000.rng: hwrng registered
[    0.679154] vc-mem: phys_addr:0x00000000 mem_base=0x3f000000 mem_size:0x3f600000(1014 MiB)
[    0.679778] vc-sm: Videocore shared memory driver
[    0.694745] brd: module loaded
[    0.703816] loop: module loaded
[    0.703907] Loading iSCSI transport class v2.0-870.
[    0.704409] tun: Universal TUN/TAP device driver, 1.6
[    0.704501] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[    0.704889] usbcore: registered new interface driver smsc95xx
[    0.704997] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.933169] Core Release: 2.80a
[    0.933237] Setting default values for core params
[    0.933344] Finished setting default values for core params
[    1.133791] Using Buffer DMA mode
[    1.133857] Periodic Transfer Interrupt Enhancement - disabled
[    1.133954] Multiprocessor Interrupt Enhancement - disabled
[    1.134047] OTG VER PARAM: 0, OTG VER FLAG: 0
[    1.134133] Dedicated Tx FIFOs mode
[    1.134512] WARN::dwc_otg_hcd_init:1032: FIQ DMA bounce buffers: virt = 0xbdd04000 dma = 0xfdd04000 len=9024
[    1.134686] FIQ FSM acceleration enabled for :
               Non-periodic Split Transactions
               Periodic Split Transactions
               High-Speed Isochronous Endpoints
               Interrupt/Control Split Transaction hack enabled
[    1.135024] dwc_otg: Microframe scheduler enabled
[    1.135072] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x805f0ad4
[    1.135180] WARN::hcd_init_fiq:460: FIQ ASM at 0x805f0e34 length 36
[    1.135289] WARN::hcd_init_fiq:486: MPHI regs_base at 0xbe87a000
[    1.135440] dwc_otg 3f980000.usb: DWC OTG Controller
[    1.135556] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    1.140107] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[    1.144642] Init: Port Power? op_state=1
[    1.149143] Init: Power Port (0)
[    1.153778] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    1.158292] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.162768] usb usb1: Product: DWC OTG Controller
[    1.167226] usb usb1: Manufacturer: Linux 4.9.59 dwc_otg_hcd
[    1.171670] usb usb1: SerialNumber: 3f980000.usb
[    1.176838] hub 1-0:1.0: USB hub found
[    1.181286] hub 1-0:1.0: 1 port detected
[    1.186309] dwc_otg: FIQ enabled
[    1.186314] dwc_otg: NAK holdoff enabled
[    1.186318] dwc_otg: FIQ split-transaction FSM enabled
[    1.186331] Module dwc_common_port init
[    1.186568] usbcore: registered new interface driver usb-storage
[    1.191285] mousedev: PS/2 mouse device common for all mice
[    1.196776] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[    1.201578] bcm2835-cpufreq: min=600000 max=1200000
[    1.206502] sdhci: Secure Digital Host Controller Interface driver
[    1.209975] sdhci: Copyright(c) Pierre Ossman
[    1.212389] sdhost-bcm2835 3f202000.sdhost: could not get clk, deferring probe
[    1.216673] mmc-bcm2835 3f300000.mmc: could not get clk, deferring probe
[    1.218997] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.223626] ledtrig-cpu: registered to indicate activity on CPUs
[    1.226048] hidraw: raw HID events driver (C) Jiri Kosina
[    1.228507] usbcore: registered new interface driver usbhid
[    1.230816] usbhid: USB HID core driver
[    1.233652] vchiq: vchiq_init_state: slot_zero = 0xbdd80000, is_master = 0
[    1.237079] [vc_sm_connected_init]: start
[    1.240622] vc_vchi_sm_init: failed to open VCHI service (-1)
[    1.240673] [vc_sm_connected_init]: failed to initialize shared memory service
[    1.243080] [vc_sm_connected_init]: end - returning -1
[    1.245887] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[    1.248916] ip_tables: (C) 2000-2006 Netfilter Core Team
[    1.251438] Initializing XFRM netlink socket
[    1.254404] NET: Registered protocol family 10
[    1.257527] NET: Registered protocol family 17
[    1.259957] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    1.262505] Key type dns_resolver registered
[    1.265153] Registering SWP/SWPB emulation handler
[    1.268094] registered taskstats version 1
[    1.274563] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    1.277178] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[    1.280942] console [ttyS0] disabled
[    1.283497] 3f215040.serial: ttyS0 at MMIO 0x0 (irq = 220, base_baud = 31250000) is a 16550
[    2.320912] console [ttyS0] enabled
[    2.327504] sdhost: log_buf @ bdd07000 (fdd07000)
[    2.407105] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    2.417256] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    2.425739] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[    2.454354] Indeed it is in host mode hprt0 = 00021501
[    2.547185] of_cfs_init
[    2.549275] random: fast init done
[    2.558320] of_cfs_init: OK
[    2.573502] Freeing unused kernel memory: 4096K
[    2.575823] mmc0: host does not support reading read-only switch, assuming write-enable
[    2.577775] mmc0: new high speed SDHC card at address 0007
[    2.578341] mmcblk0: mmc0:0007 SD32G 28.8 GiB
[    2.582139] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    2.583637] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    2.585137] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    2.587837] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    2.642211]  mmcblk0: p1 p2 p3 p4 < p5 p6 >
[    2.657162] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    2.666836] Indeed it is in host mode hprt0 = 00001101
[    2.759745] mmc1: new high speed SDIO card at address 0001
[    2.897448] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    2.907257] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.917708] hub 1-1:1.0: USB hub found
[    2.924235] hub 1-1:1.0: 5 ports detected
[    3.247203] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.397445] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    3.407042] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.419913] smsc95xx v1.0.5
[    3.540282] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:f2:4a:ec
[    3.663647] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.698934] EXT4-fs (mmcblk0p5): mounted filesystem with ordered data mode. Opts: (null)
[    4.144754] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    4.166184] aufs au_opts_verify:1645:init[1]: dirperm1 breaks the protection by the permission bits on the lower branch
[    4.207120] usb 1-1.3: new high-speed USB device number 4 using dwc_otg
[    4.360178] usb 1-1.3: New USB device found, idVendor=0bda, idProduct=5411
[    4.369818] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.379874] usb 1-1.3: Product: 4-Port USB 2.0 Hub
[    4.387336] usb 1-1.3: Manufacturer: Generic
[    4.395286] hub 1-1.3:1.0: USB hub found
[    4.403811] hub 1-1.3:1.0: 4 ports detected
[    4.727134] usb 1-1.3.3: new full-speed USB device number 5 using dwc_otg
[    4.873211] usb 1-1.3.3: New USB device found, idVendor=046d, idProduct=c52f
[    4.885477] usb 1-1.3.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.898159] usb 1-1.3.3: Product: USB Receiver
[    4.907706] usb 1-1.3.3: Manufacturer: Logitech
[    4.923976] input: Logitech USB Receiver as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3.3/1-1.3.3:1.0/0003:046D:C52F.0001/input/input0
[    4.942894] hid-generic 0003:046D:C52F.0001: input,hidraw0: USB HID v1.11 Mouse [Logitech USB Receiver] on usb-3f980000.usb-1.3.3/input0
[    4.966208] input: Logitech USB Receiver as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3.3/1-1.3.3:1.1/0003:046D:C52F.0002/input/input1
[    5.047608] hid-generic 0003:046D:C52F.0002: input,hiddev0,hidraw1: USB HID v1.11 Device [Logitech USB Receiver] on usb-3f980000.usb-1.3.3/input1
[    5.167138] usb 1-1.3.4: new low-speed USB device number 6 using dwc_otg
[    5.334962] usb 1-1.3.4: New USB device found, idVendor=046d, idProduct=c328
[    5.347539] usb 1-1.3.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    5.360446] usb 1-1.3.4: Product: USB Keyboard
[    5.370142] usb 1-1.3.4: Manufacturer: Logitech
[    5.400658] input: Logitech USB Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.0/0003:046D:C328.0003/input/input2
[    5.487789] hid-generic 0003:046D:C328.0003: input,hidraw2: USB HID v1.10 Keyboard [Logitech USB Keyboard] on usb-3f980000.usb-1.3.4/input0
[    5.526501] input: Logitech USB Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3.4/1-1.3.4:1.1/0003:046D:C328.0004/input/input3
[    5.607735] hid-generic 0003:046D:C328.0004: input,hiddev0,hidraw3: USB HID v1.10 Device [Logitech USB Keyboard] on usb-3f980000.usb-1.3.4/input1
[    6.236726] systemd[1]: System time before build time, advancing clock.
[    6.281031] systemd[1]: systemd 232 running in system mode. (-PAM -AUDIT -SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
[    6.305899] systemd[1]: Detected architecture arm.
[    6.348600] systemd[1]: Set hostname to <raspberrypi3>.
[    6.362397] systemd[1]: Hardware watchdog 'Broadcom BCM2835 Watchdog timer', version 0
[    6.376359] systemd[1]: Set hardware watchdog to 10s.
[    6.529474] systemd[1]: [/lib/systemd/system/systemd-ask-password-plymouth.service:12] Executable path is not absolute, ignoring: --watch --plymouth
[    6.549414] systemd[1]: systemd-ask-password-plymouth.service: Service lacks both ExecStart= and ExecStop= setting. Refusing.
[    6.663248] systemd[1]: mnt-sysroot-active.mount: Unit is bound to inactive unit dev-mmcblk0p2.device. Stopping, too.
[    6.680706] systemd[1]: Requested transaction contradicts existing jobs: Resource deadlock avoided
[    6.785113] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    8.447425] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    8.797941] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[    8.803322] usbcore: registered new interface driver brcmfmac
[    8.890826] random: crng init done
[    8.990063] brcmfmac: Firmware version = wl0: Aug  7 2017 00:46:29 version 7.45.41.46 (r666254 CY) FWID 01-f8a78378
[    9.017922] brcmfmac: brcmf_c_preinit_dcmds: CLM version = API: 12.2 Data: 7.11.15 Compiler: 1.24.2 ClmImport: 1.24.1 Creation: 2014-05-26 10:53:55 Inc Data: 9.10.41 Inc Compiler: 1.29.4 Inc ClmImport: 1.36.3 Creation: 2017-08-07 00:37:47 
[    9.920105] EXT4-fs (mmcblk0p3): mounted filesystem with ordered data mode. Opts: (null)
[    9.976936] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[   11.078165] uart-pl011 3f201000.serial: no DMA platform data
[   13.937184] usb 1-1.4: new high-speed USB device number 7 using dwc_otg
[   14.078897] usb 1-1.4: New USB device found, idVendor=12d1, idProduct=14fe
[   14.085373] EXT4-fs (mmcblk0p6): mounted filesystem with ordered data mode. Opts: (null)
[   14.101674] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   14.101683] usb 1-1.4: Product: HUAWEI_MOBILE
[   14.101686] usb 1-1.4: Manufacturer: HUAWEI_MOBILE
[   14.101690] usb 1-1.4: SerialNumber: 0123456789ABCDEF
[   14.140708] usb-storage 1-1.4:1.0: USB Mass Storage device detected
[   14.155439] scsi host0: usb-storage 1-1.4:1.0
[   15.225947] scsi 0:0:0:0: CD-ROM            HUAWEI   Mass Storage     2.31 PQ: 0 ANSI: 2
[   15.240343] scsi 0:0:0:1: Direct-Access     HUAWEI   TF CARD Storage  2.31 PQ: 0 ANSI: 2
[   15.257448] sd 0:0:0:1: [sda] Attached SCSI removable disk
[   15.301030] i2c /dev entries driver
[   15.508229] brcmfmac: power management disabled
[   15.567398] Bluetooth: Core ver 2.22
[   15.578310] NET: Registered protocol family 31
[   15.589986] Bluetooth: HCI device and connection manager initialized
[   15.603461] Bluetooth: HCI socket layer initialized
[   15.615637] Bluetooth: L2CAP socket layer initialized
[   15.627987] Bluetooth: SCO socket layer initialized
[   15.669626] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   15.675362] Bluetooth: HCI UART driver ver 2.3
[   15.675369] Bluetooth: HCI UART protocol H4 registered
[   15.675374] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   15.675579] Bluetooth: HCI UART protocol Broadcom registered
[   15.808433] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   15.877681] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   15.923972] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   15.933749] brcmfmac: power management disabled
[   15.949321] usb 1-1.4: USB disconnect, device number 7
[   16.167922] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   16.173588] Bluetooth: BNEP filters: protocol multicast
[   16.179341] Bluetooth: BNEP socket layer initialized
[   16.484686] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   16.490962] brcmfmac: power management disabled
[   16.857868] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[   17.017132] usb 1-1.4: new high-speed USB device number 8 using dwc_otg
[   17.148073] usb 1-1.4: New USB device found, idVendor=12d1, idProduct=1506
[   17.155203] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[   17.162838] usb 1-1.4: Product: HUAWEI_MOBILE
[   17.167450] usb 1-1.4: Manufacturer: HUAWEI_MOBILE
[   17.266986] usb-storage 1-1.4:1.3: USB Mass Storage device detected
[   17.274185] scsi host0: usb-storage 1-1.4:1.3
[   17.280813] usb-storage 1-1.4:1.4: USB Mass Storage device detected
[   17.287903] scsi host1: usb-storage 1-1.4:1.4
[   17.300877] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC1E1
[   18.337607] scsi 1:0:0:0: Direct-Access     HUAWEI   TF CARD Storage  2.31 PQ: 0 ANSI: 2
[   18.346245] scsi 0:0:0:0: CD-ROM            HUAWEI   Mass Storage     2.31 PQ: 0 ANSI: 2
[   18.360029] sd 1:0:0:0: [sda] Attached SCSI removable disk
[   19.308742] Netfilter messages via NETLINK v0.30.
[   20.391343] ctnetlink v0.93: registering with nfnetlink.
[   20.411570] IPv6: ADDRCONF(NETDEV_UP): balena0: link is not ready
[   23.031152] Bridge firewalling registered
[  194.629561] sr 0:0:0:0: [sr0] scsi-1 drive
[  194.633827] cdrom: Uniform CD-ROM driver Revision: 3.20
[  194.641396] sr 0:0:0:0: Attached scsi CD-ROM sr0
[  194.703709] usbcore: registered new interface driver cdc_ncm
[  194.726653] usbcore: registered new interface driver cdc_wdm
[  194.740933] usbcore: registered new interface driver usbserial
[  194.747163] usbcore: registered new interface driver usbserial_generic
[  194.754465] usbserial: USB Serial support registered for generic
[  194.784239] usbcore: registered new interface driver option
[  194.791914] usbserial: USB Serial support registered for GSM modem (1-port)
[  194.826511] huawei_cdc_ncm 1-1.4:1.2: MAC-Address: 00:1e:10:1f:00:00
[  194.833201] huawei_cdc_ncm 1-1.4:1.2: setting rx_max = 16384
[  194.846720] huawei_cdc_ncm 1-1.4:1.2: NDP will be placed at end of frame for this device.
[  194.856154] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  194.864593] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  194.867014] huawei_cdc_ncm 1-1.4:1.2: cdc-wdm0: USB WDM device
[  194.868010] huawei_cdc_ncm 1-1.4:1.2 wwan0: register 'huawei_cdc_ncm' at usb-3f980000.usb-1.4, Huawei CDC NCM device, 00:1e:10:1f:00:00
[  194.868242] option 1-1.4:1.0: GSM modem (1-port) converter detected
[  194.868729] usbcore: registered new interface driver huawei_cdc_ncm
[  194.875564] usb 1-1.4: GSM modem (1-port) converter now attached to ttyUSB0
[  194.875712] option 1-1.4:1.1: GSM modem (1-port) converter detected
[  194.876354] usb 1-1.4: GSM modem (1-port) converter now attached to ttyUSB1
[  194.922660] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  194.927960] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8d fc 00 00 02 00
[  194.927969] blk_update_request: critical medium error, dev sr0, sector 145392
[  194.943657] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  194.952053] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  194.958025] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  194.963287] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8d fc 00 00 02 00
[  194.971036] blk_update_request: critical medium error, dev sr0, sector 145392
[  194.978348] Buffer I/O error on dev sr0, logical block 18174, async page read
[  195.102323] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.110723] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.116717] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.121991] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8c 80 00 00 3c 00
[  195.129744] blk_update_request: critical medium error, dev sr0, sector 143872
[  195.143406] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.151782] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.157755] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.163020] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8c bc 00 00 04 00
[  195.170763] blk_update_request: critical medium error, dev sr0, sector 144112
[  195.184415] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.192808] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.198789] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.204056] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8c 80 00 00 02 00
[  195.211830] blk_update_request: critical medium error, dev sr0, sector 143872
[  195.219162] Buffer I/O error on dev sr0, logical block 17984, async page read
[  195.234135] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.242536] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.248512] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.253779] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8d fa 00 00 02 00
[  195.261522] blk_update_request: critical medium error, dev sr0, sector 145384
[  195.303218] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.340010] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.374856] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.409010] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8d fa 00 00 02 00
[  195.445765] blk_update_request: critical medium error, dev sr0, sector 145384
[  195.482712] Buffer I/O error on dev sr0, logical block 18173, async page read
[  195.553785] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.592506] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.628944] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.664670] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8d f6 00 00 02 00
[  195.702907] blk_update_request: critical medium error, dev sr0, sector 145368
[  195.748115] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  195.788259] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  195.825666] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  195.862439] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8d f6 00 00 02 00
[  195.902111] blk_update_request: critical medium error, dev sr0, sector 145368
[  195.941460] Buffer I/O error on dev sr0, logical block 18171, async page read
[  196.014523] sr 0:0:0:0: [sr0] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08
[  196.055104] sr 0:0:0:0: [sr0] tag#0 Sense Key : 0x3 [current] 
[  196.093194] sr 0:0:0:0: [sr0] tag#0 ASC=0x11 ASCQ=0x0 
[  196.130650] sr 0:0:0:0: [sr0] tag#0 CDB: opcode=0x28 28 00 00 00 8c 80 00 00 3c 00
[  196.170440] blk_update_request: critical medium error, dev sr0, sector 143872
[  196.222778] Buffer I/O error on dev sr0, logical block 17984, async page read
[  196.275403] Buffer I/O error on dev sr0, logical block 18170, async page read
[  361.583569] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[  361.596449] brcmfmac: power management disabled

.
root@aab36ea:~# mmcli -m 0

/org/freedesktop/ModemManager1/Modem/0 (device id 'c03442eb1febc02230e829e7933d771ab778563e')
  -------------------------
  Hardware |   manufacturer: 'huawei'
           |          model: 'E3372'
           |       revision: '21.318.01.00.104'
           |      supported: 'gsm-umts'
           |        current: 'gsm-umts'
           |   equipment id: '861821036486782'
  -------------------------
  System   |         device: '/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4'
           |        drivers: 'huawei_cdc_ncm, option1'
           |         plugin: 'Huawei'
           |   primary port: 'ttyUSB0'
           |          ports: 'ttyUSB0 (at), ttyUSB1 (at), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'none'
           | unlock retries: 'sim-pin (3), sim-pin2 (3), sim-puk (10), sim-puk2 (10)'
           |          state: 'connected'
           |    power state: 'on'
           |    access tech: 'lte'
           | signal quality: '100' (recent)
  -------------------------
  Modes    |      supported: 'allowed: 2g; preferred: none
           |                  allowed: 3g; preferred: none
           |                  allowed: 4g; preferred: none
           |                  allowed: 2g, 3g, 4g; preferred: none'
           |        current: 'allowed: 2g, 3g, 4g; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  3GPP     |           imei: '861821036486782'
           |  enabled locks: 'none'
           |    operator id: '23801'
           |  operator name: 'TDC'
           |   subscription: 'unknown'
           |   registration: 'home'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

  -------------------------
  Bearers  |          paths: '/org/freedesktop/ModemManager1/Bearer/1, /org/freedesktop/ModemManager1/Bearer/0'

mhe_lorenz · February 12, 2018, 2:02pm

It takes 2-3 minutes before the modem is detected but I guess that is due to the required modeswitch.

floion · February 12, 2018, 6:27pm

Can you also paste the output of:

mmcli -m 0 --command=“+UUSBCONF?”

and

mmcli -m 0 --command=“+UUSBCONF=?”

please?

mhe_lorenz · February 12, 2018, 9:40pm

Here you go @floion!

bash-4.3# mmcli -m 0 --command="+UUSBCONF?"
error: command failed: 'GDBus.Error:org.freedesktop.ModemManager1.Error.MobileEquipment.Unknown: Unknown error' 

bash-4.3# mmcli -m 0 --command="+UUSBCONF=?"
error: command failed: 'GDBus.Error:org.freedesktop.ModemManager1.Error.MobileEquipment.Unknown: Unknown error'

floion · February 14, 2018, 7:25am

Do you have the ability to build your own image? The reason I am asking this is because in master we have updated ModemManager. And we should debug your problem with this new MM version. So you can either build resinOS for RPI3 yourself from master and then we can continue with this or we can wait a few days until we do a new release for the pi3.
Let me know how you feel about this

mhe_lorenz · February 15, 2018, 12:47am

@floion, I guess that building myself will at some point require cross compiling? I have had success with that in some images while it have failed on others - e.g. with ROS. If a can grab the docker file or similar instructions somewhere I could give it a try. The feasibility of this depends on when the release is out, as I am out of office until monday.