3G network time out

Bug #329228 reported by Fernando Miguel
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
network-manager (Ubuntu)
Fix Released
Undecided
Unassigned

Bug Description

Binary package hint: network-manager

Jaunty 64 bits, NM from PPA
Huawei E220

it will detect dongle, and ask PIN, but it fails to connect

Feb 13 21:15:17 blubug NetworkManager: <info> starting...
Feb 13 21:15:17 blubug NetworkManager: <info> Found radio killswitch /org/freedesktop/Hal/devices/pci_8086_4229_rfkill_4965AGN_wlan
Feb 13 21:15:17 blubug NetworkManager: <info> eth0: driver is 'sky2'.
Feb 13 21:15:17 blubug NetworkManager: <info> Found new Ethernet device 'eth0'.
Feb 13 21:15:17 blubug NetworkManager: <info> (eth0): exported as /org/freedesktop/Hal/devices/net_00_1d_60_7f_e0_ae
Feb 13 21:15:17 blubug NetworkManager: <info> wlan2: driver is 'iwlagn'.
Feb 13 21:15:17 blubug NetworkManager: <info> wlan2: driver supports SSID scans (scan_capa 0x01).
Feb 13 21:15:17 blubug NetworkManager: <info> Found new 802.11 WiFi device 'wlan2'.
Feb 13 21:15:17 blubug NetworkManager: <info> (wlan2): exported as /org/freedesktop/Hal/devices/net_00_1d_e0_12_a2_57
Feb 13 21:15:17 blubug NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Feb 13 21:15:17 blubug last message repeated 2 times
Feb 13 21:15:21 blubug NetworkManager: <info> (eth0): device state change: 1 -> 2
Feb 13 21:15:21 blubug NetworkManager: <info> (eth0): bringing up device.
Feb 13 21:15:21 blubug kernel: [ 1521.532732] sky2 eth0: enabling interface
Feb 13 21:15:21 blubug NetworkManager: <info> (eth0): preparing device.
Feb 13 21:15:21 blubug NetworkManager: <info> (eth0): deactivating device (reason: 2).
Feb 13 21:15:21 blubug NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Feb 13 21:15:21 blubug NetworkManager: <info> (wlan2): device state change: 1 -> 2
Feb 13 21:15:21 blubug NetworkManager: <info> (wlan2): bringing up device.
Feb 13 21:15:21 blubug kernel: [ 1521.536751] ADDRCONF(NETDEV_UP): eth0: link is not ready
Feb 13 21:15:21 blubug kernel: [ 1521.740415] Registered led device: iwl-phy0::radio
Feb 13 21:15:21 blubug kernel: [ 1521.740441] Registered led device: iwl-phy0::assoc
Feb 13 21:15:21 blubug kernel: [ 1521.740464] Registered led device: iwl-phy0::RX
Feb 13 21:15:21 blubug kernel: [ 1521.740486] Registered led device: iwl-phy0::TX
Feb 13 21:15:21 blubug NetworkManager: <info> (wlan2): preparing device.
Feb 13 21:15:21 blubug NetworkManager: <info> (wlan2): deactivating device (reason: 2).
Feb 13 21:15:21 blubug kernel: [ 1521.783763] ADDRCONF(NETDEV_UP): wlan2: link is not ready
Feb 13 21:15:21 blubug NetworkManager: <info> (wlan2): device state change: 2 -> 3
Feb 13 21:15:21 blubug NetworkManager: <info> (wlan2): supplicant interface state: starting -> ready
Feb 13 21:15:39 blubug kernel: [ 1540.008184] usb 3-1: new full speed USB device using uhci_hcd and address 8
Feb 13 21:15:39 blubug kernel: [ 1540.171683] usb 3-1: configuration #1 chosen from 1 choice
Feb 13 21:15:39 blubug kernel: [ 1540.175234] usb-storage: probe of 3-1:1.0 failed with error -1
Feb 13 21:15:39 blubug kernel: [ 1540.232118] usb 3-1: USB disconnect, address 8
Feb 13 21:15:40 blubug kernel: [ 1540.968177] usb 3-1: new full speed USB device using uhci_hcd and address 9
Feb 13 21:15:40 blubug kernel: [ 1541.132670] usb 3-1: configuration #1 chosen from 1 choice
Feb 13 21:15:40 blubug kernel: [ 1541.134461] usb-storage: probe of 3-1:1.0 failed with error -5
Feb 13 21:15:40 blubug kernel: [ 1541.134475] option 3-1:1.0: GSM modem (1-port) converter detected
Feb 13 21:15:40 blubug kernel: [ 1541.134562] usb 3-1: GSM modem (1-port) converter now attached to ttyUSB0
Feb 13 21:15:40 blubug kernel: [ 1541.157374] usb-storage: probe of 3-1:1.1 failed with error -5
Feb 13 21:15:40 blubug kernel: [ 1541.157394] option 3-1:1.1: GSM modem (1-port) converter detected
Feb 13 21:15:40 blubug kernel: [ 1541.157505] usb 3-1: GSM modem (1-port) converter now attached to ttyUSB1
Feb 13 21:15:40 blubug kernel: [ 1541.163229] usb-storage: probe of 3-1:1.2 failed with error -1
Feb 13 21:15:40 blubug nm-system-settings: SCPlugin-Ifupdown: device added (udi: /org/freedesktop/Hal/devices/usb_device_12d1_1003_noserial_if0_serial_usb_0_3, iface: (null)): iface not found
Feb 13 21:15:41 blubug NetworkManager: <info> ttyUSB0: driver is 'option'.
Feb 13 21:15:41 blubug NetworkManager: <debug> [1234559741.004392] setup_monitor_device(): No monitoring udi provided
Feb 13 21:15:41 blubug NetworkManager: <info> Found new Modem device 'ttyUSB0'.
Feb 13 21:15:41 blubug NetworkManager: <info> (ttyUSB0): exported as /org/freedesktop/Hal/devices/usb_device_12d1_1003_noserial_if0_serial_usb_0_3
Feb 13 21:15:45 blubug NetworkManager: <info> (ttyUSB0): device state change: 1 -> 2
Feb 13 21:15:45 blubug NetworkManager: <info> (ttyUSB0): deactivating device (reason: 2).
Feb 13 21:15:45 blubug NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
Feb 13 21:15:45 blubug NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
Feb 13 21:15:45 blubug NetworkManager: <info> (ttyUSB0): device state change: 2 -> 3
Feb 13 21:16:10 blubug hddtemp[3725]: /dev/sg0: WDC WD3200BEVT-00ZCT0: 27 C
Feb 13 21:16:10 blubug hddtemp[3725]: /dev/sda: WDC WD3200BEVT-00ZCT0: 27 C
Feb 13 21:16:18 blubug NetworkManager: <info> Activation (ttyUSB0) starting connection 'TMN'
Feb 13 21:16:18 blubug NetworkManager: <info> (ttyUSB0): device state change: 3 -> 4
Feb 13 21:16:18 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 13 21:16:18 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Feb 13 21:16:18 blubug NetworkManager: <debug> [1234559778.990072] nm_serial_device_open(): (ttyUSB0) opening device...
Feb 13 21:16:18 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Feb 13 21:16:30 blubug NetworkManager: <WARN> init_done(): Trying alternate modem initialization
Feb 13 21:16:30 blubug NetworkManager: <info> (ttyUSB0): GSM pin secret required
Feb 13 21:16:30 blubug NetworkManager: <info> (ttyUSB0): device state change: 4 -> 6
Feb 13 21:16:30 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
Feb 13 21:16:30 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
Feb 13 21:16:30 blubug NetworkManager: <info> (ttyUSB0): device state change: 6 -> 4
Feb 13 21:16:30 blubug NetworkManager: <debug> [1234559790.041844] nm_serial_device_open(): (ttyUSB0) opening device...
Feb 13 21:16:30 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
Feb 13 21:16:41 blubug NetworkManager: <WARN> init_done(): Trying alternate modem initialization
Feb 13 21:16:41 blubug NetworkManager: <info> (ttyUSB0): powering up...
Feb 13 21:16:41 blubug NetworkManager: <info> Searching for a network...
Feb 13 21:16:45 blubug last message repeated 4 times
Feb 13 21:16:48 blubug NetworkManager: <info> Registered on Home network
Feb 13 21:16:48 blubug NetworkManager: <info> Associated with network: +COPS: 0,0,"Telecomunicacoes",2
Feb 13 21:16:48 blubug NetworkManager: <info> Connected, Woo!
Feb 13 21:16:48 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Feb 13 21:16:48 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Feb 13 21:16:48 blubug NetworkManager: <info> (ttyUSB0): device state change: 4 -> 5
Feb 13 21:16:48 blubug NetworkManager: <info> Starting pppd connection
Feb 13 21:16:48 blubug NetworkManager: <debug> [1234559808.467211] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute ttyUSB0 noipdefault 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
Feb 13 21:16:48 blubug pppd[17699]: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so is for pppd version 2.4.4, this is 2.4.5
Feb 13 21:16:48 blubug NetworkManager: <debug> [1234559808.475548] nm_ppp_manager_start(): ppp started with pid 17699
Feb 13 21:16:48 blubug NetworkManager: <info> Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Feb 13 21:16:48 blubug NetworkManager: <WARN> ppp_exit_code(): ppp pid 17699 exited with error: pppd options error
Feb 13 21:16:48 blubug NetworkManager: <debug> [1234559808.476047] ppp_watch_cb(): ppp pid 17699 cleaned up
Feb 13 21:16:48 blubug NetworkManager: <info> (ttyUSB0): device state change: 5 -> 9
Feb 13 21:16:48 blubug NetworkManager: <debug> [1234559808.476145] nm_serial_device_close(): Closing device 'ttyUSB0'
Feb 13 21:16:48 blubug NetworkManager: <info> Marking connection 'TMN' invalid.
Feb 13 21:16:48 blubug NetworkManager: <info> Activation (ttyUSB0) failed.
Feb 13 21:16:48 blubug NetworkManager: <info> (ttyUSB0): device state change: 9 -> 3
Feb 13 21:16:48 blubug NetworkManager: <info> (ttyUSB0): deactivating device (reason: 0).
Feb 13 21:16:48 blubug NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
Feb 13 21:16:48 blubug NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
Feb 13 21:17:01 blubug /USR/SBIN/CRON[17788]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)

