Cannot find Huawei modem (open port) after restart if connection wasn't manually dropped - regression since Natty

[Deejay_TNT]

Ubuntu 11.10 Oneiric
uname -a: Linux home 3.0.0-12-generic #20-Ubuntu SMP Fri Oct 7 14:50:42 UTC 2011 i686 i686 i386 GNU/Linux
network-manager: 0.9.1.90-0ubuntu3
modemmanager: 0.5-1ubuntu1
--------------------------

If I connect to a 3G network, keep the connection open (stay connected), and either restart a computer or stop-start network-manager, the modem (Huawei E173) will not be "detected" anymore (cannot open port). Worked fine in Natty.

Ways to fix: unplug the modem AND stop-start network-manager (which stops-starts modemmanager), plug modem back in.
Seems like the modem "keeps connection open" while still being powered on and cannot be initialized properly. Very irritating since it cannot be fixed without modem unplugging.
Full debug info below.

Details in short (see attached files for full debug info):

Modem after connecting to 3G network, then either restarting the computer or restarting network-manager (syslog):
Oct 15 08:54:08 home kernel: [ 9.435382] USB Serial support registered for GSM modem (1-port)
Oct 15 08:54:08 home kernel: [ 9.436317] option 1-6:1.0: GSM modem (1-port) converter detected
Oct 15 08:54:08 home kernel: [ 9.436478] usb 1-6: GSM modem (1-port) converter now attached to ttyUSB0
Oct 15 08:54:08 home kernel: [ 9.436522] option 1-6:1.3: GSM modem (1-port) converter detected
Oct 15 08:54:08 home kernel: [ 9.436611] usb 1-6: GSM modem (1-port) converter now attached to ttyUSB1
Oct 15 08:54:08 home kernel: [ 9.436622] option 1-6:1.4: GSM modem (1-port) converter detected
Oct 15 08:54:08 home kernel: [ 9.436703] usb 1-6: GSM modem (1-port) converter now attached to ttyUSB2
Oct 15 08:54:08 home kernel: [ 9.436766] option: v0.7.2:USB Driver for GSM modems
Oct 15 08:54:08 home modem-manager[877]: <info> ModemManager (version 0.5) starting...
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Novatel
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Option High-Speed
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin AnyData
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin X22X
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Nokia
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Wavecom
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin SimTech
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin ZTE
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Generic
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Linktop
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Samsung
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Ericsson MBM
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Sierra
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin MotoC
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Option
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Gobi
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Huawei
Oct 15 08:54:08 home modem-manager[877]: <info> Loaded plugin Longcheer
Oct 15 08:54:08 home modem-manager[877]: <info> (ttyUSB0) opening serial port...
Oct 15 08:54:08 home NetworkManager[882]: <info> modem-manager is now available
Oct 15 08:54:08 home NetworkManager[882]: <info> modem-manager is now available
Oct 15 08:55:05 home modem-manager[877]: <info> (ttyUSB0) closing serial port...
Oct 15 08:55:05 home modem-manager[877]: <info> (ttyUSB0) serial port closed
Oct 15 08:55:05 home modem-manager[877]: <info> (ttyUSB0) opening serial port...
Oct 15 08:55:11 home modem-manager[877]: <info> (ttyUSB0) closing serial port...
Oct 15 08:55:11 home modem-manager[877]: <info> (ttyUSB0) serial port closed

---------------------------------------------------

