NM 0.9 with Sierra USB 305 modem connection problems

[Arief M Utama <arief utama gmail com>]

Hi all,


I'm using Debian's NM 0.9 with MM 0.5 (from experimental repo),
with Sierra Wireless modem USB 305 (USB id: 1199:68a3) mobile broadband 
connection does not work.

Actually since 0.8 it never really worked well, but on 0.8.4 release it 
was bit better, at least sometimes it managed to connect.

Connecting with ppp chatscripts always worked flawlessly though so we 
can be sure it's not an issue with the modem hardware.

Attached is a copy of syslog of a latest session.

I'll be happy to help with more debugging.

Thank you for helps and pointers.


All the best.
-arief


Aug 26 02:44:11 mawar NetworkManager[1396]:    SCPlugin-Ifupdown: devices added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.7/net/wwan0, iface: wwan0)
Aug 26 02:44:11 mawar NetworkManager[1396]:    SCPlugin-Ifupdown: device added (path: /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1/2-1:1.7/net/wwan0, iface: wwan0): no ifupdown configuration found.
Aug 26 02:44:11 mawar modem-manager[1420]: <info>  (ttyUSB0) opening serial port...
Aug 26 02:44:11 mawar modem-manager[1420]: <info>  (ttyUSB3) opening serial port...
Aug 26 02:44:11 mawar modem-manager[1420]: <info>  (ttyUSB2) opening serial port...
Aug 26 02:44:11 mawar modem-manager[1420]: <info>  (ttyUSB1) opening serial port...
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB0) closing serial port...
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB0) serial port closed
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB0) opening serial port...
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (Sierra): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1 claimed port ttyUSB0
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB2) closing serial port...
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB2) serial port closed
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (Sierra): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1 claimed port ttyUSB2
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB0) closing serial port...
Aug 26 02:44:13 mawar modem-manager[1420]: <info>  (ttyUSB0) serial port closed
Aug 26 02:44:14 mawar modem-manager[1420]: <info>  (Sierra): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb2/2-1 claimed port wwan0
Aug 26 02:44:19 mawar modem-manager[1420]: <info>  (ttyUSB3) closing serial port...
Aug 26 02:44:19 mawar modem-manager[1420]: <info>  (ttyUSB3) serial port closed
Aug 26 02:44:24 mawar modem-manager[1420]: <info>  (ttyUSB1) closing serial port...
Aug 26 02:44:24 mawar modem-manager[1420]: <info>  (ttyUSB1) serial port closed
Aug 26 02:44:24 mawar modem-manager[1420]: <info>  (ttyUSB1) opening serial port...
Aug 26 02:44:30 mawar modem-manager[1420]: <info>  (ttyUSB1) closing serial port...
Aug 26 02:44:30 mawar modem-manager[1420]: <info>  (ttyUSB1) serial port closed
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> WWAN now disabled by management service
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> (wwan0): new GSM/UMTS device (driver: 'sierra' ifindex: 6)
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> (wwan0): exported as /org/freedesktop/NetworkManager/Devices/3
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> (wwan0): now managed
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> (wwan0): device state change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> (wwan0): deactivating device (reason: 2).
Aug 26 02:44:30 mawar NetworkManager[1396]: <info> (wwan0): device state change: unavailable -> disconnected (reason 'none') [20 30 0]
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) starting connection 'Telkomsel Flash'
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> (wwan0): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) Stage 1 of 5 (Device Prepare) started...
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> (wwan0): device state change: prepare -> need-auth (reason 'none') [40 60 0]
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) Stage 1 of 5 (Device Prepare) complete.
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) Stage 1 of 5 (Device Prepare) started...
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> (wwan0): device state change: need-auth -> prepare (reason 'none') [60 40 0]
Aug 26 02:44:34 mawar NetworkManager[1396]: <info> Activation (wwan0) Stage 1 of 5 (Device Prepare) complete.
Aug 26 02:44:34 mawar modem-manager[1420]: <info>  (ttyUSB0) opening serial port...
Aug 26 02:44:34 mawar modem-manager[1420]: <info>  Modem /org/freedesktop/ModemManager/Modems/1: state changed (disabled -> enabling)
Aug 26 02:44:45 mawar modem-manager[1420]: <info>  (ttyUSB2) opening serial port...
Aug 26 02:44:45 mawar modem-manager[1420]: Invalid error code: 518
Aug 26 02:44:45 mawar modem-manager[1420]: <info>  Modem /org/freedesktop/ModemManager/Modems/1: state changed (enabling -> enabled)
Aug 26 02:44:45 mawar NetworkManager[1396]: <info> WWAN now enabled by management service
Aug 26 02:44:45 mawar modem-manager[1420]: <info>  Modem /org/freedesktop/ModemManager/Modems/1: state changed (enabled -> registered)
Aug 26 02:44:45 mawar modem-manager[1420]: <info>  Modem /org/freedesktop/ModemManager/Modems/1: state changed (registered -> connecting)
Aug 26 02:44:45 mawar NetworkManager[1396]: <warn> GSM connection failed: (32) Unknown error
Aug 26 02:44:45 mawar NetworkManager[1396]: <info> (wwan0): device state change: prepare -> failed (reason 'unknown') [40 120 1]
Aug 26 02:44:45 mawar NetworkManager[1396]: <info> Marking connection 'Telkomsel Flash' invalid.
Aug 26 02:44:45 mawar NetworkManager[1396]: <warn> Activation (wwan0) failed.
Aug 26 02:44:45 mawar NetworkManager[1396]: <info> (wwan0): device state change: failed -> disconnected (reason 'none') [120 30 0]
Aug 26 02:44:45 mawar NetworkManager[1396]: <info> (wwan0): deactivating device (reason: 0).
Aug 26 02:44:45 mawar modem-manager[1420]: <info>  Modem /org/freedesktop/ModemManager/Modems/1: state changed (connecting -> disconnecting)
Aug 26 02:44:46 mawar modem-manager[1420]: <info>  Modem /org/freedesktop/ModemManager/Modems/1: state changed (disconnecting -> registered)