Bug 572340 - Bluetooth PAN connection don't established by NetworkManager
Summary: Bluetooth PAN connection don't established by NetworkManager
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: rawhide
Hardware: i686
OS: Linux
low
medium
Target Milestone: ---
Assignee: Dan Williams
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-03-10 22:21 UTC by Avalone
Modified: 2010-04-23 22:51 UTC (History)
2 users (show)

Fixed In Version: ModemManager-0.3-9.git20100409.fc12
Clone Of:
Environment:
Last Closed: 2010-04-23 22:51:02 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
FC12 NetworkManager PANU log (5.47 KB, application/octet-stream)
2010-03-10 22:21 UTC, Avalone
no flags Details
FC13 NetworkManager PANU log (4.81 KB, application/octet-stream)
2010-03-10 22:22 UTC, Avalone
no flags Details
FC13 NetworkManager 0.8.0-3 PANU log (4.64 KB, application/octet-stream)
2010-03-24 13:29 UTC, Avalone
no flags Details

Description Avalone 2010-03-10 22:21:07 UTC
Created attachment 399194 [details]
FC12 NetworkManager PANU log

Description of problem:
Successfully created through Bluetooth-applet PAN connection cannot be established.
(In FC12 this config work ok)
Nokia 6085 as bluetooth PAN device.

Version-Release number of selected component (if applicable):
FC13 alpha build
NetworkManager.i686  1:0.8.0-0.4.git20100211.fc13 

How reproducible:
Always

Steps to Reproduce:
1. Create PAN connection through Bluetooth applet and set checkbox "Use this device to connect to internet" at last page of wizard.
2. Click at created item (in Avalible section) in NetworkConnection applet
3.
  
Actual results:
Connection icon going through 2 stage (one and two greed dot circling), and then back to unconnected status. (See attached message log - FC13.log)

Expected results:
Connection established (See attached message log - FC12.log)

Additional info:

Comment 1 Avalone 2010-03-10 22:22:15 UTC
Created attachment 399195 [details]
FC13 NetworkManager PANU log

Comment 2 Fedora Update System 2010-03-24 09:38:20 UTC
NetworkManager-0.8.0-3.git20100323.fc13,ModemManager-0.3-4.git20100323.fc13 has been submitted as an update for Fedora 13.
http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-3.git20100323.fc13,ModemManager-0.3-4.git20100323.fc13

Comment 3 Fedora Update System 2010-03-24 09:40:33 UTC
NetworkManager-0.8.0-3.git20100323.fc13,ModemManager-0.3-4.git20100323.fc13 has been submitted as an update for Fedora 13.
http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-3.git20100323.fc13,ModemManager-0.3-4.git20100323.fc13

Comment 4 Fedora Update System 2010-03-24 09:48:17 UTC
NetworkManager-0.8.0-3.git20100323.fc12,ModemManager-0.3-4.git20100323.fc12 has been submitted as an update for Fedora 12.
http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-3.git20100323.fc12,ModemManager-0.3-4.git20100323.fc12

Comment 5 Avalone 2010-03-24 13:26:10 UTC
Try NM-0.8.0-3.git20100323.fc13.

Logic fixed (Dhcp now see bnep0 connection), but don't work.

dhclient.i686 version   4.1.1-13.fc13                                 

See new attached log.

Comment 6 Avalone 2010-03-24 13:29:35 UTC
Created attachment 402308 [details]
FC13 NetworkManager 0.8.0-3 PANU log

Comment 7 Fedora Update System 2010-03-24 23:28:04 UTC
NetworkManager-0.8.0-3.git20100323.fc12, ModemManager-0.3-4.git20100323.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update NetworkManager ModemManager'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-3.git20100323.fc12,ModemManager-0.3-4.git20100323.fc12

Comment 8 Fedora Update System 2010-03-27 00:56:52 UTC
ModemManager-0.3-4.git20100323.fc12, NetworkManager-0.8.0-4.git20100325.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update ModemManager NetworkManager'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-4.git20100325.fc12,ModemManager-0.3-4.git20100323.fc12