ppp:
  Installed: 2.4.5~git20081126t100229-0ubuntu1~nm1
  Candidate: 2.4.5~git20081126t100229-0ubuntu1~nm1
  Version table:
 *** 2.4.5~git20081126t100229-0ubuntu1~nm1 0
        500 http://ppa.launchpad.net jaunty/main Packages
        100 /var/lib/dpkg/status
     2.4.4rel-10ubuntu3 0
        500 ftp://darkstar.ist.utl.pt jaunty/main Packages
        500 ftp://archive.ubuntu.com jaunty/main Packages
network-manager-pptp:
  Installed: 0.7-0ubuntu2~nm2
  Candidate: 0.7-0ubuntu2~nm2
  Version table:
 *** 0.7-0ubuntu2~nm2 0
        500 http://ppa.launchpad.net jaunty/main Packages
        100 /var/lib/dpkg/status
     0.7-0ubuntu1 0
        500 ftp://darkstar.ist.utl.pt jaunty/universe Packages
        500 ftp://archive.ubuntu.com jaunty/universe Packages
network-manager:
  Installed: 0.7-0ubuntu1
  Candidate: 0.7-0ubuntu1
  Version table:
 *** 0.7-0ubuntu1 0
        500 ftp://darkstar.ist.utl.pt jaunty/main Packages
        500 ftp://archive.ubuntu.com jaunty/main Packages
        100 /var/lib/dpkg/status
     0.7-0ubuntu1~nm1 0
        500 http://ppa.launchpad.net jaunty/main Packages

