Ubuntu
modemmanager package

F3507G - Cannot connect using 3G/HDSPA modem (Karmic - NM 0.8 regression ?)

Bug #434737 reported by ignasi
52
This bug affects 9 people
Affects Status Importance Assigned to Milestone
modemmanager (Ubuntu)
Fix Released
Medium
Alexander Sack

Bug Description

Binary package hint: network-manager

I've been connecting through 3G services since Jaunty without noticeable problems. However, I've been testing karmic for the past month and things have not been so good. If I use wvdial or gnome-ppp I have no troubles at all.

I have a Lenovo ThinkPad SL-500 with an Ericsson F3507G 3G modem inside. I've done a full repport with comments and logs with the hopes that anybody can see what's going on...

Hardware:

Bus 002 Device 003: ID 0bdb:1900 Ericsson Business Mobile Networks BV

First time I try to dial:

Sep 21 13:28:27 Caladan modem-manager: (ttyACM0) opening serial device...
Sep 21 13:28:27 Caladan modem-manager: Got failure code 100: Unknown error
Sep 21 13:28:28 Caladan NetworkManager: <info> (usb0): device state change: 4 -> 6 (reason 0)
Sep 21 13:28:28 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 21 13:28:28 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) started...
Sep 21 13:28:28 Caladan NetworkManager: <info> (usb0): device state change: 6 -> 4 (reason 0)
Sep 21 13:28:28 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) complete.
Sep 21 13:28:28 Caladan modem-manager: Got failure code 11: SIM PIN required
Sep 21 13:28:28 Caladan modem-manager: Got failure code 11: SIM PIN required
Sep 21 13:28:28 Caladan modem-manager: (ttyACM0) closing serial device...

PIN Code has been already inserted in connection settings

NM is trying yo establish the connection without success. Finally I cancel it. Then I get these messages:

Sep 21 13:29:57 Caladan NetworkManager: <info> (usb0): device state change: 4 -> 3 (reason 39)
Sep 21 13:29:57 Caladan NetworkManager: <info> (usb0): deactivating device (reason: 39).
Sep 21 13:30:28 Caladan 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 13:30:28 Caladan NetworkManager: <info> (usb0): device state change: 3 -> 9 (reason 1)
Sep 21 13:30:28 Caladan NetworkManager: <info> Activation (usb0) failed.
Sep 21 13:30:28 Caladan NetworkManager: <info> (usb0): device state change: 9 -> 3 (reason 0)
Sep 21 13:30:28 Caladan NetworkManager: <info> (usb0): deactivating device (reason: 0).

Second try:

Sep 21 13:31:20 Caladan NetworkManager: <info> Activation (usb0) starting connection 'Simyo'
Sep 21 13:31:20 Caladan NetworkManager: <info> (usb0): device state change: 3 -> 4 (reason 0)
Sep 21 13:31:20 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 21 13:31:20 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) started...
Sep 21 13:31:20 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) complete.
Sep 21 13:31:20 Caladan modem-manager: (ttyACM0) opening serial device...
Sep 21 13:31:21 Caladan modem-manager: Registration state changed: 4
Sep 21 13:31:22 Caladan modem-manager: get_reg_status_done: unknown response: *ESTKSMENU: Servicio simyo,0,1#012#0151,Servicio Roaming#012#015#015#012#015#012+CREG: 1,4
Sep 21 13:31:22 Caladan NetworkManager: <WARN> stage1_prepare_done(): GSM modem connection failed: Could not parse the response
Sep 21 13:31:22 Caladan NetworkManager: <info> (usb0): device state change: 4 -> 9 (reason 1)
Sep 21 13:31:22 Caladan NetworkManager: <info> Marking connection 'Simyo' invalid.
Sep 21 13:31:22 Caladan NetworkManager: <info> Activation (usb0) failed.
Sep 21 13:31:22 Caladan NetworkManager: <info> (usb0): device state change: 9 -> 3 (reason 0)
Sep 21 13:31:22 Caladan NetworkManager: <info> (usb0): deactivating device (reason: 0).
Sep 21 13:31:22 Caladan modem-manager: (ttyACM0) closing serial device...

