I had a project going where I had to give a Raspberry Pi network connectivity, which seemed to me like a pretty common requirement. The hardware I was provided with was a Raspberry Pi 3, and a USB-3G stick (or internet stick like they call them here) by Huawei, the E3531. While I did not expect this to be straightforward plug and play, I have to say I’m slightly dismayed at how complicated the journey was. From apparent EMI (electromagnetic interference), to obscure config settings, I’ve definitely learned a bunch of new things.
The Pi and the stick
Thankfully the hardware of the stick itself is pretty straightforward: take off the cover, slap in the SIM card, and off you go. Surely enough, plugging in the stick to a laptop running Windows, the interface was directly recognised, and after entering the PIN, the laptop was online. Good, that meant the stick itself worked fine.
Ethernet woes
Having confirmed the stick as known-good, I plugged it into the Pi. Then something odd happened. It might be relevant to mention at this point that I usually work with the Pi over SSH. In this case, I was sharing internet with the Pi from my Macbook, so that I could SSH in over Ethernet. However, as soon as I would plug in the stick, my shell on the Pi would time out. Additionally, the status indicator LED on the 3G stick kept flashing in the same pattern. I figured there could be a plausible explanation regarding network interfaces, perhaps the stick nuked the Ethernet interface in order to provide its own.
I SSH’d in over WiFi to go check things out. I unplugged the stick, tail -f‘d the /var/log/syslog/ and tried to see what was going on. It quickly became clear that plugging in the 3G stick caused the Pi to go in some sort of network-interface-initialising loop:
Dec 14 19:36:34 raspberrypi kernel: [ 600.294878] usb 1-1.4: New USB device found, idVendor=12d1, idProduct=15d2
Dec 14 19:36:34 raspberrypi kernel: [ 600.294892] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Dec 14 19:36:34 raspberrypi kernel: [ 600.294899] usb 1-1.4: Product: HUAWEI Mobile
Dec 14 19:36:34 raspberrypi kernel: [ 600.294905] usb 1-1.4: Manufacturer: HUAWEI
Dec 14 19:36:34 raspberrypi kernel: [ 600.294911] usb 1-1.4: SerialNumber: FFFFFFFFFFFFFFFF
Dec 14 19:36:34 raspberrypi kernel: [ 600.308012] usb-storage 1-1.4:1.0: USB Mass Storage device detected
Dec 14 19:36:34 raspberrypi kernel: [ 600.308221] scsi host15: usb-storage 1-1.4:1.0
Dec 14 19:36:34 raspberrypi mtp-probe: checking bus 1, device 26: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4"
Dec 14 19:36:34 raspberrypi mtp-probe: bus: 1, device: 26 was not an MTP device
Dec 14 19:36:34 raspberrypi systemd[1]: Starting USB_ModeSwitch...
Dec 14 19:36:34 raspberrypi usb_modeswitch: switch device 12d1:15d2 on 001/026
Dec 14 19:36:34 raspberrypi kernel: [ 600.904426] usb 1-1.4: usbfs: interface 0 claimed by usb-storage while 'usb_modeswitch' sets config #2
Dec 14 19:36:34 raspberrypi avahi-daemon[446]: Interface eth0.IPv6 no longer relevant for mDNS.
Dec 14 19:36:34 raspberrypi dhcpcd[727]: eth0: arp if_readrawpacket: Network is down
Dec 14 19:36:34 raspberrypi avahi-daemon[446]: Leaving mDNS multicast group on interface eth0.IPv6 with address fe80::6b65:cf6:a9ae:24e7.
Dec 14 19:36:34 raspberrypi dhcpcd[727]: eth0: carrier lost
Dec 14 19:36:34 raspberrypi avahi-daemon[446]: Interface eth0.IPv4 no longer relevant for mDNS.
Dec 14 19:36:34 raspberrypi avahi-daemon[446]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.2.4.
Dec 14 19:36:34 raspberrypi avahi-daemon[446]: Withdrawing address record for fe80::6b65:cf6:a9ae:24e7 on eth0.
Dec 14 19:36:35 raspberrypi avahi-daemon[446]: Withdrawing address record for 192.168.2.4 on eth0.
Dec 14 19:36:35 raspberrypi avahi-daemon[446]: Withdrawing workstation service for eth0.
Dec 14 19:36:35 raspberrypi kernel: [ 601.023704] usb usb1-port1: disabled by hub (EMI?), re-enabling...
Dec 14 19:36:35 raspberrypi kernel: [ 601.023727] usb 1-1: USB disconnect, device number 23
Dec 14 19:36:35 raspberrypi kernel: [ 601.023734] usb 1-1.1: USB disconnect, device number 24
Dec 14 19:36:35 raspberrypi kernel: [ 601.024117] smsc95xx 1-1.1:1.0 eth0: unregister 'smsc95xx' usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet
Dec 14 19:36:35 raspberrypi kernel: [ 601.024213] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Dec 14 19:36:35 raspberrypi systemd[1]: Stopping ifup for eth0...
Dec 14 19:36:35 raspberrypi kernel: [ 601.094153] usb 1-1.4: USB disconnect, device number 26
Dec 14 19:36:35 raspberrypi dhcpcd[727]: eth0: deleting address fe80::6b65:cf6:a9ae:24e7
Dec 14 19:36:35 raspberrypi dhcpcd[727]: eth0: deleting route to 192.168.2.0/24
Dec 14 19:36:35 raspberrypi dhcpcd[727]: eth0: deleting default route via 192.168.2.1
Dec 14 19:36:35 raspberrypi systemd[1]: Stopped ifup for eth0.
Dec 14 19:36:35 raspberrypi dhcpcd[727]: eth0: removing interface
Dec 14 19:36:36 raspberrypi ntpd[761]: Deleting interface #9 eth0, 192.168.2.4#123, interface stats: received=0, sent=0, dropped=0, active_time=268 secs
Dec 14 19:36:36 raspberrypi ntpd[761]: Deleting interface #8 eth0, fe80::6b65:cf6:a9ae:24e7#123, interface stats: received=0, sent=0, dropped=0, active_time=271 secs
Dec 14 19:36:36 raspberrypi ntpd[761]: peers refreshed
Dec 14 19:36:39 raspberrypi kernel: [ 605.963777] cdc_mbim 1-1.4:2.0: SET_NTB_FORMAT failed
Dec 14 19:36:39 raspberrypi kernel: [ 605.983852] cdc_mbim 1-1.4:2.0: bind() failure
Dec 14 19:36:39 raspberrypi kernel: [ 605.984652] usb-storage 1-1.4:2.2: USB Mass Storage device detected
Dec 14 19:36:39 raspberrypi kernel: [ 605.994481] scsi host16: usb-storage 1-1.4:2.2
Dec 14 19:36:39 raspberrypi systemd[1]: Started USB_ModeSwitch.
Dec 14 19:36:40 raspberrypi kernel: [ 606.153779] Indeed it is in host mode hprt0 = 00001501
Dec 14 19:36:40 raspberrypi kernel: [ 606.333738] usb 1-1: new high-speed USB device number 27 using dwc_otg
Dec 14 19:36:40 raspberrypi kernel: [ 606.333895] Indeed it is in host mode hprt0 = 00001101
Dec 14 19:36:40 raspberrypi kernel: [ 606.533839] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
Dec 14 19:36:40 raspberrypi kernel: [ 606.533850] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Dec 14 19:36:40 raspberrypi kernel: [ 606.534349] hub 1-1:1.0: USB hub found
Dec 14 19:36:40 raspberrypi kernel: [ 606.534404] hub 1-1:1.0: 5 ports detected
Dec 14 19:36:40 raspberrypi kernel: [ 606.813699] usb 1-1.1: new high-speed USB device number 28 using dwc_otg
Dec 14 19:36:40 raspberrypi kernel: [ 606.913857] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
Dec 14 19:36:40 raspberrypi kernel: [ 606.913871] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Dec 14 19:36:40 raspberrypi kernel: [ 606.916431] smsc95xx v1.0.4
Dec 14 19:36:40 raspberrypi kernel: [ 606.975706] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:23:20:00
Dec 14 19:36:40 raspberrypi mtp-probe: checking bus 1, device 28: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1"
Dec 14 19:36:40 raspberrypi mtp-probe: bus: 1, device: 28 was not an MTP device
Dec 14 19:36:41 raspberrypi dhcpcd[727]: eth0: adding address fe80::6b65:cf6:a9ae:24e7
Dec 14 19:36:42 raspberrypi systemd[1]: Starting ifup for eth0...
Dec 14 19:36:42 raspberrypi systemd[1]: Started ifup for eth0.
Dec 14 19:36:42 raspberrypi dhcpcd[727]: eth0: waiting for carrier
Dec 14 19:36:42 raspberrypi kernel: [ 608.154982] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Dec 14 19:36:42 raspberrypi kernel: [ 608.155206] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Dec 14 19:36:42 raspberrypi systemd[1]: Reloading OpenBSD Secure Shell server.
Dec 14 19:36:42 raspberrypi systemd[1]: Reloaded OpenBSD Secure Shell server.
Dec 14 19:36:43 raspberrypi dhcpcd[727]: eth0: carrier acquired
Dec 14 19:36:43 raspberrypi kernel: [ 609.861674] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Dec 14 19:36:43 raspberrypi kernel: [ 609.862378] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
Dec 14 19:36:43 raspberrypi dhcpcd[727]: eth0: IAID eb:23:20:00
Dec 14 19:36:44 raspberrypi dhcpcd[727]: eth0: soliciting an IPv6 router
Dec 14 19:36:44 raspberrypi dhcpcd[727]: eth0: rebinding lease of 192.168.2.4
Dec 14 19:36:44 raspberrypi kernel: [ 610.813729] usb 1-1.4: new high-speed USB device number 29 using dwc_otg
Dec 14 19:36:44 raspberrypi avahi-daemon[446]: Joining mDNS multicast group on interface eth0.IPv6 with address fe80::6b65:cf6:a9ae:24e7.
Dec 14 19:36:44 raspberrypi avahi-daemon[446]: New relevant interface eth0.IPv6 for mDNS.
Dec 14 19:36:44 raspberrypi avahi-daemon[446]: Registering new address record for fe80::6b65:cf6:a9ae:24e7 on eth0.*.
Dec 14 19:36:44 raspberrypi kernel: [ 610.915472] usb 1-1.4: New USB device found, idVendor=12d1, idProduct=15d2
That wasn’t all though. The kernel also kept mentioning that it detected a USB hub coming up, and it shutting down because of EMI (which I’m guessing stands for electromagnetic interference)? I’m not the only one coming across this problem, as shown by this Stack Overflow question (which sadly doesn’t have an answer).
Dec 14 19:36:35 raspberrypi kernel: [ 601.023704] usb usb1-port1: disabled by hub (EMI?), re-enabling...
Dec 14 19:36:35 raspberrypi kernel: [ 601.023727] usb 1-1: USB disconnect, device number 23
Dec 14 19:36:35 raspberrypi kernel: [ 601.023734] usb 1-1.1: USB disconnect, device number 24
Dec 14 19:36:35 raspberrypi kernel: [ 601.024117] smsc95xx 1-1.1:1.0 eth0: unregister 'smsc95xx' usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet
Dec 14 19:36:35 raspberrypi kernel: [ 601.024213] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
Dec 14 19:36:35 raspberrypi systemd[1]: Stopping ifup for eth0...
Dec 14 19:36:35 raspberrypi kernel: [ 601.094153] usb 1-1.4: USB disconnect, device number 26
Dec 14 19:36:40 raspberrypi kernel: [ 606.534349] hub 1-1:1.0: USB hub found
Dec 14 19:36:40 raspberrypi kernel: [ 606.534404] hub 1-1:1.0: 5 ports detected
Alrighty then. That would probably explain the network-interface-loop. The 3G stick gets connected, the hub goes down, it comes back up, the Pi detects the stick, then the hub goes down again, repeat ad infinitum.
Intermezzo: USB internet sticks and Linux
At this point it is probably best to clarify what exactly the deal is with USB internet sticks and Linux. A bit over a decade ago, as these sticks started picking up speed, manufacturers implemented a pretty elegant system: when the stick would be plugged in, it would first boot into a Mass Media Storage mode/partition, which contained the driver. From there on it would install the driver, and then swtich to its ‘modem’ mode. Of course, as we saw above, this works flawlessly under Windows, but not so much under Linux distros. Of course, the Linux community being what it is, it didn’t take long for a brilliant developer somewhere to come up with a tool, in this instance called usb-modeswitch. As its name implies, this nifty little tool allows you to force the 3G stick into modem mode when it initially comes up in Mass Media Storage mode.
Stabilizing the Pi
I’m not entirely new to Linux/Debian stuff, but to say I know what I’m doing would be an overstatement. While trying to figure out what on earth was going on with the Pi, I discovered that if I issued the usb-modeswitch command at just the right time (read: slam up-enter multiple times a second), there would be a brief window in which usb-modeswitch actually managed to switch the mode of the stick to modem. From there on, the whole thing stabilised, and I could SSH back in over Ethernet. The command looks like this:
usb_modeswitch -v 12d1 -p 15d2 -V 12d1 -P 1506 -M "55534243123456780000000000000011062000000100000000000000000000"
I have to admit I came across it with some luck: googling around for the specific E3531 commands I came on the usb-modeswitch wiki, where this was posted. The -v flag and the -p flag are specific to the stick you have. I found that the -p value tends to change, despite the stick (Huawei 3531) being the same. I figured out what values I should slap in there by just tailing the syslog, grepping for usb, and seeing what it spits out when I connect the stick:
Dec 20 19:43:02 raspberrypi kernel: [ 2.580488] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
The payload -M is apparently the same for all Huawei modems (or so I read on the usb-modeswitch wiki).
Treating the ‘EMI’ symptom
It would not be realistic that the Pi would require a shell session every time it boots, just so someone could spam the usb-modeswitch command to get the network interfaces to stabilise. Instead, I needed to have a way to instantly issue the command as soon as the stick was detected, before any of the instability occurred. Of course, udev to the rescue. I remembered had used udev before in another project, where I needed to shutdown a Pi by unplugging a specific USB device. Here, I would just add a rule to /etc/udev/rules.d with the highest priority that would issue the command right away. Here’s the rule I added:
ATTR{idVendor}=="12d1", ATTR{idProduct}=="15d2", TAG+="systemd", ENV{SYSTEMD_WANTS}="modem-attachment.service"
After a udev reload, I tested by unplugging and re-plugging the stick. Sure enough, the USB nicely booted up, left my Ethernet connection alone, and was ready for the next step: using it as a modem. That was another interesting journey, see my blogpost here for more details on that. You’ll notice that the udev rule calls a service. This is also detailed in the next blog post.