ProblemType: Bug
Architecture: amd64
DistroRelease: Ubuntu 9.04
IfupdownConfig:
 auto lo
 iface lo inet loopback
NonfreeKernelModules: nvidia
Package: network-manager 0.7-0ubuntu1
ProcEnviron:
 SHELL=/bin/bash
 PATH=(custom, no user)
 LANG=en_US.UTF-8
SourcePackage: network-manager
Uname: Linux 2.6.28-7-generic x86_64

Revision history for this message
Fernando Miguel (fernandomiguel) wrote :
Revision history for this message
Fernando Miguel (fernandomiguel) wrote :
Revision history for this message
Fernando Miguel (fernandomiguel) wrote :

after fresh reboot

Revision history for this message
Fernando Miguel (fernandomiguel) wrote :
Revision history for this message
Fernando Miguel (fernandomiguel) wrote :
Revision history for this message
Alexander Sack (asac) wrote :

 pppd[5815]: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so is for pppd version 2.4.4, this is 2.4.5

-> if forgot to respin network-manager in PPA ... uploaded -ubuntu2~nm1 of the main daemon now. Should be available in ~1h.

Please reopen if you still see this after upgrading to it.

Changed in network-manager:
status: New → Fix Released
Revision history for this message
dvo (mueller8) wrote :

After recently upgrading my system to Ubuntu 10.04, I had the same problem:
Broadband connection did not work, NetworkManager complained about: pppd options error,
and pppd said:: Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so is for pppd version 2.4.5, this is 2.4.5
Weirdly, /usr/lib/pppd/2.4.4/nm-pppd-plugin.so was identical to /usr/lib/pppd/2.4.5/nm-pppd-plugin.so

This apparently very version-sensitive plugin architecture seems to be pretty broken.
As someone wrote in https://bugzilla.redhat.com/show_bug.cgi?id=548520#c20
"If ppp updates to 2.4.6 tomorrow, then you'll be right back in the same problem."

This bug has cost me many precious hours, and still I do not have a good solution, which is pretty frustrating for end-users like me
My current workaround is to manually downgrade to ppp 2.4.4, network-manager0.7, libnm-util0 0.7
where trying to satisfy all the resulting dependency problems is a pain in the butt :-(

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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