Bug 203584

Summary: Bluetooth support
Product: Network Management Reporter: putt1ck <cputtick>
Component: Mobile BroadbandAssignee: Will Stephenson <wstephenson>
Status: RESOLVED FIXED    
Severity: wishlist CC: bugs.kde, ict, lamarque, marcus
Priority: NOR    
Version: unspecified   
Target Milestone: ---   
Platform: Ubuntu   
OS: Linux   
Latest Commit: Version Fixed In:

Description putt1ck 2009-08-12 17:42:20 UTC
Version:            (using KDE 4.3.0)
OS:                Linux
Installed from:    Ubuntu Packages

Vanilla clean install Kubuntu 9.04 with KDE4.3 from Launchpad; add Blueman, bond phone. Interface insertion works correctly as indicated by widget. Correctly configured connection fails with "deactivating device (reason:0)". Will post entire daemon.log output for the events once relevant computer is connected to the Internet...

NB removing plasma network manager packages and installing old knetworkmanager and everything works as expected.
Comment 1 putt1ck 2009-08-12 17:48:34 UTC
Log entries from daemon.log with plasma-network-manager in charge:

Aug 12 18:16:59 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 1 of 5 (Device Prepare) complete.                                                                                           
Aug 12 18:17:10 lap735 NetworkManager: <WARN>  init_done(): Modem initialization timed out         
Aug 12 18:17:10 lap735 NetworkManager: <info>  (rfcomm0): device state change: 4 -> 9              
Aug 12 18:17:10 lap735 NetworkManager: <debug> [1250097430.002460] nm_serial_device_close(): Closing device 'rfcomm0'                                                                                 
Aug 12 18:17:10 lap735 NetworkManager: <info>  Marking connection 'Vodafone' invalid.              
Aug 12 18:17:10 lap735 NetworkManager: <info>  Activation (rfcomm0) failed.                        
Aug 12 18:17:10 lap735 NetworkManager: <info>  (rfcomm0): device state change: 9 -> 3              
Aug 12 18:17:10 lap735 NetworkManager: <info>  (rfcomm0): deactivating device (reason: 0).         
Aug 12 18:17:10 lap735 NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed                                                                                
Aug 12 18:17:10 lap735 NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed                                                                             
Aug 12 18:19:56 lap735 nm-system-settings:    SCPlugin-Ifupdown: devices removed (udi: /org/freedesktop/Hal/devices/rfcomm0)                                                                          
Aug 12 18:19:56 lap735 NetworkManager: <info>  (rfcomm0): now unmanaged                            
Aug 12 18:19:56 lap735 NetworkManager: <info>  (rfcomm0): device state change: 3 -> 1              
Aug 12 18:19:56 lap735 NetworkManager: <info>  (rfcomm0): cleaning up...                           
Aug 12 18:19:56 lap735 NetworkManager: <info>  (rfcomm0): taking down device.                      
Aug 12 18:25:16 lap735 bluetoothd[5845]: link_key_request (sba=00:1F:E2:F9:34:49, dba=00:1A:89:C3:AE:67)                                                                                              
Aug 12 18:25:18 lap735 NetworkManager: <info>  (rfcomm0): found serial port (udev:GSM  hal:)       
Aug 12 18:25:18 lap735 NetworkManager: <info>  (rfcomm0): deferring until all ports found          
Aug 12 18:25:19 lap735 nm-system-settings:    SCPlugin-Ifupdown: device added (udi: /org/freedesktop/Hal/devices/rfcomm0, iface: (null)): iface not found                                             
Aug 12 18:25:19 lap735 NetworkManager: <info>  (rfcomm0): found serial port (udev:GSM  hal:GSM)    
Aug 12 18:25:19 lap735 NetworkManager: <info>  (rfcomm0): new Modem device (driver: 'rfcomm')      
Aug 12 18:25:19 lap735 NetworkManager: <info>  (rfcomm0): exported as /org/freedesktop/Hal/devices/rfcomm0                                                                                            
Aug 12 18:25:23 lap735 NetworkManager: <info>  Re-checking deferred serial ports                   
Aug 12 18:25:24 lap735 NetworkManager: <info>  (rfcomm0): device state change: 1 -> 2              
Aug 12 18:25:24 lap735 NetworkManager: <info>  (rfcomm0): deactivating device (reason: 2).         
Aug 12 18:25:24 lap735 NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed                                                                                
Aug 12 18:25:24 lap735 NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed                      

10 minutes later, old knetworkmanager reinstated:

Aug 12 18:39:42 lap735 NetworkManager: <info>  (rfcomm0): found serial port (udev:GSM  hal:)       
Aug 12 18:39:42 lap735 NetworkManager: <info>  (rfcomm0): deferring until all ports found          
Aug 12 18:39:43 lap735 nm-system-settings:    SCPlugin-Ifupdown: device added (udi: /org/freedesktop/Hal/devices/rfcomm0, iface: (null)): iface not found                                             
Aug 12 18:39:43 lap735 NetworkManager: <info>  (rfcomm0): found serial port (udev:GSM  hal:GSM)    
Aug 12 18:39:43 lap735 NetworkManager: <info>  (rfcomm0): new Modem device (driver: 'rfcomm')      
Aug 12 18:39:43 lap735 NetworkManager: <info>  (rfcomm0): exported as /org/freedesktop/Hal/devices/rfcomm0                                                                                            
Aug 12 18:39:46 lap735 NetworkManager: <info>  Re-checking deferred serial ports                   
Aug 12 18:39:48 lap735 NetworkManager: <info>  (rfcomm0): device state change: 1 -> 2              
Aug 12 18:39:48 lap735 NetworkManager: <info>  (rfcomm0): deactivating device (reason: 2).         
Aug 12 18:39:48 lap735 NetworkManager: nm_system_device_flush_ip4_routes_with_iface: assertion `iface_idx >= 0' failed                                                                                
Aug 12 18:39:48 lap735 NetworkManager: nm_system_device_flush_ip4_addresses_with_iface: assertion `iface_idx >= 0' failed                                                                             
Aug 12 18:39:48 lap735 NetworkManager: <info>  (rfcomm0): device state change: 2 -> 3              
Aug 12 18:39:56 lap735 NetworkManager: <info>  Activation (rfcomm0) starting connection 'Vodafone' 
Aug 12 18:39:56 lap735 NetworkManager: <info>  (rfcomm0): device state change: 3 -> 4              
Aug 12 18:39:56 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 1 of 5 (Device Prepare) scheduled...                                                                                        
Aug 12 18:39:56 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 1 of 5 (Device Prepare) started...                                                                                          
Aug 12 18:39:56 lap735 NetworkManager: <debug> [1250098796.956279] nm_serial_device_open(): (rfcomm0) opening device...                                                                               
Aug 12 18:39:56 lap735 NetworkManager: Invalid baudrate '384000'                                   
Aug 12 18:39:56 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 1 of 5 (Device Prepare) complete.                                                                                           
Aug 12 18:39:57 lap735 NetworkManager: <info>  (rfcomm0): powering up...                           
Aug 12 18:39:57 lap735 NetworkManager: <info>  Registered on Home network                          
Aug 12 18:39:57 lap735 NetworkManager: <info>  Associated with network: +COPS: 0,2,"23415",2       
Aug 12 18:39:57 lap735 NetworkManager: <info>  Connected, Woo!                                     
Aug 12 18:39:57 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 2 of 5 (Device Configure) scheduled...                                                                                      
Aug 12 18:39:57 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 2 of 5 (Device Configure) starting...                                                                                       
Aug 12 18:39:57 lap735 NetworkManager: <info>  (rfcomm0): device state change: 4 -> 5              
Aug 12 18:39:57 lap735 NetworkManager: <info>  Starting pppd connection                            
Aug 12 18:39:57 lap735 NetworkManager: <debug> [1250098797.998649] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute user web rfcomm0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/4 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so                                                                       
Aug 12 18:39:58 lap735 NetworkManager: <debug> [1250098798.010895] nm_ppp_manager_start(): ppp started with pid 7856
Aug 12 18:39:58 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 2 of 5 (Device Configure) complete.
Aug 12 18:39:58 lap735 NetworkManager: <info>  (rfcomm0): device state change: 5 -> 6
Aug 12 18:39:58 lap735 NetworkManager: <info>  (rfcomm0): device state change: 6 -> 7
Aug 12 18:40:03 lap735 NetworkManager: <info>  PPP manager(IP Config Get) reply received.
Aug 12 18:40:03 lap735 NetworkManager: nm_ip4_config_add_nameserver: assertion `nameserver != s' failed
Aug 12 18:40:03 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 4 of 5 (IP Configure Get) scheduled...
Aug 12 18:40:03 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 4 of 5 (IP Configure Get) started...
Aug 12 18:40:03 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 5 of 5 (IP Configure Commit) scheduled...
Aug 12 18:40:03 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 4 of 5 (IP Configure Get) complete.
Aug 12 18:40:03 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 5 of 5 (IP Configure Commit) started...
Aug 12 18:40:04 lap735 NetworkManager: <info>  (rfcomm0): device state change: 7 -> 8
Aug 12 18:40:04 lap735 NetworkManager: <info>  Policy set 'Vodafone' (ppp0) as default for routing and DNS.
Aug 12 18:40:04 lap735 NetworkManager: <info>  Activation (rfcomm0) successful, device activated.
Aug 12 18:40:04 lap735 NetworkManager: <info>  Activation (rfcomm0) Stage 5 of 5 (IP Configure Commit) complete.

Any other logs of interest?
Comment 2 Will Stephenson 2009-08-15 07:37:12 UTC
I know about it but I have not done anything about bluetooth support yet.
Comment 3 putt1ck 2009-08-15 07:45:18 UTC
Odd - everything happens except an actual connection - the new interface is recognised, you can configure it; just it doesn't connect.
Comment 4 Lamarque V. Souza 2011-04-26 02:14:28 UTC
Soon Bluedevil will be updated to automatically call the wizard. Until then you can use networkmanagement_configshell command to register a bluetooth DUN (dial-up network) connection using the steps in here:

http://lamarque-lvs.blogspot.com/2011/04/plasma-nm-bluetooth-tethering.html