NM has tried and after 2 seconds aprox. trying it cancels with an error.

Now 3rd try (this one always works):

Sep 21 13:32:49 Caladan NetworkManager: <info> Activation (usb0) starting connection 'Simyo'
Sep 21 13:32:49 Caladan NetworkManager: <info> (usb0): device state change: 3 -> 4 (reason 0)
Sep 21 13:32:49 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 21 13:32:49 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) started...
Sep 21 13:32:49 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) complete.
Sep 21 13:32:49 Caladan modem-manager: (ttyACM0) opening serial device...
Sep 21 13:32:50 Caladan modem-manager: Registration state changed: 5
Sep 21 13:32:50 Caladan modem-manager: mbm_e2nap_received, connecting
Sep 21 13:32:52 Caladan modem-manager: mbm_e2nap_received, connected
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 2 of 5 (Device Configure) scheduled...
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 2 of 5 (Device Configure) starting...
Sep 21 13:32:52 Caladan NetworkManager: <info> (usb0): device state change: 4 -> 5 (reason 0)
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 2 of 5 (Device Configure) successful.
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 3 of 5 (IP Configure Start) scheduled.
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 2 of 5 (Device Configure) complete.
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 3 of 5 (IP Configure Start) started...
Sep 21 13:32:52 Caladan NetworkManager: <info> (usb0): device state change: 5 -> 7 (reason 0)
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Beginning DHCP transaction (timeout in 45 seconds)
Sep 21 13:32:52 Caladan NetworkManager: <info> dhclient started with pid 3748
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 4 of 5 (IP6 Configure Get) scheduled...
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 3 of 5 (IP Configure Start) complete.
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 4 of 5 (IP6 Configure Get) started...
Sep 21 13:32:52 Caladan NetworkManager: <info> Activation (usb0) Stage 4 of 5 (IP6 Configure Get) complete.
Sep 21 13:32:52 Caladan dhclient: Internet Systems Consortium DHCP Client V3.1.2
Sep 21 13:32:52 Caladan dhclient: Copyright 2004-2008 Internet Systems Consortium.
Sep 21 13:32:52 Caladan dhclient: All rights reserved.
Sep 21 13:32:52 Caladan dhclient: For info, please visit http://www.isc.org/sw/dhcp/
Sep 21 13:32:52 Caladan dhclient:
Sep 21 13:32:52 Caladan NetworkManager: <info> DHCP: device usb0 state changed (null) -> preinit
Sep 21 13:32:52 Caladan dhclient: Listening on LPF/usb0/02:80:37:ec:02:00
Sep 21 13:32:52 Caladan dhclient: Sending on LPF/usb0/02:80:37:ec:02:00
Sep 21 13:32:52 Caladan dhclient: Sending on Socket/fallback
Sep 21 13:32:53 Caladan avahi-daemon[1932]: Registering new address record for fe80::80:37ff:feec:200 on usb0.*.
Sep 21 13:32:54 Caladan dhclient: DHCPDISCOVER on usb0 to 255.255.255.255 port 67 interval 3
Sep 21 13:32:54 Caladan dhclient: DHCPOFFER of 95.214.60.15 from 95.214.60.9
Sep 21 13:32:54 Caladan dhclient: DHCPREQUEST of 95.214.60.15 on usb0 to 255.255.255.255 port 67
Sep 21 13:32:54 Caladan dhclient: DHCPACK of 95.214.60.15 from 95.214.60.9
Sep 21 13:32:54 Caladan NetworkManager: <info> DHCP: device usb0 state changed preinit -> bound
Sep 21 13:32:54 Caladan NetworkManager: <info> Activation (usb0) Stage 4 of 5 (IP4 Configure Get) scheduled...
Sep 21 13:32:54 Caladan NetworkManager: <info> Activation (usb0) Stage 4 of 5 (IP4 Configure Get) started...
Sep 21 13:32:54 Caladan NetworkManager: <info> address 95.214.60.15
Sep 21 13:32:54 Caladan NetworkManager: <info> prefix 27 (255.255.255.224)
Sep 21 13:32:54 Caladan NetworkManager: <info> gateway 95.214.60.10
Sep 21 13:32:54 Caladan NetworkManager: <info> nameserver '195.230.105.134'
Sep 21 13:32:54 Caladan NetworkManager: <info> nameserver '195.230.105.135'
Sep 21 13:32:54 Caladan NetworkManager: <info> Activation (usb0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 21 13:32:54 Caladan NetworkManager: <info> Activation (usb0) Stage 4 of 5 (IP4 Configure Get) complete.
Sep 21 13:32:54 Caladan NetworkManager: <info> Activation (usb0) Stage 5 of 5 (IP Configure Commit) started...
Sep 21 13:32:54 Caladan avahi-daemon[1932]: Joining mDNS multicast group on interface usb0.IPv4 with address 95.214.60.15.
Sep 21 13:32:54 Caladan avahi-daemon[1932]: New relevant interface usb0.IPv4 for mDNS.
Sep 21 13:32:54 Caladan avahi-daemon[1932]: Registering new address record for 95.214.60.15 on usb0.IPv4.
Sep 21 13:32:54 Caladan dhclient: bound to 95.214.60.15 -- renewal in 142 seconds.
Sep 21 13:32:55 Caladan NetworkManager: <info> (usb0): device state change: 7 -> 8 (reason 0)
Sep 21 13:32:55 Caladan NetworkManager: <info> Policy set 'Simyo' (usb0) as default for routing and DNS.
Sep 21 13:32:55 Caladan NetworkManager: <info> Activation (usb0) successful, device activated.
Sep 21 13:32:55 Caladan NetworkManager: <info> Activation (usb0) Stage 5 of 5 (IP Configure Commit) complete.
Sep 21 13:32:55 Caladan nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/01ifupdown' exited with error status 1.
Sep 21 13:32:56 Caladan ntpdate[3806]: adjust time server 91.189.94.4 offset 0.084273 sec

Sometimes connection will be stable, but most of the times, after 1 minute the connection drops. Here's the log when it fails:

Sep 21 16:31:16 Caladan 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 16:31:16 Caladan NetworkManager: <info> (usb0): device state change: 8 -> 9 (reason 1)
Sep 21 16:31:16 Caladan NetworkManager: <info> Activation (usb0) failed.
Sep 21 16:31:16 Caladan NetworkManager: <info> (usb0): device state change: 9 -> 3 (reason 0)
Sep 21 16:31:16 Caladan NetworkManager: <info> (usb0): deactivating device (reason: 0).
Sep 21 16:31:16 Caladan modem-manager: (ttyACM0) closing serial device...
Sep 21 16:31:16 Caladan NetworkManager: <info> (usb0): canceled DHCP transaction, dhcp client pid 3708
Sep 21 16:31:16 Caladan NetworkManager: <WARN> check_one_route(): (usb0) error -34 returned from rtnl_route_del(): Sucess#012
Sep 21 16:31:16 Caladan avahi-daemon[1814]: Withdrawing address record for 95.214.73.202 on usb0.
Sep 21 16:31:16 Caladan avahi-daemon[1814]: Leaving mDNS multicast group on interface usb0.IPv4 with address 95.214.73.202.
Sep 21 16:31:16 Caladan avahi-daemon[1814]: Interface usb0.IPv4 no longer relevant for mDNS.
Sep 21 16:31:16 Caladan avahi-daemon[1814]: Withdrawing address record for fe80::80:37ff:feec:200 on usb0.

Now, if it does not fail, I can be connected for hours. Now, today, after some minutes connected, I disconnected the 3G connection, and there is no way (no matter how many times I try to get connected again). Here's the log:

Sep 21 13:43:23 Caladan NetworkManager: <info> Activation (usb0) starting connection 'Simyo'
Sep 21 13:43:23 Caladan NetworkManager: <info> (usb0): device state change: 3 -> 4 (reason 0)
Sep 21 13:43:23 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) scheduled...
Sep 21 13:43:23 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) started...
Sep 21 13:43:23 Caladan NetworkManager: <info> Activation (usb0) Stage 1 of 5 (Device Prepare) complete.
Sep 21 13:43:23 Caladan modem-manager: (ttyACM0) opening serial device...
Sep 21 13:43:24 Caladan modem-manager: Got failure code 100: Unknown error

