After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 732932 - Sierra 308 makes ModemManager Crash
Sierra 308 makes ModemManager Crash
Status: RESOLVED WONTFIX
Product: NetworkManager
Classification: Platform
Component: ModemManager
unspecified
Other Linux
: Normal normal
: ---
Assigned To: NetworkManager maintainer(s)
NetworkManager maintainer(s)
Depends on:
Blocks:
 
 
Reported: 2014-07-09 00:59 UTC by rn0163
Modified: 2014-07-13 11:05 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Crash report & log (305.28 KB, application/zip)
2014-07-09 11:52 UTC, rn0163
Details
ModemManager Logs (16.37 KB, application/zip)
2014-07-11 02:42 UTC, rn0163
Details
Updated log (14.90 KB, application/zip)
2014-07-11 12:17 UTC, rn0163
Details
Log After Using Minicom (16.11 KB, application/zip)
2014-07-11 16:30 UTC, rn0163
Details

Description rn0163 2014-07-09 00:59:35 UTC
When trying to connect to Internet using Sierra 308 USB modem, ModemManager always crashes. 

lsusb output:
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 14.04 LTS
Release: 14.04
Codename: trusty
Linux reinaldo-home 3.13.0-24-generic #46-Ubuntu SMP Thu Apr 10 19:11:08 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

Bus 002 Device 006: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 004: ID 046d:c31c Logitech, Inc. Keyboard K120 for Business
Bus 001 Device 003: ID 046d:c52f Logitech, Inc. Unifying Receiver
Bus 001 Device 008: ID 0f3d:68a3 Airprime, Incorporated
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