Comment 9 Fedora Update System 2010-04-03 04:48:54 UTC
ModemManager-0.3-6.git20100331.fc12, NetworkManager-0.8.0-4.git20100325.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update ModemManager NetworkManager'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-4.git20100325.fc12,ModemManager-0.3-6.git20100331.fc12

Comment 10 Igor Bukanov 2010-04-06 16:48:15 UTC
I confirm this bug on Fedora-13 alpha with updates as of 2010-04-06. PAN networking is extremely unstable with Nokia XPress Music 5280. It fails either after a DNS lookup or after one or two TCP connections. On the other hand DUN networking with the same setup works without any problems. Here is the system relevant system log:

Apr  6 16:49:01 chernika NetworkManager: <info>  Activation (00:24:04:C2:C5:81) Stage 5 of 5 (IP Configure Commit) complete.
Apr  6 16:49:01 chernika ntpd[1180]: Listening on interface #35 bnep0, 10.0.66.2#123 Enabled
Apr  6 16:49:20 chernika kernel: btusb_intr_complete: hci0 urb de5a5e70 failed to resubmit (1)
Apr  6 16:49:20 chernika kernel: btusb_bulk_complete: hci0 urb de5a5790 failed to resubmit (1)
Apr  6 16:49:20 chernika kernel: btusb_bulk_complete: hci0 urb de5a5580 failed to resubmit (1)
Apr  6 16:49:25 chernika NetworkManager: <info>  (00:24:04:C2:C5:81): device state change: 8 -> 9 (reason 44)
Apr  6 16:49:25 chernika NetworkManager: <info>  Activation (00:24:04:C2:C5:81) failed.
Apr  6 16:49:25 chernika NetworkManager: <info>  (00:24:04:C2:C5:81): device state change: 9 -> 3 (reason 0)
Apr  6 16:49:25 chernika NetworkManager: <info>  (00:24:04:C2:C5:81): deactivating device (reason: 0).
Apr  6 16:49:25 chernika NetworkManager: (bnep0): canceled DHCP transaction, dhcp client pid 11633
Apr  6 16:49:25 chernika avahi-daemon[1071]: Interface bnep0.IPv4 no longer relevant for mDNS.
Apr  6 16:49:25 chernika avahi-daemon[1071]: Leaving mDNS multicast group on interface bnep0.IPv4 with address 10.0.66.2.
Apr  6 16:49:25 chernika dbus: [system] Rejected send message, 2 matched rules; type="method_return", sender=":1.10" (uid=0 pid=1167 comm="/usr/sbin/bluetoothd) interface="(unset)" member="(unset)" error name="(unset)" requested_reply=0 destination=":1.1" (uid=0 pid=1060 comm="NetworkManager))
Apr  6 16:49:25 chernika bluetoothd[1171]: bnep0 disconnected
Apr  6 16:49:25 chernika avahi-daemon[1071]: Withdrawing address record for fe80::210:60ff:fed0:5e2b on bnep0.
Apr  6 16:49:25 chernika avahi-daemon[1071]: Withdrawing address record for 10.0.66.2 on bnep0.
Apr  6 16:49:25 chernika NetworkManager: <WARN>  check_one_route(): (bnep0) error -3 returned from rtnl_route_del(): Sucess#012
Apr  6 16:49:25 chernika NetworkManager: <WARN>  check_one_route(): (bnep0) error -34 returned from rtnl_route_del(): Sucess#012
Apr  6 16:49:25 chernika NetworkManager: <WARN>  check_one_route(): (bnep0) error -3 returned from rtnl_route_del(): Sucess#012
Apr  6 16:49:25 chernika NetworkManager: <WARN>  check_one_route(): (bnep0) error -3 returned from rtnl_route_del(): Sucess#012
Apr  6 16:49:25 chernika NetworkManager: <WARN>  check_one_route(): (bnep0) error -3 returned from rtnl_route_del(): Sucess#012
Apr  6 16:49:26 chernika ntpd[1180]: Deleting interface #34 bnep0, fe80::210:60ff:fed0:5e2b#123, interface stats: received=0, sent=0, dropped=0, active_time=28 secs
Apr  6 16:49:26 chernika ntpd[1180]: Deleting interface #35 bnep0, 10.0.66.2#123, interface stats: received=0, sent=0, dropped=0, active_time=25 secs
Apr  6 16:49:29 chernika kernel: btusb_intr_complete: hci0 urb ed7edf20 failed to resubmit (1)

