Modem suddenly disconnecting?

Mon Dec 9 07:28:29 PST 2013

Hi Aleksander,

No, I cannot update modemmanager to a newer version for now. My system is restricted with what packages I can load/install.

What I can see here from the logs, it looks like after NetworkManager has enabled WWAN support, the driver does a reset and then reports "firmware changed". See below. Anyone ever seen this? 

Unfortunately I cannot get any debugging from modemmanager, because when I kill the process as explained in your Wiki, then automatically a new process modemmanger is started without me being able to start it manually with --debugging enabled.

Thanks for any further advice.

Karoline

Dec 09 16:18:13 [modem-manager] (ttyUSB1) opening serial device...
Dec 09 16:18:13 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: unlock no longer required
Dec 09 16:18:13 [modem-manager] (ttyUSB1) closing serial device...
Dec 09 16:18:13 [modem-manager] (ttyUSB1) opening serial device...
Dec 09 16:18:13 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
Dec 09 16:18:13 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
Dec 09 16:18:13 [NetworkManager] <info> WWAN now enabled by management service
Dec 09 16:18:17 [kernel] [  351.895517] usb 1-1.2: reset high-speed USB device number 4 using ehci_hcd
Dec 09 16:18:17 [kernel] [  351.981628] usb 1-1.2: device firmware changed
Dec 09 16:18:17 [modem-manager] (ttyUSB1) closing serial device...
Dec 09 16:18:17 [kernel] [  351.982068] usb 1-1.2: USB disconnect, device number 4
Dec 09 16:18:17 [kernel] [  351.982279] qcserial ttyUSB0: Qualcomm USB modem converter now disconnected from ttyUSB0
Dec 09 16:18:17 [kernel] [  351.982310] qcserial 1-1.2:1.1: device disconnected
Dec 09 16:18:17 [kernel] [  351.982494] qcserial ttyUSB1: Qualcomm USB modem converter now disconnected from ttyUSB1
Dec 09 16:18:17 [kernel] [  351.982513] qcserial 1-1.2:1.2: device disconnected
Dec 09 16:18:17 [modem-manager] Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> disabled)
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): now unmanaged
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): device state change: 3 -> 1 (reason 36)
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): cleaning up...
Dec 09 16:18:17 [NetworkManager] <info> (ttyUSB1): taking down device.

Aleksander Morgado <aleksander at lanedo.com> schrieb am 12:41 Montag, 9.Dezember 2013:

Hey Karoline,