Log:
Jul 3 22:27:25 reinaldo-home ModemManager[4142]: <info> ModemManager (version 1.0.0) starting...
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <info> NetworkManager state is now CONNECTED_GLOBAL
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <warn> (ttyUSB2) failed to connect modem: Message did not receive a reply (timeout by message bus)
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: nm_device_get_state: assertion 'NM_IS_DEVICE (device)' failed
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: modem_prepare_result: assertion 'state == NM_DEVICE_STATE_PREPARE' failed
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <info> ModemManager disappeared from bus
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <warn> (ttyUSB2) failed to disconnect modem: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name :1.113 was not provided by any .service files
Jul 3 22:27:23 reinaldo-home whoopsie[1055]: message repeated 4 times: [ offline]
Jul 3 22:27:25 reinaldo-home whoopsie[1055]: Could not determine if this is a default route:
Jul 3 22:27:25 reinaldo-home whoopsie[1055]: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: Method "Get" with signature "ss" on interface "org.freedesktop.DBus.Properties" doesn't exist#012
Jul 3 22:27:25 reinaldo-home whoopsie[1055]: Could not determine if this is a default route:
Jul 3 22:27:25 reinaldo-home whoopsie[1055]: GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: Method "Get" with signature "ss" on interface "org.freedesktop.DBus.Properties" doesn't exist#012
Jul 3 22:27:25 reinaldo-home whoopsie[1055]: offline
Jul 3 22:27:25 reinaldo-home NetworkManager[725]: <info> ModemManager available in the bus
Jul 3 22:27:27 reinaldo-home ModemManager[4142]: <warn> Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.4/0000:02:00.0': not supported by any plugin
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.626433] usb 2-1.5: new high-speed USB device number 14 using ehci-pci
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.720098] usb 2-1.5: config 1 has an invalid interface number: 9 but max is 5
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.720104] usb 2-1.5: config 1 has an invalid interface number: 7 but max is 5
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.720107] usb 2-1.5: config 1 has no interface number 2
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.720109] usb 2-1.5: config 1 has no interface number 5
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.721596] usb 2-1.5: New USB device found, idVendor=0f3d, idProduct=68a3
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.721600] usb 2-1.5: New USB device strings: Mfr=3, Product=2, SerialNumber=4
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.721603] usb 2-1.5: Product: USB 308
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.721606] usb 2-1.5: Manufacturer: Sierra Wireless, Incorporated
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.721608] usb 2-1.5: SerialNumber: 353354046068858
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.725157] sierra 2-1.5:1.0: Sierra USB modem converter detected
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.726746] usb 2-1.5: Sierra USB modem converter now attached to ttyUSB0
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.726828] sierra 2-1.5:1.1: Sierra USB modem converter detected
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.727244] usb 2-1.5: Sierra USB modem converter now attached to ttyUSB1
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.727324] sierra 2-1.5:1.3: Sierra USB modem converter detected
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.727696] usb 2-1.5: Sierra USB modem converter now attached to ttyUSB2
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.727772] sierra 2-1.5:1.4: Sierra USB modem converter detected
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.728190] usb 2-1.5: Sierra USB modem converter now attached to ttyUSB3
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.728266] usb-storage 2-1.5:1.9: USB Mass Storage device detected
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.728482] scsi16 : usb-storage 2-1.5:1.9
Jul 3 22:27:30 reinaldo-home kernel: [ 9593.730138] sierra_net 2-1.5:1.7 wwan0: register 'sierra_net' at usb-0000:00:1d.0-1.5, Sierra Wireless USB-to-WWAN Modem, 46:e0:69:42:09:07
Jul 3 22:27:30 reinaldo-home mtp-probe: checking bus 2, device 14: "/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.5"
Jul 3 22:27:30 reinaldo-home mtp-probe: bus: 2, device: 14 was not an MTP device
Jul 3 22:27:30 reinaldo-home ModemManager[4142]: <warn> (ttyUSB0): port attributes not fully set
Jul 3 22:27:30 reinaldo-home NetworkManager[725]: SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.5/2-1.5:1.7/net/wwan0, iface: wwan0)
Jul 3 22:27:30 reinaldo-home NetworkManager[725]: SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.5/2-1.5:1.7/net/wwan0, iface: wwan0): no ifupdown configuration found.
Jul 3 22:27:30 reinaldo-home ModemManager[4142]: <warn> (ttyUSB1): port attributes not fully set
Jul 3 22:27:30 reinaldo-home ModemManager[4142]: <warn> (ttyUSB2): port attributes not fully set
Jul 3 22:27:30 reinaldo-home ModemManager[4142]: <warn> (ttyUSB3): port attributes not fully set
Jul 3 22:27:31 reinaldo-home kernel: [ 9594.728369] scsi 16:0:0:0: Direct-Access SWI SD Card 2.31 PQ: 0 ANSI: 2
Jul 3 22:27:31 reinaldo-home kernel: [ 9594.728720] sd 16:0:0:0: Attached scsi generic sg2 type 0
Jul 3 22:27:31 reinaldo-home kernel: [ 9594.730950] sd 16:0:0:0: [sdb] Attached SCSI removable disk
Jul 3 22:27:41 reinaldo-home ModemManager[4142]: <info> Creating modem with plugin 'Sierra' and '5' ports
Jul 3 22:27:41 reinaldo-home ModemManager[4142]: <warn> Could not grab port (tty/ttyUSB0): 'Cannot add port 'tty/ttyUSB0', unhandled serial type'
Jul 3 22:27:41 reinaldo-home ModemManager[4142]: <warn> (ttyUSB2): port attributes not fully set
Jul 3 22:27:41 reinaldo-home ModemManager[4142]: <info> Modem for device at '/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.5' successfully created
Jul 3 22:27:42 reinaldo-home ModemManager[4142]: <warn> Couldn't load unlock retries: 'Unknown error'
Jul 3 22:27:49 reinaldo-home ModemManager[4142]: <warn> couldn't load Operator identifier: 'SIM failed to handle CRSM request (sw1 103 sw2 0)'
Jul 3 22:27:50 reinaldo-home ModemManager[4142]: <warn> couldn't load list of Own Numbers: 'Failed to parse NV MDN command result: -17'
Jul 3 22:27:53 reinaldo-home ModemManager[4142]: <info> Modem: state changed (unknown -> disabled)
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <warn> (ttyUSB2): failed to look up interface index
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> WWAN now disabled by management service
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): new Broadband device (driver: 'sierra, sierra_net' ifindex: 0)
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): exported as /org/freedesktop/NetworkManager/Devices/10
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): deactivating device (reason 'managed') [2]
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> NetworkManager state is now DISCONNECTED
Jul 3 22:27:53 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
Jul 3 22:27:56 reinaldo-home AptDaemon: INFO: Quitting due to inactivity
Jul 3 22:27:56 reinaldo-home AptDaemon: INFO: Quitting was requested
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> disable requested (sleeping: no enabled: yes)
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> sleeping or disabling...
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> (eth0): device state change: unavailable -> unmanaged (reason 'sleeping') [20 10 37]
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> (eth0): cleaning up...
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> (eth0): taking down device.
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> NetworkManager state is now ASLEEP
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): device state change: disconnected -> unmanaged (reason 'sleeping') [30 10 37]
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): cleaning up...
Jul 3 22:28:01 reinaldo-home NetworkManager[725]: <info> (ttyUSB2): taking down device.
Comment 1 Aleksander Morgado 2014-07-09 08:23:01 UTC
(In reply to comment #0)
> When trying to connect to Internet using Sierra 308 USB modem, ModemManager
> always crashes. 
> 

Yet I see no crash in the logs :)

