Bug 596011 - Regression: total failure to connect via mobile Broadband (cdc_acm)
Regression: total failure to connect via mobile Broadband (cdc_acm)
Status: CLOSED CURRENTRELEASE
Product: Fedora
Classification: Fedora
Component: NetworkManager (Show other bugs)
12
All Linux
low Severity medium
: ---
: ---
Assigned To: Dan Williams
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2010-05-26 02:30 EDT by David Anderson
Modified: 2010-08-04 01:11 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2010-08-04 01:11:22 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
modem manager log (17.77 KB, text/plain)
2010-08-01 18:48 EDT, Stuart D Gathman
no flags Details
network manager log to go with modem-manager log (5.99 KB, text/plain)
2010-08-01 18:49 EDT, Stuart D Gathman
no flags Details

  None (edit)
Description David Anderson 2010-05-26 02:30:56 EDT
Description of problem:

I upgraded NetworkManager to NetworkManager-0.8.0-6.git20100408.fc12.x86_64, and the corresponding NetworkManager-gnome and NetworkManager-glib versions.

After doing so, attempts to connect to 3G broadband via two different Nokias always failed. On down-grading back to the original versions I had (NetworkManager-0.7.997-2.git20091214.fc12.x86_64), everything worked again.

This is with ModemManager-0.3-2.git20100211.fc12.x86_64, which was upgraded to ModemManager-0.3-9.git20100409.fc12.x86_64 and then downgraded again. ppp version is ppp-2.4.5-2.fc12.x86_64.

How reproducible: Every time.

Here is the log output of the phone being connected, and then the failure to connect to the Internet:

May 25 18:16:39 localhost kernel: usb 1-7: new high speed USB device using ehci_hcd and address 4
May 25 18:16:39 localhost kernel: usb 1-7: New USB device found, idVendor=0421, idProduct=010e
May 25 18:16:39 localhost kernel: usb 1-7: New USB device strings: Mfr=1, Product=2, SerialNumber=3
May 25 18:16:39 localhost kernel: usb 1-7: Product: Nokia E75
May 25 18:16:39 localhost kernel: usb 1-7: Manufacturer: Nokia
May 25 18:16:39 localhost kernel: usb 1-7: SerialNumber: 359557011527518
May 25 18:16:39 localhost kernel: usb 1-7: configuration #1 chosen from 1 choice
May 25 18:16:40 localhost kernel: NET: Registered protocol family 35
May 25 18:16:40 localhost kernel: cdc_acm 1-7:1.1: ttyACM0: USB ACM device
May 25 18:16:40 localhost kernel: usbcore: registered new interface driver cdc_acm
May 25 18:16:40 localhost kernel: cdc_acm: v0.26:USB Abstract Control Model driver for USB modems and ISDN adapters
May 25 18:16:40 localhost kernel: usbcore: registered new interface driver cdc_ether
May 25 18:16:40 localhost kernel: usb 1-7: bad CDC descriptors
May 25 18:16:40 localhost kernel: usbcore: registered new interface driver rndis_host
May 25 18:16:40 localhost kernel: cdc_phonet: probe of 1-7:1.10 failed with error -22
May 25 18:16:40 localhost kernel: usbcore: registered new interface driver cdc_phonet
May 25 18:16:40 localhost kernel: usb 1-7: bad CDC descriptors
May 25 18:16:40 localhost kernel: usbcore: registered new interface driver rndis_wlan
May 25 18:16:40 localhost modem-manager: (ttyACM0) opening serial device...
May 25 18:16:41 localhost modem-manager: (ttyACM0) closing serial device...
May 25 18:16:41 localhost modem-manager: (ttyACM0) opening serial device...
May 25 18:16:41 localhost modem-manager: (Nokia): GSM modem /sys/devices/pci0000:00/0000:00:13.5/usb1/1-7 claimed port ttyACM0
May 25 18:16:41 localhost modem-manager: (ttyACM0) closing serial device...
May 25 18:16:41 localhost NetworkManager: <info> (ttyACM0): new GSM device (driver: 'cdc_acm')
May 25 18:16:41 localhost NetworkManager: <info> (ttyACM0): exported as /org/freedesktop/NetworkManager/Devices/2
May 25 18:16:41 localhost NetworkManager: <info> (ttyACM0): now managed
May 25 18:16:41 localhost NetworkManager: <info> (ttyACM0): device state change: 1 -> 2 (reason 2)
May 25 18:16:41 localhost NetworkManager: <info> (ttyACM0): deactivating device (reason: 2).
May 25 18:16:41 localhost NetworkManager: <info> (ttyACM0): device state change: 2 -> 3 (reason 0)
May 25 18:16:45 localhost NetworkManager: <info> Activation (ttyACM0) starting connection 'Auto Mobile Broadband (GSM) connection'
May 25 18:16:45 localhost NetworkManager: <info> (ttyACM0): device state change: 3 -> 4 (reason 0)
May 25 18:16:45 localhost NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled...
May 25 18:16:45 localhost NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started...
May 25 18:16:45 localhost modem-manager: (ttyACM0) opening serial device...
May 25 18:16:45 localhost NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete.
May 25 18:16:45 localhost modem-manager: Modem /org/freedesktop/ModemManager/Modems/0: state changed (disabled -> enabling)
May 25 18:16:46 localhost modem-manager: Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabling -> enabled)
May 25 18:16:46 localhost modem-manager: Modem /org/freedesktop/ModemManager/Modems/0: state changed (enabled -> registered)
May 25 18:16:46 localhost modem-manager: Modem /org/freedesktop/ModemManager/Modems/0: state changed (registered -> connecting)
May 25 18:16:46 localhost modem-manager: Modem /org/freedesktop/ModemManager/Modems/0: state changed (connecting -> registered)
May 25 18:16:46 localhost NetworkManager: <info> (ttyACM0): device state change: 4 -> 9 (reason 1)
May 25 18:16:46 localhost NetworkManager: <info> Marking connection 'Auto Mobile Broadband (GSM) connection' invalid.
May 25 18:16:46 localhost NetworkManager: <info> (ttyACM0): device state change: 9 -> 3 (reason 0)
May 25 18:16:46 localhost NetworkManager: <info> (ttyACM0): deactivating device (reason: 0).
Comment 1 Dan Williams 2010-05-26 05:47:05 EDT
Can you do the following for me, as root?