PROPER (expected to be permanent) modem functioning (syslog):
Oct 15 08:07:51 home kernel: [ 9.329122] USB Serial support registered for GSM modem (1-port)
Oct 15 08:07:51 home kernel: [ 9.329523] option 1-4:1.0: GSM modem (1-port) converter detected
Oct 15 08:07:51 home kernel: [ 9.329722] usb 1-4: GSM modem (1-port) converter now attached to ttyUSB0
Oct 15 08:07:51 home kernel: [ 9.329743] option 1-4:1.3: GSM modem (1-port) converter detected
Oct 15 08:07:51 home kernel: [ 9.329877] usb 1-4: GSM modem (1-port) converter now attached to ttyUSB1
Oct 15 08:07:51 home kernel: [ 9.329887] option 1-4:1.4: GSM modem (1-port) converter detected
Oct 15 08:07:51 home kernel: [ 9.330024] usb 1-4: GSM modem (1-port) converter now attached to ttyUSB2
Oct 15 08:07:51 home kernel: [ 9.330448] option: v0.7.2:USB Driver for GSM modems
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Linktop
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Samsung
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Ericsson MBM
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Sierra
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin MotoC
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Option
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Gobi
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Huawei
Oct 15 08:07:51 home modem-manager[863]: <info> Loaded plugin Longcheer
Oct 15 08:07:51 home modem-manager[863]: <info> (ttyUSB0) opening serial port...
Oct 15 08:07:51 home NetworkManager[926]: <info> modem-manager is now available
Oct 15 08:07:54 home modem-manager[863]: <info> (ttyUSB0) closing serial port...
Oct 15 08:07:54 home modem-manager[863]: <info> (ttyUSB0) serial port closed
Oct 15 08:07:54 home modem-manager[863]: <info> (ttyUSB0) opening serial port...
Oct 15 08:07:54 home modem-manager[863]: <info> (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb1/1-4 claimed port ttyUSB0
Oct 15 08:07:55 home modem-manager[863]: <info> (ttyUSB0) closing serial port...
Oct 15 08:07:55 home modem-manager[863]: <info> (ttyUSB0) serial port closed
Oct 15 08:07:57 home modem-manager[863]: <info> (ttyUSB1) opening serial port...
Oct 15 08:07:57 home modem-manager[863]: <info> (ttyUSB2) opening serial port...
Oct 15 08:07:58 home modem-manager[863]: <info> (ttyUSB2) closing serial port...
Oct 15 08:07:58 home modem-manager[863]: <info> (ttyUSB2) serial port closed
Oct 15 08:07:58 home modem-manager[863]: <info> (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb1/1-4 claimed port ttyUSB2
Oct 15 08:08:09 home modem-manager[863]: <info> (ttyUSB1) closing serial port...
Oct 15 08:08:09 home modem-manager[863]: <info> (ttyUSB1) serial port closed
Oct 15 08:08:09 home modem-manager[863]: <info> (ttyUSB1) opening serial port...
Oct 15 08:08:12 home modem-manager[863]: <info> (ttyUSB1) closing serial port...
Oct 15 08:08:12 home modem-manager[863]: <info> (ttyUSB1) serial port closed
Oct 15 08:08:12 home modem-manager[863]: <info> (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb1/1-4 claimed port ttyUSB1
Oct 15 08:09:30 home modem-manager[863]: <info> (ttyUSB0) opening serial port...
Oct 15 08:09:30 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
Oct 15 08:09:30 home modem-manager[863]: <info> (ttyUSB2) opening serial port...
Oct 15 08:09:30 home modem-manager[863]: Invalid error code: 303
Oct 15 08:09:30 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
Oct 15 08:09:30 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> registered)
Oct 15 08:09:31 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> connecting)
Oct 15 08:09:31 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting -> registered)
Oct 15 08:09:31 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> searching)
Oct 15 08:09:31 home modem-manager[863]: <info> Modem /org/freedesktop/ModemManager/Modems/0: state changed (searching -> registered)

------------------------

Some more info (received while modemmanager in debug mode) in short (full log attached):
Modemmanager sends five AT^CURC=0 commands to ttyUSB0, receives no (or unexpected) reply.
Then sends five AT^GETPORTMODE commands to ttyUSB0, receives no (or unexpected) reply.
Then sends three AT+GCAP commands to ttyUSB0, receives no (or unexpected) reply.
Closes port ttyUSB0. Reopens port ttyUSB0.
Sends two 00 78 f0 7e signals to ttyUSB0, receives no (or unexpected) reply.
Closes port ttyUSB0.
At the same time, ttyUSB1 and ttyUSB2 continuosly get "re-checking support..." and "deferring support check" without success (and keep getting that after ttyUSB0 gets closed).

Dumb guess:
Maybe a different AT command should be sent to "reset" the modem if it "thinks there is a session open"?

[Deejay_TNT (idaho)]

I think this bug in Fedora bugtracker is related to this: https://bugzilla.redhat.com/show_bug.cgi?id=717727#c10

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[iGadget (igadget)]

I'm experiencing the same issue since I upgraded from Natty to Oneiric. However, in my case it's actually a bit worse because I can't get online anymore whatsoever. I have been able to get online *once*, just the first time after my system had been upgraded. Every attempt to get online after that has failed. Even rebooting the system makes no difference.

So maybe there's a persistent bogus setting not getting reset somewhere? Where should I look?

[Deejay_TNT (idaho)]

Did you try unpluggin the modem AND restarting computer (actually only network-manager service needs to be restarted)?

In my case if the modem is still pluggen in (even though the computer may be rebooted or even swithed off, while still getting +5V power from the USB port) - it won't connect.

Try to do that (unplug the modem completely from the usb port AND restart either network-manager or the computer.
Then check if it helps.

Also, you can monitor /var/log/syslog looking for line that states: (Huawei): GSM modem /sys/devices/pci0000:00/0000:00:1d.7/usb1/1-4 claimed port ttyUSBX. If such a line appers - the modem will work OK.

BTW, I checked the same thing in Fedora 16 (but I didn't install updates to Fedora 16 yet) - same issue.

[iGadget (igadget)]

Thanks for your tips. I always unplug the modem when it doesn't work. And since I only (have) use of the modem while on the road, it's always unplugged when arriving at my destination anyway. And while I've not tried restarting the machine right after the modem fails to connect, I don't think it will make any difference since I've rebooted the machine several times in between the moments I actually tried using the modem. And it failed to connect every time anyway.

I always keep a look at /var/log/syslog when trying to get online, I even did that when using 11.04 (how bad is that anyway - having to anticipate for failure instead of just using the device...). That's how I noticed the "Invalid error code: 303" and found your bug report on the Fedora bug tracker and link to this page :)

I'll keep a look out for the "...claimed port ttyUSBX" message, but somehow I feel like it's not going to show up whatsoever...

[Marius B. Kotsbak (mariusko)]

Have anyone of you tested this in Ubuntu 12.04 LTS?