Comment 11 Dan Williams 2010-04-06 17:17:10 UTC
(In reply to comment #10)
> I confirm this bug on Fedora-13 alpha with updates as of 2010-04-06. PAN
> networking is extremely unstable with Nokia XPress Music 5280. It fails either
> after a DNS lookup or after one or two TCP connections. On the other hand DUN
> networking with the same setup works without any problems. Here is the system
> relevant system log:
> 
> Apr  6 16:49:01 chernika NetworkManager: <info>  Activation (00:24:04:C2:C5:81)
> Stage 5 of 5 (IP Configure Commit) complete.
> Apr  6 16:49:01 chernika ntpd[1180]: Listening on interface #35 bnep0,
> 10.0.66.2#123 Enabled
> Apr  6 16:49:20 chernika kernel: btusb_intr_complete: hci0 urb de5a5e70 failed
> to resubmit (1)
> Apr  6 16:49:20 chernika kernel: btusb_bulk_complete: hci0 urb de5a5790 failed
> to resubmit (1)
> Apr  6 16:49:20 chernika kernel: btusb_bulk_complete: hci0 urb de5a5580 failed
> to resubmit (1)

I believe this indicates kernel problems though, not NM problems.  These messages show failed communication between the kernel bluetooth driver and the bluetooth device itself.  I don't think they are related to this bug.  I've seen these sorts of things periodically, and it's usually a bug in the BT drivers since switching to another adapter (with a different chipset) makes things work.

Comment 12 Igor Bukanov 2010-04-06 17:35:05 UTC
> I believe this indicates kernel problems though, not NM problems.

But why then DUN works without any problems with the same adapter and phone?

Comment 13 Dan Williams 2010-04-06 20:19:39 UTC
(In reply to comment #12)
> > I believe this indicates kernel problems though, not NM problems.
> 
> But why then DUN works without any problems with the same adapter and phone?    

Because PAN is different than DUN and the functionality takes different paths through the kernel and different paths through your phone.  Those kernel messages indicate a critical problem with the *driver* not being able to talk to the device, which doesn't have much to do with NetworkManager.

Comment 14 Avalone 2010-04-07 19:11:39 UTC
Updated to 0406 testing repo
ModemManager.i686            0.3-7.git20100405.fc13   @updates-testing
NetworkManager.i686          0.8.0-4.git20100325.fc13 @updates-testing
NetworkManager-glib.i686     0.8.0-4.git20100325.fc13 @updates-testing
NetworkManager-gnome.i686    0.8.0-4.git20100325.fc13 @updates-testing

Console log from: NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

NetworkManager: bluez_manager_bdaddr_added_cb: BT device Nokia 6085 (00:19:2D:95:9D:F5) added (DUN NAP)
NetworkManager: <info>  (00:19:2D:95:9D:F5): new Bluetooth device (driver: 'bluez')
NetworkManager: <info>  (00:19:2D:95:9D:F5): exported as /org/freedesktop/NetworkManager/Devices/1
NetworkManager: <info>  (00:19:2D:95:9D:F5): now managed
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 1 -> 2 (reason 2)
NetworkManager: <info>  (00:19:2D:95:9D:F5): deactivating device (reason: 2).
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 2 -> 3 (reason 0)
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) starting connection '00:19:2D:95:9D:F5 PANU'
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 3 -> 4 (reason 0)
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 2 of 5 (Device Configure) starting...
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 4 -> 5 (reason 0)
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5 bnep0/bluetooth) Stage 2 of 5 (Device Configure) successful.  Will connect via PAN.
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 3 of 5 (IP Configure Start) started...
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 5 -> 7 (reason 0)
NetworkManager: Activation (bnep0) Beginning DHCPv4 transaction (timeout in 45 seconds)
NetworkManager: <info>  running: /sbin/dhclient -d -4 -sf /usr/libexec/nm-dhcp-client.action -pf /var/run/dhclient-bnep0.pid -lf /var/lib/dhclient/dhclient-1cc564bd-1c5c-437d-a37d-1d8bb2091920-bnep0.lease -cf /var/run/nm-dhclient-bnep0.conf bnep0
NetworkManager: <info>  dhclient started with pid 4419
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 4 of 5 (IP6 Configure Get) scheduled...
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 4 of 5 (IP6 Configure Get) started...
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) Stage 4 of 5 (IP6 Configure Get) complete.
Internet Systems Consortium DHCP Client 4.1.1
Copyright 2004-2010 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/