1) install latest ModemManager and NetworkManager
2) service NetworkManager stop
3) killall -TERM modem-manager
4) modem-manager --debug
5) (in another terminal) /usr/sbin/NetworkManager --no-daemon

and then reproduce the problem.  Please then attach the output of both NetworkManager and modem-manager so we can diagnose further.

FWIW this would appear to be limited to Nokia devices via USB, as the following phones work for me tethered via USB:

1) LG Rumor (CDMA)
2) Sony-Ericsson TM-506

and via DUN:

1) Nokia 2726
Comment 2 Stuart D Gathman 2010-08-01 18:26:49 EDT
I have a Cricket A600, which was working perfectly until mid June.  I believe the update that broke it was:

Jun 17 21:38:27 Updated: 1:NetworkManager-glib-0.8.1-0.1.git20100510.fc12.i686
Jun 17 21:39:38 Updated: ModemManager-0.3-13.git20100507.fc12.i686
Jun 17 21:39:43 Updated: 1:NetworkManager-0.8.1-0.1.git20100510.fc12.i686
Jun 17 21:40:24 Updated: 1:NetworkManager-gnome-0.8.1-0.1.git20100510.fc12.i686
Jun 17 21:40:27 Updated: 1:NetworkManager-vpnc-0.8.0-1.git20100411.fc12.i686
Jun 17 21:40:29 Updated: 1:NetworkManager-pptp-0.8.0-1.git20100411.fc12.i686

I am updating to latest to provide the debug info you requested (but for A600, not Nokia).
Comment 3 Stuart D Gathman 2010-08-01 18:48:29 EDT
Created attachment 435921 [details]
modem manager log

Updated from updates-testing

  Updating       : 1:NetworkManager-glib-0.8.1-1.fc12.i686                  1/8 
  Updating       : ModemManager-0.4-4.git20100720.fc12.i686                 2/8 
  Updating       : 1:NetworkManager-0.8.1-1.fc12.i686                       3/8 
  Updating       : 1:NetworkManager-gnome-0.8.1-1.fc12.i686                 4/8 

after initial no-carrier, unplugged and plugged modem.
Comment 4 Stuart D Gathman 2010-08-01 18:49:19 EDT
Created attachment 435922 [details]
network manager log to go with modem-manager log
Comment 5 Stuart D Gathman 2010-08-02 18:23:02 EDT
Since the "no carrier" error seems suspicious, just to make sure, I attached the modem to a Windows box.  The Windows software now asks for a username and password (which it never did before).  So something has changed on the service.  Will report after talking with tech support (who will only talk to you if you run their Windows software).
Comment 6 Stuart D Gathman 2010-08-03 16:05:46 EDT
Ok, the current failure is because the Cricket autopay failed for July (suspending the account).  That still doesn't explain why it quit working mid June.  However, it does mean that the logs I uploaded are worthless, and maybe I should delete them.  (Or maybe NM can reliably detect a suspended account.)

As soon as we get done yelling at their billing dept, I'll test again with the latest NM to see if the problem from the June update is fixed.
Comment 7 Stuart D Gathman 2010-08-03 23:12:35 EDT
Whatever the problem was Jun 17, it is now resolved with the latest NM from updates (writing this via modem).  Unless developers request it, I won't bother downgrading to narrow down exactly which version was broken.  Sorry for the noise.
Comment 8 Dan Williams 2010-08-04 01:11:22 EDT
No problem, thanks for the update.

Note You need to log in before you can comment on or make changes to this bug.