Bug 534230

Summary: Impossible to connect a mobile broadband device to internet with (k)networkmanager.
Product: [openSUSE] openSUSE 11.2 Reporter: Forgotten User gj9_3EwFEj <forgotten_gj9_3EwFEj>
Component: KDE4 ApplicationsAssignee: Will Stephenson <wstephenson>
Status: RESOLVED FIXED QA Contact: E-mail List <qa-bugs>
Severity: Major    
Priority: P5 - None CC: david.maillists, forgotten_2Bw2fCSUmf, richard, wstephenson, zajec5
Version: Milestone 7Flags: coolo: SHIP_STOPPER-
Target Milestone: RC 2   
Hardware: x86-64   
OS: openSUSE 11.2   
Whiteboard:
Found By: --- Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: Network Manager log containing all connection attempts made today.

Description Forgotten User gj9_3EwFEj 2009-08-25 21:46:21 UTC
User-Agent:       Mozilla/5.0 (X11; U; Linux x86_64; en-GB; rv:1.9.1.2) Gecko/20090730 SUSE/3.5.2-2.4 Firefox/3.5.2

I have two 3G modems, the first a Option icon 225 and the second a Huawei E180. I have never with opensuse 11.2 through KNM been able to connect any of them to the Internet. Both are detected by networkmanager and becomes configurable inside KNM however when trying to connect they seem just to sit there, knm says either 'configuring device' or 'waiting for authorization'. I have also a computer running ubuntu 9.04 where the Huawei modem *just works* , I have compared all values between the two system and they seem to be identical. Running MS6, freshly installed.

Output from a connection attempt with the Option icon 225