Listening on LPF/bnep0/00:1d:92:c5:18:9d
Sending on   LPF/bnep0/00:1d:92:c5:18:9d
Sending on   Socket/fallback
NetworkManager: DHCPv4: device bnep0 state changed nbi -> preinit
NetworkManager: <WARN>  device_creator(): /sys/devices/pci0000:00/0000:00:1d.3/usb5/5-1/5-1:1.0/bluetooth/hci0/hci0:42/bnep0: couldn't determine device driver; ignoring...
DHCPDISCOVER on bnep0 to 255.255.255.255 port 67 interval 3
DHCPDISCOVER on bnep0 to 255.255.255.255 port 67 interval 8
receive_packet failed on bnep0: Network is down
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5/bluetooth): bluetooth link disconnected.
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 7 -> 9 (reason 40)
NetworkManager: <info>  Marking connection '00:19:2D:95:9D:F5 PANU' invalid.
NetworkManager: <info>  Activation (00:19:2D:95:9D:F5) failed.
NetworkManager: <info>  (00:19:2D:95:9D:F5): device state change: 9 -> 3 (reason 0)
NetworkManager: <info>  (00:19:2D:95:9D:F5): deactivating device (reason: 0).
NetworkManager: (bnep0): canceled DHCP transaction, dhcp client pid 4419
NetworkManager: <info>  Policy set 'HUB' (eth0) as default for routing and DNS.

so no changes from prev version.


Sorry, but i'm cannot put bluetoothd log, because cannot start bluetoothd with debug.

bluetoothd -n -d
bluetoothd[4443]: Bluetooth daemon 4.63
bluetoothd[4443]: Enabling debug information
bluetoothd[4443]: parsing main.conf
bluetoothd[4443]: discovto=0
bluetoothd[4443]: pairto=0
bluetoothd[4443]: pageto=8192
bluetoothd[4443]: name=%h-%d
bluetoothd[4443]: class=0x000100
bluetoothd[4443]: discov_interval=0
bluetoothd[4443]: Key file does not have key 'DeviceID'
bluetoothd[4443]: Unable to get on D-Bus


/usr/sbin/bluetoothd -n -d -u
(empty output and return to shell)

Comment 15 Fedora Update System 2010-04-09 01:36:09 UTC
ModemManager-0.3-7.git20100405.fc12, NetworkManager-0.8.0-4.git20100325.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update ModemManager NetworkManager'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-4.git20100325.fc12,ModemManager-0.3-7.git20100405.fc12

Comment 16 Fedora Update System 2010-04-09 03:57:52 UTC
NetworkManager-0.8.0-6.git20100408.fc13, ModemManager-0.3-8.git20100408.fc13 has been pushed to the Fedora 13 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 17 Fedora Update System 2010-04-10 10:22:31 UTC
ModemManager-0.3-9.git20100409.fc12, NetworkManager-0.8.0-6.git20100408.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update ModemManager NetworkManager'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/NetworkManager-0.8.0-6.git20100408.fc12,ModemManager-0.3-9.git20100409.fc12

Comment 18 Avalone 2010-04-19 12:50:52 UTC
I'm try Bluetooth PAN with lastest updates-testing today. No success.

But with lastest Network Manager now DUN available on my phone (Nokia 6080).

Repair phone with both checkbox selected, and PAN - no success, DUN - work like charm (i'm only select custom APN, because my GSM provider (Russia/Beeline) use different APN for different tariffs.

Thanks for long awaited NetworkManager functionality (DUN support) i'm now able use my bluetooth phone as modem through gui (for a 2 month i'm use command line rfbind/wvdial combo).

Comment 19 Fedora Update System 2010-04-23 22:50:09 UTC
ModemManager-0.3-9.git20100409.fc12, NetworkManager-0.8.0-6.git20100408.fc12 has been pushed to the Fedora 12 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.