ModemManager

Vodafone 3G PCMCIA Card ramdonly fails to connect

Bug #434275 reported by João Pinto
16
This bug affects 2 people
Affects Status Importance Assigned to Milestone
ModemManager
Fix Committed
Undecided
Unassigned
modemmanager (Ubuntu)
Fix Released
Low
Unassigned
network-manager (Ubuntu)
Invalid
Undecided
Unassigned

Bug Description

Version: 0.8~a~git.20090911t130220.4c77fa0-0ubuntu6

When using a Vodafone 3G PCMCIA card NM randomly fails to connect, some times I need to retry for about 10 times:

Sep 21 08:15:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) starting connection 'Vodafone'
Sep 21 08:15:08 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0)
Sep 21 08:15:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 21 08:15:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Sep 21 08:15:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Sep 21 08:15:08 pt001424-laptop modem-manager: (ttyUSB0) opening serial device...
Sep 21 08:15:21 pt001424-laptop modem-manager: Registration state changed: 2
Sep 21 08:15:25 pt001424-laptop modem-manager: Registration state changed: 1
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5 (reason 0)
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 5 -> 7 (reason 0)
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Starting pppd connection
Sep 21 08:15:25 pt001424-laptop NetworkManager: <debug> [1253517325.311780] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/0 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
Sep 21 08:15:25 pt001424-laptop NetworkManager: <debug> [1253517325.319152] nm_ppp_manager_start(): ppp started with pid 2774
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled...
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started...
Sep 21 08:15:25 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete.
Sep 21 08:15:25 pt001424-laptop NetworkManager: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Sep 21 08:15:25 pt001424-laptop NetworkManager: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no exported connection
Sep 21 08:15:27 pt001424-laptop NetworkManager: <WARN> stage1_prepare_done(): GSM modem connection failed: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
Sep 21 08:15:27 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 7 -> 9 (reason 1)
Sep 21 08:15:27 pt001424-laptop NetworkManager: <info> Marking connection 'Vodafone' invalid.
Sep 21 08:15:27 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) failed.
Sep 21 08:15:27 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3 (reason 0)
Sep 21 08:15:27 pt001424-laptop NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0).
Sep 21 08:15:27 pt001424-laptop NetworkManager: flush_routes: assertion `iface_idx >= 0' failed
Sep 21 08:15:27 pt001424-laptop NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed
Sep 21 08:15:27 pt001424-laptop NetworkManager: SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Sep 21 08:15:28 pt001424-laptop modem-manager: (ttyUSB0) closing serial device...
Sep 21 08:15:29 pt001424-laptop NetworkManager: <debug> [1253517329.001825] ensure_killed(): waiting for ppp pid 2774 to exit
Sep 21 08:15:29 pt001424-laptop NetworkManager: <debug> [1253517329.001997] ensure_killed(): ppp pid 2774 cleaned up

Here is a sucessfull conection log:
Sep 21 22:00:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) starting connection 'Vodafone'
Sep 21 22:00:08 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4 (reason 0)
Sep 21 22:00:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 21 22:00:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Sep 21 22:00:08 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Sep 21 22:00:08 pt001424-laptop modem-manager: (ttyUSB0) opening serial device...
Sep 21 22:00:21 pt001424-laptop modem-manager: Registration state changed: 2
Sep 21 22:00:23 pt001424-laptop modem-manager: Registration state changed: 1
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5 (reason 0)
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 5 -> 7 (reason 0)
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Starting pppd connection
Sep 21 22:00:23 pt001424-laptop NetworkManager: <debug> [1253566823.387259] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/0 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
Sep 21 22:00:23 pt001424-laptop NetworkManager: <debug> [1253566823.402748] nm_ppp_manager_start(): ppp started with pid 2786
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled...
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started...
Sep 21 22:00:23 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete.
Sep 21 22:00:23 pt001424-laptop NetworkManager: SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Sep 21 22:00:23 pt001424-laptop NetworkManager: SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no exported connection
Sep 21 22:00:33 pt001424-laptop NetworkManager: <info> PPP manager(IP Config Get) reply received.
Sep 21 22:00:33 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) scheduled...
Sep 21 22:00:33 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) started...
Sep 21 22:00:33 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 21 22:00:33 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) complete.
Sep 21 22:00:33 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) started...
Sep 21 22:00:34 pt001424-laptop NetworkManager: <info> (ttyUSB0): device state change: 7 -> 8 (reason 0)
Sep 21 22:00:34 pt001424-laptop NetworkManager: <info> Policy set 'Vodafone' (ppp0) as default for routing and DNS.
Sep 21 22:00:34 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) successful, device activated.
Sep 21 22:00:34 pt001424-laptop NetworkManager: <info> Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) complete.
Sep 21 22:00:35 pt001424-laptop nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/01ifupdown' exited with error status 1.
Sep 21 22:00:36 pt001424-laptop ntpdate[2863]: adjust time server 91.189.94.4 offset 0.182885 sec

Revision history for this message
João Pinto (joaopinto) wrote :

I have found the following.
When I plugin the PCMCIA card the driver configures 4 devices, ttyUSB0-3 , networkmanager (or modemmanager?) is randomly selecting a device when connecting.
The connection is only successful when the ttyUSB0 device is used.

Revision history for this message
João Pinto (joaopinto) wrote :

Looking at lshal (see attachmenet), there is a single device which advertises the 'modem' capability, which is /dev/ttyUSB0, network-manager should be using this one instead of selecting a random device.

Revision history for this message
Mathieu Trudel-Lapierre (cyphermox) wrote :

João,

Could you follow the instructions in https://wiki.ubuntu.com/DebuggingModemmanager and add the information requested there to this bug?

Thanks!

Changed in modemmanager (Ubuntu):
status: New → Incomplete
Changed in network-manager (Ubuntu):
status: New → Invalid
Revision history for this message
João Pinto (joaopinto) wrote :

Matt,
thanks for the feedback.

I have added the trunk ppa and then did multiple connection attempts, it is working fine now, always using ttyUSB0 .
Is it safe to keep with the trunk ppa enable or are you are likely to move the ppa fix to the lucid's repository ?
Any chance the fix being applied also on Karmic ? I have a stable partition where I can't afford to upgrade to the trunk PPA .

Thanks

Revision history for this message
Mathieu Trudel-Lapierre (cyphermox) wrote :

João,

This should be corrected soon in Lucid, and probably in Karmic as well in an update.

Changed in modemmanager (Ubuntu):
status: Incomplete → Fix Committed
importance: Undecided → Low
Changed in modemmanager:
status: New → Fix Committed
Marius B. Kotsbak (mariusko)
Changed in modemmanager (Ubuntu):
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.