Aug 24 21:44:35 lillevide NetworkManager: <info>  Found new GSM modem device 'hso0' (driver: 'hso').                                                          
Aug 24 21:44:35 lillevide NetworkManager: <info>  (hso0): exported as /org/freedesktop/Hal/devices/usb_device_af0_6971_Serial_Number_if0_serial_unknown_0     
Aug 24 21:44:35 lillevide NetworkManager: <info>  Found new GSM modem device '/dev/ttyHS1' (driver: 'hso').                                                   
Aug 24 21:44:35 lillevide NetworkManager: <info>  (/dev/ttyHS1): exported as /org/freedesktop/Hal/devices/usb_device_af0_6971_Serial_Number_if0_serial_unknown
_1                                                                                                                                                            
Aug 24 21:44:40 lillevide NetworkManager: <info>  (hso0): device state change: 1 -> 2                                                                         
Aug 24 21:44:40 lillevide NetworkManager: <info>  (hso0): deactivating device (reason: 2).                                                                    
Aug 24 21:44:40 lillevide NetworkManager: <info>  (/dev/ttyHS1): device state change: 1 -> 2                                                                  
Aug 24 21:44:40 lillevide NetworkManager: <info>  (/dev/ttyHS1): deactivating device (reason: 2).                                                             
Aug 24 21:44:40 lillevide NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed                                     
Aug 24 21:44:40 lillevide NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed
Aug 24 21:44:40 lillevide NetworkManager: <info>  (hso0): device state change: 2 -> 3
Aug 24 21:44:40 lillevide NetworkManager: <info>  (/dev/ttyHS1): device state change: 2 -> 3
Aug 24 21:44:50 lillevide NetworkManager: <info>  Activation (hso0) starting connection 'Telenor'
Aug 24 21:44:50 lillevide NetworkManager: <info>  (hso0): device state change: 3 -> 4
Aug 24 21:44:50 lillevide NetworkManager: <info>  Activation (hso0) Stage 1 of 5 (Device Prepare) scheduled...
Aug 24 21:44:50 lillevide NetworkManager: <info>  Activation (hso0) Stage 1 of 5 (Device Prepare) started...
Aug 24 21:44:50 lillevide NetworkManager: <info>  (hso0): device state change: 4 -> 6
Aug 24 21:44:50 lillevide NetworkManager: <info>  Activation (hso0) Stage 1 of 5 (Device Prepare) complete.
Aug 24 21:44:50 lillevide NetworkManager: <WARN>  update_one_setting(): Failed to update connection secrets: 1 ipv4
Aug 24 21:44:50 lillevide NetworkManager: real_connection_secrets_updated: assertion `caller == SECRETS_CALLER_GSM' failed
Aug 24 21:48:53 lillevide NetworkManager: <info>  (hso0): device state change: 6 -> 3
Aug 24 21:48:53 lillevide NetworkManager: <info>  (hso0): deactivating device (reason: 39).
Aug 24 21:48:57 lillevide NetworkManager: <info>  Activation (/dev/ttyHS1) starting connection 'Telenor'
Aug 24 21:48:57 lillevide NetworkManager: <info>  (/dev/ttyHS1): device state change: 3 -> 4
Aug 24 21:48:57 lillevide NetworkManager: <info>  Activation (/dev/ttyHS1) Stage 1 of 5 (Device Prepare) scheduled...
Aug 24 21:48:57 lillevide NetworkManager: <info>  Activation (/dev/ttyHS1) Stage 1 of 5 (Device Prepare) started...
Aug 24 21:48:57 lillevide NetworkManager: <info>  Activation (/dev/ttyHS1) Stage 1 of 5 (Device Prepare) complete.
Aug 24 21:50:14 lillevide NetworkManager: <WARN>  stage1_prepare_done(): GSM modem connection failed: Serial command timed out
Aug 24 21:50:14 lillevide NetworkManager: <info>  (/dev/ttyHS1): device state change: 4 -> 9
Aug 24 21:50:14 lillevide NetworkManager: <info>  Marking connection 'Telenor' invalid.
Aug 24 21:50:14 lillevide NetworkManager: <info>  Activation (/dev/ttyHS1) failed.
Aug 24 21:50:14 lillevide NetworkManager: <info>  (/dev/ttyHS1): device state change: 9 -> 3
Aug 24 21:50:14 lillevide NetworkManager: <info>  (/dev/ttyHS1): deactivating device (reason: 0).
Aug 24 21:50:14 lillevide NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed
Aug 24 21:50:14 lillevide NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed


Reproducible: Always

Steps to Reproduce:
1.
2.
3.
Comment 1 Will Stephenson 2009-08-30 10:13:33 UTC
Can you compare between nm-applet and knetworkmanager on openSUSE? ubuntu ships a different version of NetworkManager.

see 
http://userbase.kde.org/NetworkManagement#It.27s_All_KDE.27s_Fault.21

for details
Comment 2 Forgotten User gj9_3EwFEj 2009-09-01 20:37:57 UTC
Sorry for the delay. 

I just ran a quick test and i would say nm-applet is even worse. The Option device have two leds with three modes indicating the device status.

Leds flashing -- device attached.
Leds fade in and out -- device registered with provider.
Leds stay lit -- device connected.

With knetworkmanager at least the device entered stage two, meaning was is able to get the device registered with the proviced, nm-applet does not even come that far. I started nm-applet from a konsole and got this output when trying to connect.
             
** (nm-applet:3038): WARNING **: Invalid connection: 'NMSettingConnection' / 'id' invalid: 2

** (nm-applet:3038): WARNING **: Invalid connection: 'NMSettingConnection' / 'uuid' invalid: 2

** (nm-applet:3038): WARNING **: Invalid connection: 'NMSettingConnection' / 'type' invalid: 2

** (nm-applet:3038): WARNING **: Invalid connection: 'NMSettingConnection' / 'type' invalid: 3

** (nm-applet:3038): WARNING **: Invalid connection: 'NMSettingConnection' / 'type' invalid: 3

** (nm-applet:3038): WARNING **: Invalid connection: 'NMSettingConnection' / 'type' invalid: 3
Comment 3 Forgotten User gj9_3EwFEj 2009-09-12 12:39:59 UTC
Hey, someone seem to have done their homework ;-) Now with MS7 I have actually managed to connect both my devices to the internet a few times. It's far from every time a connection attempt succeeds I would say about 30% actually does, still I see that as a major improvement.

A few observations. 

1) Sometimes for no apparent reason the Manage connection dialogue appears missing both device pin and connection password. Pressing cancel and edit the current connection profile I see all needed secrets are actually is stored in the profile. When this happens the only way I have found to make KNM reuse the original profile data is actually to reboot the whole machine. Restarting the network in my case only makes the device undetected upon reattaching. 

2)  Sometime a successful connection is not notived by KNM. The device leds indicates that it is connected still KNM only showing status "Awaiting Authorization"

3) Quite often also on a succeeded connection /etc/resolv.conf remains empty.

Output when that happens, further down..

I will attach the whole log from all my connection attempts today but successful and unsuccessful. The Connection 'Tre' is the Huawei device and the connection 'Telenor' the Option. 

If there is anything more I can do please let me know.
 

## Connection when resolv.conf remains empty.
Sep 12 13:42:30 lillevide NetworkManager: <info>  Activation (ttyUSB0) starting connection 'Tre'                                          
Sep 12 13:42:30 lillevide NetworkManager: <info>  (ttyUSB0): device state change: 3 -> 4 (reason 0)                                       
Sep 12 13:42:30 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...                         
Sep 12 13:42:30 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...                           
Sep 12 13:42:30 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.                            
Sep 12 13:42:38 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
Sep 12 13:42:38 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
Sep 12 13:42:38 lillevide NetworkManager: <info>  (ttyUSB0): device state change: 4 -> 5 (reason 0)
Sep 12 13:42:38 lillevide NetworkManager: <info>  Starting pppd connection
Sep 12 13:42:38 lillevide NetworkManager: <debug> [1252755758.160512] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute user dummy ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/0 plugin /usr/lib64/pppd/2.4.4/nm-pppd-plugin.so
Sep 12 13:42:38 lillevide NetworkManager: <debug> [1252755758.192931] nm_ppp_manager_start(): ppp started with pid 7431
Sep 12 13:42:38 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
Sep 12 13:42:38 lillevide NetworkManager: <info>  (ttyUSB0): device state change: 5 -> 6 (reason 0)
Sep 12 13:42:38 lillevide NetworkManager: <WARN>  update_one_setting(): Failed to update connection secrets: 1 ipv4
Sep 12 13:42:38 lillevide NetworkManager: <info>  (ttyUSB0): device state change: 6 -> 7 (reason 0)
Sep 12 13:42:48 lillevide NetworkManager: <info>  PPP manager(IP Config Get) reply received.
Sep 12 13:42:48 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP Configure Get) scheduled...
Sep 12 13:42:48 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP Configure Get) started...
Sep 12 13:42:48 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) scheduled...
Sep 12 13:42:48 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP Configure Get) complete.
Sep 12 13:42:48 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) started...
Sep 12 13:42:49 lillevide NetworkManager: <info>  (ttyUSB0): device state change: 7 -> 8 (reason 0)
Sep 12 13:42:49 lillevide NetworkManager: <debug> [1252755769.015184] run_netconfig(): Spawning '/sbin/netconfig modify --service NetworkManager'
Sep 12 13:42:49 lillevide NetworkManager: <info>  Clearing nscd hosts cache.
Sep 12 13:42:49 lillevide NetworkManager: <info>  Policy set 'Tre' (ppp0) as default for routing and DNS.
Sep 12 13:42:49 lillevide NetworkManager: <info>  Activation (ttyUSB0) successful, device activated.
Sep 12 13:42:49 lillevide NetworkManager: <info>  Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) complete.
Sep 12 13:42:49 lillevide nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/autofs' exited with error status 1.
Sep 12 13:42:49 lillevide nm-dispatcher.action: Script '/etc/NetworkManager/dispatcher.d/nfs' exited with error status 2.

lillevide:~ # more /etc/resolv.conf
# Generated by NetworkManager
Comment 4 Forgotten User gj9_3EwFEj 2009-09-12 12:43:04 UTC
Created attachment 317985 [details]
Network Manager log containing all connection attempts made today.
Comment 5 Will Stephenson 2009-09-15 10:16:47 UTC
Thanks for the detailed testing 

1) was my fault, fixed in Factory 

2) I agree, we're looking at a NM problem not a knetworkmanager problem.  Raymond Wooninck is building some preliminary NM 0.8pre packages to see how trunk NM behaves, but I doubt we will get these into 11.1, unfortunately.

3) Also an NM problem

Reassigning to NetworkManager for 2 and 3.
Comment 6 David Garcia 2009-10-06 01:20:07 UTC
I cannot connect to a 3G network with knetworkmanager: sometimes it does nothing, sometimes it connects but fails to write in /etc/resolv.conf.

But I can connect flawlessly with nm-applet, even with the PIN enabled in the SIM card.

By the way, while the bug is fixed, do you happen to know how I can configure KDE to autostart nm-applet instead of knetworkmanager? I am using factory and KDE.

Thank you very much.
Comment 7 Tambet Ingo 2009-10-06 06:06:00 UTC
Edit /etc/xdg/autostart/nm-applet.desktop and remove the following line:

OnlyShowIn=GNOME;
Comment 8 Will Stephenson 2009-10-06 08:53:35 UTC
David, since you _can_ connect with nm-applet but not with knetworkmanager, can you show me the dbus output for your 3G connection with nm-applet and with knetworkmanager?  If I can see what knm is doing differently I can fix it relatively quickly.
Comment 9 David Garcia 2009-10-06 16:05:11 UTC
OK, William. Can you please tell me how to see such dbus outputs?
Comment 10 Will Stephenson 2009-10-06 20:14:09 UTC
see 

http://userbase.kde.org/NetworkManagement#It.27s_All_KDE.27s_Fault.21

for instructions
Comment 11 David Garcia 2009-10-07 15:59:49 UTC
Well, first of all I must say that I connected with knetworkmanager, but it wrote nothing on /etc/resolv.conf. I could still navigate if I put the *numeric* URL in Firefox. So I disconnected, deleted /resolv.conf and tried to connect again. At that moment, knetworkmanager did nothing, not even did it try to connect.

With nm-applet I sometimes have the same problem about empty /etc/resolv.conf, but I disconnect, remove /etc/resolv.conf, try to connect again, and nm-applet does try to connect again. Sometimes I have to repeat the process two or three times, but the DNSs are written on /etc/resolv.conf sooner or later, so the connection eventually becomes successful.

So the point may be an initial error with NetworkManager not writing the DNSs in /etc/resolv.conf (I will open a bug about that); then knetworkmanager would not allow another go, but nm-applet allows it.

Anyway, the dbus outputs are (with some output obscured for privacy):

knetworkmanager (when I try to connect a second time but 
knetworkmanager does nothing):

qdbus --system --literal org.freedesktop.NetworkManagerUserSettings /org/freedesktop/NetworkManagerSettings/3 org.freedesktop.NetworkManagerSettings.Connection.GetSettings                                                                                                                                                                        
[Argument: a{sa{sv}} {"connection" = [Argument: a{sv} {"autoconnect" = [Variant(bool): false], "id" = [Variant(QString): "*****"], "timestamp" = [Variant(uint): 1254931130], "type" = [Variant(QString): "gsm"], "uuid" = [Variant(QString): "********-*****-****-****-************"]}], "gsm" = [Argument: a{sv} {"apn" = [Variant(QString): "gprs-service.com"], "number" = [Variant(QString): "*99#"]}], "ppp" = [Argument: a{sv} {"baud" = [Variant(uint): 0], "crtscts" = [Variant(bool): false], "lcp-echo-failure" = [Variant(uint): 0], "lcp-echo-interval" = [Variant(uint): 0], "mppe-stateful" = [Variant(bool): false], "mru" = [Variant(uint): 0], "mtu" = [Variant(uint): 0], "no-vj-comp" = [Variant(bool): false], "noauth" = [Variant(bool): false], "nobsdcomp" = [Variant(bool): false], "nodeflate" = [Variant(bool): false], "refuse-chap" = [Variant(bool): false], "refuse-eap" = [Variant(bool): false], "refuse-mschap" = [Variant(bool): false], "refuse-mschapv2" = [Variant(bool): false], "refuse-pap" = [Variant(bool): false], "require-mppe" = [Variant(bool): false], "require-mppe-128" = [Variant(bool): false]}], "serial" = [Argument: a{sv} {"baud" = [Variant(uint): 0], "bits" = [Variant(uint): 0], "parity" = [Variant(QString): ""], "send-delay" = [Variant(qulonglong): 0], "stopbits" = [Variant(uint): 0]}]}]

nm-applet (when I reconnected a second or third time and, finally, the DNSs are written in /etc/resolv.conf):

$ qdbus --system --literal org.freedesktop.NetworkManagerUserSettings /org/freedesktop/NetworkManagerSettings/4 org.freedesktop.NetworkManagerSettings.Connection.GetSettings
[Argument: a{sa{sv}} {"ppp" = [Argument: a{sv} {}], "ipv4" = [Argument: a{sv} {"addresses" = [Variant: [Argument: aau {}]], "dns" = [Variant: [Argument: au {}]], "routes" = [Variant: [Argument: aau {}]], "method" = [Variant(QString): "auto"]}], "gsm" = [Argument: a{sv} {"number" = [Variant(QString): "*99#"], "apn" = [Variant(QString): "gprs-service.com"]}], "connection" = [Argument: a{sv} {"uuid" = [Variant(QString): "********-****-****-****-************"], "autoconnect" = [Variant(bool): false], "id" = [Variant(QString): "Auto Mobile Broadband (GSM) connection"], "type" = [Variant(QString): "gsm"], "timestamp" = [Variant(qulonglong): 1254929316]}], "serial" = [Argument: a{sv} {"baud" = [Variant(uint): 115200]}]}]
Comment 12 David Garcia 2009-10-07 16:21:15 UTC
As promised, I opened another bug on https://bugzilla.novell.com/show_bug.cgi?id=545035 about NetWorkManager seldom writing the DNSs in /etc/resolv.conf.

But still, this bug here about knetworkmanager not allowing a second connection should be fixed as well.

Thank you.
Comment 13 Will Stephenson 2009-10-19 22:25:53 UTC
*** Bug 533253 has been marked as a duplicate of this bug. ***
Comment 14 Will Stephenson 2009-10-19 22:28:32 UTC
*** Bug 547760 has been marked as a duplicate of this bug. ***
Comment 15 Forgotten User gj9_3EwFEj 2009-10-21 20:00:20 UTC
Just some feedback. I have been away from home quite a bit lately and therefor also been using my mobile broadband very much. It actually works quite well. I to experience the "have to dial twice" phenomenon where the first connection attempts always after 20 sec or so needs to be canceled and the second always succeed. What is quite evident and annoying is the empty resolv.conf, sometime I have had to disconnect and reconnect as much as five times before I get my DNS servers written to the file. Do you have all information needed, if not let me know.

Now running RC1
Comment 16 Will Stephenson 2009-10-22 19:55:08 UTC
I've added some code to remove the empty/false/zero settings seen in David's trace from comment #13, and i can now always connect with my old GSM option card.

The resolv.conf problems remain, especially if i have Ethernet and GSM up (default route on eth0) then disconnect eth0, switching the default route to the GSM ppp0 - an empty resolv.conf is written instead of the DNS values obtained from GSM.  But that is #545035, #544195 #546213 or #509509 depending on which way you look.
Comment 17 Forgotten User 2Bw2fCSUmf 2009-10-27 07:15:39 UTC
Confirm "have to dial twice" for Huawei Technologies Co., Ltd. E620 USB Modem (USB ID 12d1:1001) and 11.2 RC1.
Are there any fixes in the repos as this is marked RESOLVED?
Comment 18 Rafał Miłecki 2009-12-05 18:56:41 UTC
Will: I can see you were hardly working on KNetworkManager :)

I experience this bug describes using openSUSE 11.2 but that is because openSUSE contains old version of KNetworkManager (svn1043876). I compiled KNetworkManager from svn (rev 1058902) and don't see that bug anymore. However it may be hard to install version from svn as it needs Qt 4.6 (just for some animation effect I believe :(). Someone dropped compatibility with 4.5 by that. But good news is that bug is generally fixed :)

I also experience other bug with stage1_prepare_done warn that happens on reconnect try. But this should be resolved soon, see https://bugzilla.redhat.com/show_bug.cgi?id=541314 .