Can you grab debug logs of ModemManager/NetworkManager following these steps?
http://www.freedesktop.org/wiki/Software/ModemManager/Debugging/


Also, worth trying with a newer ModemManager if possible (1.2 or better, git master); as 1.0 is 1 year old.
Comment 2 rn0163 2014-07-09 11:52:20 UTC
Created attachment 280249 [details]
Crash report & log
Comment 3 rn0163 2014-07-09 11:53:46 UTC
When I tried to connect to Internet, the mobile connection was disconnected immediately and I saw a crash report dialog after that. Here I also attach the crash report file. I hope it could be useful for explaining this issue.

Anyway, I have upgraded to ModemManager 1.2 and still got the same result. As I use Ubuntu, I followed the debugging procedure in Ubuntu Wiki page (https://wiki.ubuntu.com/DebuggingModemmanager). Log file is also attached.

Output of "sudo mmcli -L":
Found 1 modems:
	/org/freedesktop/ModemManager1/Modem/0 [Sierra Wireless, Incorporated] USB 308


Output of "sudo mmcli -m 0":
/org/freedesktop/ModemManager1/Modem/0 (device id '2fb10174a4752a6d23f6aa05d65b931df177f46a')
  -------------------------
  Hardware |   manufacturer: 'Sierra Wireless, Incorporated'
           |          model: 'USB 308'
           |       revision: 'M3_0_10_13AP C:/WS/M3_0_10_13AP/MDM8200/SRC/AMSS 2010/09/24 18:44:04'
           |      supported: 'gsm-umts'
           |        current: 'gsm-umts'
           |   equipment id: '353354046068858'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.3'
           |        drivers: 'sierra, sierra_net'
           |         plugin: 'Sierra'
           |   primary port: 'ttyUSB2'
           |          ports: 'ttyUSB1 (qcdm), ttyUSB2 (at), ttyUSB3 (at), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'none'
           | unlock retries: 'unknown'
           |          state: 'disabled'
           |    power state: 'on'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: 'allowed: 2g; preferred: none
           |                  allowed: 3g; preferred: none
           |                  allowed: 2g, 3g; preferred: none
           |                  allowed: 2g, 3g; preferred: 2g
           |                  allowed: 2g, 3g; preferred: 3g'
           |        current: 'allowed: 2g, 3g; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4'
  -------------------------
  3GPP     |           imei: '353354046068858'
           |  enabled locks: 'none'
           |    operator id: 'unknown'
           |  operator name: 'unknown'
           |   subscription: 'unknown'
           |   registration: 'unknown'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

  -------------------------
  Bearers  |          paths: 'none'
Comment 4 Aleksander Morgado 2014-07-10 18:04:56 UTC
Those debug steps are for Ubuntu < 14.04 (i.e. not for ModemManager 1.x) so you didn't really end up getting the ModemManager debug logs.

Can you retry to get the debug logs following the "when not using systemd" steps in http://www.freedesktop.org/wiki/Software/ModemManager/Debugging/?
Comment 5 rn0163 2014-07-11 02:42:36 UTC
Created attachment 280462 [details]
ModemManager Logs
Comment 6 rn0163 2014-07-11 02:51:54 UTC
Sorry, I'm a casual user and not quite skilled in doing things like this. Here I attach the log files again.
Comment 7 Aleksander Morgado 2014-07-11 07:58:05 UTC
(In reply to comment #6)
> Sorry, I'm a casual user and not quite skilled in doing things like this. Here
> I attach the log files again.

No problem, we're here to help :)


So, the modem ends up being handled with 4 usable interfaces, of which 2 are AT ports:
 tty/ttyUSB2 at (primary)
 tty/ttyUSB3 at (secondary)
 net/wwan0 data (primary)
 tty/ttyUSB1 qcdm

Your problem is that when we are listing the SMS messages, the modem crashes and removes the 2 usable AT ports:
 (ttyUSB1) unexpected port hangup!
 (ttyUSB2) unexpected port hangup!
 released by modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.3
 released by modem /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.3

So the modem ends up being left with 2 interfaces (net and qcdm) which are not usable for modem control. ModemManager should detect that and fully remove the modem in that case, as the control AT interfaces are both gone. But it doesn't do that and ends up crashing afterwards.

Now, your real problem here is that you need to avoid the modem crashing when listing the SMS messages. If that is not avoided, it will always crash. I'm going to assume that you don't mind the SMS messages to be removed, so the way to do this would be to:

1) Stop ModemManager and make sure it doesn't start. In Ubuntu, you can do this by moving the binary to another location, like:
 $ sudo mv /usr/sbin/ModemManager /ModemManager
 $ sudo killall -9 ModemManager

2) Install and run minicom in one of the ttys:
 $ sudo apt-get install minicom
 $ sudo minicom -D /dev/ttyUSB2