> Hi I'm using modemmanager-0.4 and I've got a problem trying to use my
> integrated HP broadband modem.
> 
> Here the logs and a description of the problem:
> 
> ModemManager and NetworkManager detect my modem OK.
> 
> Dec 06 10:43:09 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:43:09 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:43:12 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:43:12 [NetworkManager] <warn> (ttyUSB1): failed to look up
> interface index
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): new GSM device
> (driver: 'qcserial' ifindex: -1)
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): exported as
> /org/freedesktop/NetworkManager/Devices/2
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): now managed
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): device state change:
> 1 -> 2 (reason 2)
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): deactivating device
> (reason: 2).
> Dec 06 10:43:12 [NetworkManager] <info> (ttyUSB1): device state change:
> 2 -> 3 (reason 0)
> Dec 06 10:43:54 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:43:54 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: unlock no longer required
> Dec 06 10:43:54 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:43:54 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:43:54 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
> Dec 06 10:43:54 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
> Dec 06 10:43:54 [NetworkManager] <info> WWAN now enabled by management
> service
> 
> At this point I have programmatically enabled and unlocked the modem by
> sending sendPin() and enable() to the modem via DBUS.
> But then, suddenly I get a disconnect from the USB modem. I don't
> understand why this happens, and I don't do anything programmatically
> here other than requesting modem information (manufacturer, network
> registration).
> 
> Dec 06 10:43:58 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:43:58 [kernel] [   90.892492] usb 1-1.2: USB disconnect,
> device number 4
> Dec 06 10:43:58 [kernel] [   90.892658] qcserial ttyUSB0: Qualcomm USB
> modem converter now disconnected from ttyUSB0
> Dec 06 10:43:58 [kernel] [   90.892676] qcserial 1-1.2:1.1: device
> disconnected
> Dec 06 10:43:58 [kernel] [   90.892807] qcserial ttyUSB1: Qualcomm USB
> modem converter now disconnected from ttyUSB1
> Dec 06 10:43:58 [kernel] [   90.892819] qcserial 1-1.2:1.2: device
> disconnected
> Dec 06 10:43:58 [modem-manager] Modem
> /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> disabled)
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): now unmanaged
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): device state change:
> 3 -> 1 (reason 36)
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): cleaning up...
> Dec 06 10:43:58 [NetworkManager] <info> (ttyUSB1): taking down device.
> 
> At this point the modem is down and disappeared from ModemManager.
> Then it shows up again as a new USB device.
> 
> Dec 06 10:43:59 [kernel] [   91.323911] usb 1-1.2: new high-speed USB
> device number 8 using ehci_hcd
> Dec 06 10:43:59 [kernel] [   91.412677] usb 1-1.2: config 1 has an
> invalid interface number: 1 but max is 0
> Dec 06 10:43:59 [kernel] [   91.412683] usb 1-1.2: config 1 has no
> interface number 0
> Dec 06 10:43:59 [kernel] [   91.414620] usb 1-1.2: New USB device found,
> idVendor=03f0, idProduct=241d
> Dec 06 10:43:59 [kernel] [   91.414626] usb 1-1.2: New USB device
> strings: Mfr=3, Product=2, SerialNumber=0
> Dec 06 10:43:59 [kernel] [   91.414630] usb 1-1.2: Product: HP un2420
> Mobile Broadband Module
> Dec 06 10:43:59 [kernel] [   91.414634] usb 1-1.2: Manufacturer:
> Qualcomm Incorporated
> Dec 06 10:43:59 [kernel] [   91.416325] qcserial 1-1.2:1.1: Qualcomm USB
> modem converter detected
> Dec 06 10:43:59 [kernel] [   91.416443] usb 1-1.2: Qualcomm USB modem
> converter now attached to ttyUSB0
> Dec 06 10:44:00 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:44:04 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:44:04 [kernel] [   96.254729] usb 1-1.2: USB disconnect,
> device number 8
> Dec 06 10:44:04 [kernel] [   96.254856] qcserial ttyUSB0: Qualcomm USB
> modem converter now disconnected from ttyUSB0
> Dec 06 10:44:04 [kernel] [   96.254873] qcserial 1-1.2:1.1: device
> disconnected
> Dec 06 10:44:04 [modem-manager] mm_serial_port_close: assertion
> `priv->open_count > 0' failed
> Dec 06 10:44:04 [kernel] [   96.431980] usb 1-1.2: new high-speed USB
> device number 9 using ehci_hcd
> Dec 06 10:44:04 [kernel] [   96.529939] usb 1-1.2: New USB device found,
> idVendor=03f0, idProduct=251d
> Dec 06 10:44:04 [kernel] [   96.529945] usb 1-1.2: New USB device
> strings: Mfr=4, Product=3, SerialNumber=0
> Dec 06 10:44:04 [kernel] [   96.529949] usb 1-1.2: Product: HP un2420
> Mobile Broadband Module
> Dec 06 10:44:04 [kernel] [   96.529953] usb 1-1.2: Manufacturer:
> Qualcomm Incorporated
> Dec 06 10:44:04 [kernel] [   96.534212] qcserial 1-1.2:1.1: Qualcomm USB
> modem converter detected
> Dec 06 10:44:04 [kernel] [   96.534294] usb 1-1.2: Qualcomm USB modem
> converter now attached to ttyUSB0
> Dec 06 10:44:04 [kernel] [   96.535342] qcserial 1-1.2:1.2: Qualcomm USB
> modem converter detected
> Dec 06 10:44:04 [kernel] [   96.535419] usb 1-1.2: Qualcomm USB modem
> converter now attached to ttyUSB1
> 
> Here ModemManager then detects a new device (the same modem!!) and
> registeres as a new modem device under a different DBUS path than
> previously (even though still the same device).
> 
> Dec 06 10:44:04 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:44:04 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:44:08 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:44:08 [modem-manager] (ttyUSB1) opening serial device...
> Dec 06 10:44:08 [modem-manager] (Gobi): GSM modem
> /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 claimed port ttyUSB1
> Dec 06 10:44:08 [modem-manager] (ttyUSB1) closing serial device...
> Dec 06 10:44:17 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:44:17 [modem-manager] (ttyUSB0) opening serial device...
> Dec 06 10:44:20 [modem-manager] (ttyUSB0) closing serial device...
> Dec 06 10:44:20 [NetworkManager] <warn> (ttyUSB1): failed to look up
> interface index
> Dec 06 10:44:20 [NetworkManager] <info> WWAN now disabled by management
> service
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): new GSM device
> (driver: 'qcserial' ifindex: -1)
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): exported as
> /org/freedesktop/NetworkManager/Devices/3
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): now managed
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): device state change:
> 1 -> 2 (reason 2)
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): deactivating device
> (reason: 2).
> Dec 06 10:44:20 [NetworkManager] <info> (ttyUSB1): device state change:
> 2 -> 3 (reason 0)
> 
> Anyone got any idea why this happens and how I can further debug the
> problem?
> 

0.4 is a really really old version. Aren't you able to upgrade it to
something newer, like 0.6.x at least? Of course 1.0.x with libqmi
support would be much better anyway, as I see it's a Gobi device.

Anyway, there's little we can do without debug logs from ModemManager.
You can probably follow the instructions here, but I'm not sure whether
they apply to MM 0.4:

https://wiki.gnome.org/Projects/NetworkManager/Debugging

If you're really into trying MM 1.0, use these ones:

http://www.freedesktop.org/wiki/Software/ModemManager/Debugging/

-- 
Aleksander

_______________________________________________
ModemManager-devel mailing list
ModemManager-devel at lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/modemmanager-devel/attachments/20131209/e375c71e/attachment-0001.html>