After more than a minute it times out and cancels the connection request. Here's the log:

Sep 21 13:44:31 Caladan 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 13:44:31 Caladan NetworkManager: <info> (usb0): device state change: 4 -> 9 (reason 1)
Sep 21 13:44:31 Caladan NetworkManager: <info> Marking connection 'Simyo' invalid.
Sep 21 13:44:31 Caladan NetworkManager: <info> Activation (usb0) failed.
Sep 21 13:44:31 Caladan NetworkManager: <info> (usb0): device state change: 9 -> 3 (reason 0)
Sep 21 13:44:31 Caladan NetworkManager: <info> (usb0): deactivating device (reason: 0).
Sep 21 13:44:31 Caladan modem-manager: (ttyACM0) closing serial device...

The only way to connect again is (via hardware) to switch off the device and turn it back on. Then we start from the beginning again (it will work after 2 failures).

Regards,

Ignacio Garcia

Tags: 3g karmic mbm
Revision history for this message
Bruno Possolo (brunopossolo) wrote :
Download full text (4.6 KiB)

With me the problem happens with Samsung Z100... I try to connect to the 3G Network and my phone just reboots... In Ubuntu 9.04 worked Ok without any problem.

Here is my SYSLOG:
Oct 1 10:37:04 lap-tea-cup01 wpa_supplicant[1295]: CTRL-EVENT-SCAN-RESULTS
Oct 1 10:37:42 lap-tea-cup01 NetworkManager: <info> Activation (ttyACM0) starting connection 'TMN Default'
Oct 1 10:37:42 lap-tea-cup01 NetworkManager: <info> (ttyACM0): device state change: 3 -> 4 (reason 0)
Oct 1 10:37:42 lap-tea-cup01 NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 1 10:37:42 lap-tea-cup01 NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started...
Oct 1 10:37:42 lap-tea-cup01 NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete.
Oct 1 10:37:42 lap-tea-cup01 modem-manager: (ttyACM0) opening serial device...
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: <WARN> stage1_prepare_done(): GSM modem connection failed: Serial command timed out
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: <info> (ttyACM0): device state change: 4 -> 9 (reason 1)
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: <info> Marking connection 'TMN Default' invalid.
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: Tried to set deprecated property gsm/puk
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: <info> Activation (ttyACM0) failed.
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: <info> (ttyACM0): device state change: 9 -> 3 (reason 0)
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: <info> (ttyACM0): deactivating device (reason: 0).
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: flush_routes: assertion `iface_idx >= 0' failed
Oct 1 10:37:45 lap-tea-cup01 NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed
Oct 1 10:37:50 lap-tea-cup01 modem-manager: (ttyACM0) closing serial device...
Oct 1 10:37:54 lap-tea-cup01 modem-manager: Removed modem /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1
Oct 1 10:37:54 lap-tea-cup01 NetworkManager: <info> (ttyACM0): now unmanaged
Oct 1 10:37:54 lap-tea-cup01 NetworkManager: <info> (ttyACM0): device state change: 3 -> 1 (reason 36)
Oct 1 10:37:54 lap-tea-cup01 NetworkManager: <info> (ttyACM0): cleaning up...
Oct 1 10:37:54 lap-tea-cup01 NetworkManager: <info> (ttyACM0): taking down device.
Oct 1 10:37:54 lap-tea-cup01 NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Oct 1 10:37:54 lap-tea-cup01 NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Oct 1 10:37:55 lap-tea-cup01 kernel: [ 121.941277] padlock: VIA PadLock not detected.
Oct 1 10:37:55 lap-tea-cup01 kernel: [ 642.988037] usb 2-1: new full speed USB device using uhci_hcd and address 2
Oct 1 10:37:55 lap-tea-cup01 kernel: [ 643.147189] usb 2-1: configuration #1 chosen from 1 choice
Oct 1 10:37:55 lap-tea-cup01 kernel: [ 643.225121] cdc_acm 2-1:1.0: ttyACM0: USB ACM device
Oct 1 10:37:55 lap-tea-cup01 kernel: [ 643.228208] usbcore: registered new interface driver cdc_acm
Oct 1 10:37:55 lap-tea-cup01 kernel: [ 643.228682] cdc_acm: v0.26:USB Abstract ...

Read more...

Revision history for this message
darko (darko2) wrote :

I'm confirming the bug on Lenovo SL500.

Revision history for this message
Niklas Herder (herder) wrote :

Also confirming on an Asus EEE 901, with a Globetrotter HSDPA modem.

The connecton never goes up, but instead fails with these messages in syslog:

Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) starting connection 'Tele2/Comviq Default'
Oct 7 09:56:09 watchika NetworkManager: <info> (hso0): device state change: 3 -> 4 (reason 0)
Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) Stage 1 of 5 (Device Prepare) started...
Oct 7 09:56:09 watchika NetworkManager: <info> (hso0): device state change: 4 -> 6 (reason 0)
Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) Stage 1 of 5 (Device Prepare) complete.
Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) Stage 1 of 5 (Device Prepare) started...
Oct 7 09:56:09 watchika NetworkManager: <info> (hso0): device state change: 6 -> 4 (reason 0)
Oct 7 09:56:09 watchika NetworkManager: <info> Activation (hso0) Stage 1 of 5 (Device Prepare) complete.
Oct 7 09:56:10 watchika NetworkManager: <WARN> stage1_prepare_done(): GSM modem connection failed: SIM PUK required
Oct 7 09:56:10 watchika NetworkManager: <info> (hso0): device state change: 4 -> 9 (reason 1)
Oct 7 09:56:10 watchika NetworkManager: <info> Marking connection 'Tele2/Comviq Default' invalid.
Oct 7 09:56:10 watchika NetworkManager: Tried to set deprecated property gsm/puk
Oct 7 09:56:10 watchika NetworkManager: <info> Activation (hso0) failed.
Oct 7 09:56:10 watchika NetworkManager: <info> (hso0): device state change: 9 -> 3 (reason 0)
Oct 7 09:56:10 watchika NetworkManager: <info> (hso0): deactivating device (reason: 0).

Revision history for this message
Alessio "Spinus" Moscatello (spinus) wrote :
Download full text (5.6 KiB)

I've a similar problem with a Motorola K3 (identified as "22b8:6402 Motorola PCS" by lsusb)
I think that this is probably a regression of NM 0.8!

Oct 7 17:57:27 ubuntu kernel: [ 549.052022] usb 2-3: new full speed USB device using ohci_hcd and address 3
Oct 7 17:57:27 ubuntu modem-manager: (ttyACM0) opening serial device...
Oct 7 17:57:27 ubuntu modem-manager: (ttyACM0): probe requested by plugin 'Generic'
Oct 7 17:57:33 ubuntu modem-manager: (ttyACM0) closing serial device...
Oct 7 17:57:33 ubuntu modem-manager: (Generic): GSM modem /sys/devices/pci0000:00/0000:00:13.0/usb2/2-3 claimed port ttyACM0
Oct 7 17:57:33 ubuntu modem-manager: Added modem /sys/devices/pci0000:00/0000:00:13.0/usb2/2-3
Oct 7 17:57:33 ubuntu modem-manager: Exported modem /sys/devices/pci0000:00/0000:00:13.0/usb2/2-3 as /org/freedesktop/ModemManager/Modems/0
Oct 7 17:57:33 ubuntu NetworkManager: <info> (ttyACM0): new GSM device (driver: 'cdc_acm')
Oct 7 17:57:33 ubuntu NetworkManager: <info> (ttyACM0): exported as /org/freedesktop/NetworkManager/Devices/1
Oct 7 17:57:33 ubuntu NetworkManager: <info> (ttyACM0): now managed
Oct 7 17:57:33 ubuntu NetworkManager: <info> (ttyACM0): device state change: 1 -> 2 (reason 2)
Oct 7 17:57:33 ubuntu NetworkManager: <info> (ttyACM0): deactivating device (reason: 2).
Oct 7 17:57:33 ubuntu NetworkManager: flush_routes: assertion `iface_idx >= 0' failed
Oct 7 17:57:33 ubuntu NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed
Oct 7 17:57:33 ubuntu NetworkManager: <info> (ttyACM0): device state change: 2 -> 3 (reason 0)
Oct 7 17:57:48 ubuntu NetworkManager: user_connection_updated_cb: assertion `old_connection != NULL' failed
Oct 7 17:57:48 ubuntu NetworkManager: <info> Activation (ttyACM0) starting connection 'Vodafone Default'
Oct 7 17:57:48 ubuntu NetworkManager: <info> (ttyACM0): device state change: 3 -> 4 (reason 0)
Oct 7 17:57:48 ubuntu NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) scheduled...
Oct 7 17:57:48 ubuntu NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) started...
Oct 7 17:57:48 ubuntu NetworkManager: <info> Activation (ttyACM0) Stage 1 of 5 (Device Prepare) complete.
Oct 7 17:57:48 ubuntu modem-manager: (ttyACM0) opening serial device...
Oct 7 17:57:48 ubuntu modem-manager: Got failure code 100: Unknown error
Oct 7 17:57:48 ubuntu NetworkManager: <WARN> stage1_prepare_done(): GSM modem connection failed: Unknown error
Oct 7 17:57:48 ubuntu NetworkManager: <info> (ttyACM0): device state change: 4 -> 9 (reason 1)
Oct 7 17:57:48 ubuntu NetworkManager: <info> Marking connection 'Vodafone Default' invalid.
Oct 7 17:57:48 ubuntu NetworkManager: Tried to set deprecated property gsm/puk
Oct 7 17:57:48 ubuntu NetworkManager: <info> Activation (ttyACM0) failed.
Oct 7 17:57:48 ubuntu NetworkManager: <info> (ttyACM0): device state change: 9 -> 3 (reason 0)
Oct 7 17:57:48 ubuntu NetworkManager: <info> (ttyACM0): deactivating device (reason: 0).
Oct 7 17:57:48 ubuntu NetworkManager: flush_routes: assertion `iface_idx >= 0' failed
Oct 7 17:57:48 ubuntu NetworkManager: flush_addresses: assertion `iface_idx >= 0' faile...

Read more...

Changed in network-manager (Ubuntu):
status: New → Confirmed
summary: - Many problems with 3G in Karmic
+ Cannot connect using 3G/HDSPA modem (NM 0.8 regression ?)
Alessio "Spinus" Moscatello (spinus)
summary: - Cannot connect using 3G/HDSPA modem (NM 0.8 regression ?)
+ Cannot connect using 3G/HDSPA modem (Karmic - NM 0.8 regression ?)
Revision history for this message
Alexander Sack (asac) wrote : Re: Cannot connect using 3G/HDSPA modem (Karmic - NM 0.8 regression ?)

could you please attach what we have documented here: https://wiki.ubuntu.com/DebuggingModemmanager ? thanks!

affects: network-manager (Ubuntu) → modemmanager (Ubuntu)
Changed in modemmanager (Ubuntu):
assignee: nobody → Alexander Sack (asac)
summary: - Cannot connect using 3G/HDSPA modem (Karmic - NM 0.8 regression ?)
+ F3507G - Cannot connect using 3G/HDSPA modem (Karmic - NM 0.8 regression
+ ?)
tags: added: mbm
Changed in modemmanager (Ubuntu):
importance: Undecided → Medium
Revision history for this message
Alexander Sack (asac) wrote :

niklas, can you plesae open a new bug against modemmanager package, because you don't have a ericsson modem (e.g. f3507g) ... repost your log there and also read the DebuggingModemmanager link from above.

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

note: i will only deal with the original issue here. everyone else open a new bug since oyu are using a different modem card that uses slightly different code. Thanks!

Revision history for this message
ignasi (igp-oenus) wrote :

I'm attaching the logs as requested. Also note that mm-test.py may have exited abnormally. Here's the final output of mm-test-py. Thanks very much to you.

Scanning...
simyo: available (UMTS)
vodafone ES: available (GSM)
Yoigo: available (UMTS)
vodafone ES: available (UMTS)
movistar: available (GSM)
simyo: available (GSM)
movistar: available (UMTS)

Traceback (most recent call last):
  File "./mm-test.py", line 236, in <module>
    modem.Enable(False)
  File "/usr/lib/pymodules/python2.6/dbus/proxies.py", line 140, in __call__
    **keywords)
  File "/usr/lib/pymodules/python2.6/dbus/connection.py", line 620, in call_blocking
    message, timeout)
dbus.exceptions.DBusException: org.freedesktop.ModemManager.Modem.Gsm.Unknown: Unknown error
ignasi@Caladan:~$

Revision history for this message
Alessio "Spinus" Moscatello (spinus) wrote :

Ok, I'll open a new bug against my K3 as soon I'll be able to get mm-test.py working..in fact I've the same issue of Ignasi :(

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

modemmanager (0.2.git.20091014t233208.16f3e00-0ubuntu1) karmic; urgency=low

  New upstream snapshot: 2009-10-14 21:33:52 (GMT)
  + 16f3e00f3438507aee06ffcaee560e337b8e8279
  - gsm: fix unsolicited registration by calling the statemachine callback
    info (LP: #416893)
  - mbm: use generic get_signal_quality implementation rather than our own
    CIND based one - helps to fix LP: #449037 as its less error prone
  - mbm: implement AT*ENAP polling; needed for some mbm devices, like m300 (LP: #442967)
  - gsm: don't issue CFUN=0 by default (LP: #438150)
  - mbm: fix disable after 3b19a85727458821f5df20153f8c04bc7717ba30 (LP: #447347, #438150)
  - nokia: fix class property overrides to stop modemmanager from sending AT+CFUN (LP: #450256)

 -- Alexander Sack < <email address hidden>> Thu, 15 Oct 2009 02:03:37 +0200

Changed in modemmanager (Ubuntu):
status: Confirmed → Fix Released
Revision history for this message
ignasi (igp-oenus) wrote :

Alexander, thanks so much for your fix. It works fine now.

Ignacio

Revision history for this message
konkordpl (kb-kab) wrote :
Download full text (5.5 KiB)

I have Novatel Merlin U-630 and modemmanager doesn't work well with it.
I have the newest version of modemmanager, and still got the same error: SIM failure
Don't know what to do! Could you help me?

from mm-test.py:
GSM modem
Driver: 'serial_cs'
Modem device: '/sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0'
Data device: 'ttyS2'
Vendor: Novatel Wireless Incorporated
Model: Merlin U630 (HW REV Rev 2)
Version: 14.2-14.2 [2005-08-19 22:03:28]
IMEI: <private>
IMSI: <private>
Signal quality: 67
Scanning...
Era: available (GSM)
Era: current (UMTS)
Unknown: available (UMTS)
IDEA, PL IDEA, PL 03: forbidden (GSM)
IDEA, PL IDEA, PL 03: forbidden (UMTS)
Unknown: available (GSM)
Plus GSM: forbidden (GSM)
Plus GSM: forbidden (UMTS)
Error connecting: org.freedesktop.ModemManager.Modem.Gsm.SimFailure: SIM failure

from syslog:
Dec 23 17:22:10 wallace modem-manager: Got failure code 100: Unknown error
Dec 23 17:22:11 wallace modem-manager: (ttyS2) closing serial device...
Dec 23 17:22:11 wallace modem-manager: (Generic): GSM modem /sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0 claimed port ttyS2
Dec 23 17:22:11 wallace modem-manager: Added modem /sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0
Dec 23 17:22:11 wallace modem-manager: Exported modem /sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0 as /org/freedesktop/ModemManager/Modems/1
Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): new GSM device (driver: 'serial_cs')
Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): exported as /org/freedesktop/NetworkManager/Devices/4
Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): now managed
Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): device state change: 1 -> 2 (reason 2)
Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): deactivating device (reason: 2).
Dec 23 17:22:12 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Dec 23 17:22:12 wallace NetworkManager: <info> (ttyS2): device state change: 2 -> 3 (reason 0)
Dec 23 17:22:12 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Dec 23 17:22:18 wallace modem-manager: (ttyS3) closing serial device...
Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) starting connection 'Heyah Domyślne 1'
Dec 23 17:22:32 wallace NetworkManager: <info> (ttyS2): device state change: 3 -> 4 (reason 0)
Dec 23 17:22:32 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) Stage 1 of 5 (Device Prepare) scheduled...
Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) Stage 1 of 5 (Device Prepare) started...
Dec 23 17:22:32 wallace NetworkManager: <info> (ttyS2): device state change: 4 -> 6 (reason 0)
Dec 23 17:22:32 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) Stage 1 of 5 (Device Prepar...

Read more...

Revision history for this message
Alexander Sack (asac) wrote : Re: [Bug 434737] Re: F3507G - Cannot connect using 3G/HDSPA modem (Karmic - NM 0.8 regression ?)
Download full text (5.7 KiB)

SIM failure feels like a broken SIM ... maybe its not properly inserted?

On Wed, Dec 23, 2009 at 04:31:13PM -0000, konkordpl wrote:
> I have Novatel Merlin U-630 and modemmanager doesn't work well with it.
> I have the newest version of modemmanager, and still got the same error: SIM failure
> Don't know what to do! Could you help me?
>
> from mm-test.py:
> GSM modem
> Driver: 'serial_cs'
> Modem device: '/sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0'
> Data device: 'ttyS2'
> Vendor: Novatel Wireless Incorporated
> Model: Merlin U630 (HW REV Rev 2)
> Version: 14.2-14.2 [2005-08-19 22:03:28]
> IMEI: <private>
> IMSI: <private>
> Signal quality: 67
> Scanning...
> Era: available (GSM)
> Era: current (UMTS)
> Unknown: available (UMTS)
> IDEA, PL IDEA, PL 03: forbidden (GSM)
> IDEA, PL IDEA, PL 03: forbidden (UMTS)
> Unknown: available (GSM)
> Plus GSM: forbidden (GSM)
> Plus GSM: forbidden (UMTS)
> Error connecting: org.freedesktop.ModemManager.Modem.Gsm.SimFailure: SIM failure
>
> from syslog:
> Dec 23 17:22:10 wallace modem-manager: Got failure code 100: Unknown error
> Dec 23 17:22:11 wallace modem-manager: (ttyS2) closing serial device...
> Dec 23 17:22:11 wallace modem-manager: (Generic): GSM modem /sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0 claimed port ttyS2
> Dec 23 17:22:11 wallace modem-manager: Added modem /sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0
> Dec 23 17:22:11 wallace modem-manager: Exported modem /sys/devices/pci0000:00/0000:00:1e.0/0000:02:02.0 as /org/freedesktop/ModemManager/Modems/1
> Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): new GSM device (driver: 'serial_cs')
> Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): exported as /org/freedesktop/NetworkManager/Devices/4
> Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): now managed
> Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): device state change: 1 -> 2 (reason 2)
> Dec 23 17:22:11 wallace NetworkManager: <info> (ttyS2): deactivating device (reason: 2).
> Dec 23 17:22:12 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
> Dec 23 17:22:12 wallace NetworkManager: <info> (ttyS2): device state change: 2 -> 3 (reason 0)
> Dec 23 17:22:12 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
> Dec 23 17:22:18 wallace modem-manager: (ttyS3) closing serial device...
> Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) starting connection 'Heyah Domyślne 1'
> Dec 23 17:22:32 wallace NetworkManager: <info> (ttyS2): device state change: 3 -> 4 (reason 0)
> Dec 23 17:22:32 wallace NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
> Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) Stage 1 of 5 (Device Prepare) scheduled...
> Dec 23 17:22:32 wallace NetworkManager: <info> Activation (ttyS2) Stage 1 of 5 (Device Prepare) started...
> Dec 23 17:22:32 wallace NetworkManager: <info> (ttyS2): device state change: 4 -> 6 (reason 0)
> Dec 23 17:22:32 wallace NetworkManager: <info> Unma...

Read more...

Revision history for this message
konkordpl (kb-kab) wrote :

Nope, SIM is fine. Modem works perfectly with wvdial.
I have this problem with EVERY SIM card when I'm using modemmanager.

Revision history for this message
Mathias Hasselmann (hasselmm) wrote :

Can this fix for Redhat applied to Ubuntu?

https://bugzilla.redhat.com/show_bug.cgi?id=583691#c13

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.