3) Run the following AT command inside minicom:
 AT+CMGL=1,4

4) Exit minicom:
 Ctrl-A  Z  X

5) Recover ModemManager in the correct place and restart it:
 $ sudo mv /ModemManager /usr/sbin/ModemManager
 $ /usr/sbin/ModemManager --debug

And then, see if it crashes again.
Comment 8 rn0163 2014-07-11 12:15:51 UTC
Thanks for your kind reply. I have installed minicom and executed that command but ModemManager crashed again. I still saw "unexpected port hangup!" message in the log file (attached).
Comment 9 rn0163 2014-07-11 12:17:01 UTC
Created attachment 280501 [details]
Updated log
Comment 10 Aleksander Morgado 2014-07-11 13:56:32 UTC
Gah, how stupid I am.

The command you have to run inside minicom to remove all SMS messages is this one:
 AT+CMGD=1,4

Once the previous command is run, try to execute:
 AT+CMGL=4
And see if it replies an empty response (i.e. no SMS listed).
Comment 11 rn0163 2014-07-11 16:28:14 UTC
I ran those commands and received 'OK' as responses. However, the "unexpected port hangup!" message still appears in the log after restarting ModemManager.
Comment 12 rn0163 2014-07-11 16:30:20 UTC
Created attachment 280521 [details]
Log After Using Minicom
Comment 13 Aleksander Morgado 2014-07-12 08:37:22 UTC
Did the last AT+CMGL=4 you run at minicom show any content in addition to just "OK"? Looking at the logs, it seems no SMS messages were removed from the device.

Can you retry but with the following sequence?
 AT+CPMS="ME"
 AT+CMGD=1,4
 AT+CMGL=4

And can you paste back the answers you got in each of those steps?
Comment 14 rn0163 2014-07-12 10:52:09 UTC
When I ran AT+CMGL=4, I only received "OK" as response. Here are the output of all commands:
AT+CPMS="ME" 
+CPMS: 255,255,0,50,0,0 

OK 
AT+CMGD=1,4 
OK 
AT+CMGL=4 
OK 

After running those commands, the USB modem could connect to Internet normally. Thank you very much! I have struggled with this issue for almost 2 weeks and I'm extremely grateful for your help.
Comment 15 Aleksander Morgado 2014-07-13 11:05:02 UTC
(In reply to comment #14)
> When I ran AT+CMGL=4, I only received "OK" as response. Here are the output of
> all commands:
> AT+CPMS="ME" 
> +CPMS: 255,255,0,50,0,0 
> 
> OK 
> AT+CMGD=1,4 
> OK 
> AT+CMGL=4 
> OK 
> 
> After running those commands, the USB modem could connect to Internet normally.
> Thank you very much! I have struggled with this issue for almost 2 weeks and
> I'm extremely grateful for your help.

Glad it worked :)

Unfortunately there is no clear way to automagically handle this in ModemManager, as it involves removing all SMS messages, so just keep in mind which were the steps to get the modem back.

I'm going to set the resolution state to wontfix as this is not something that we can fix in MM.