On 08/08/2011 08:38 AM, Peter Hurley wrote:
On Sat, 2011-08-06 at 13:22 -0400, Colin Beckingham wrote:
On 08/06/2011 12:50 PM, Peter Hurley wrote:
On Sat, 2011-08-06 at 11:33 -0400, Colin Beckingham wrote:
Hi Peter:
...<snip>...
I ran # hciconfig hci0 sspmode 1 to force the adapter into a secure attempt.
I downloaded and installed the latest hcidump which identifies itself
(hcidump -v) as 2.0 even though it is marked as 2.1 version on the webpage.
Made another attempt to connect, here is the syslog
# tail -n 100 /var/log/messages | grep bluetoothd
Aug 6 05:15:39 linux-c96h bluetoothd[1246]: Audio connection got
disconnected
Aug 6 11:23:29 linux-c96h bluetoothd[1246]: Rejecting request: remote
device can't provide MITM
Aug 6 11:23:56 linux-c96h bluetoothd[1246]: Discovery session
0x7f801d0a6ca0 with :1.4178 activated
Aug 6 11:24:01 linux-c96h bluetoothd[1246]: Stopping discovery
Aug 6 11:24:13 linux-c96h bluetoothd[1246]: Permission denied (13)
and a binary hcidump is attached.
Hi Colin,
That makes a lot more sense!
Would you please repeat the experiment with bluetoothd in debug mode,
though? That would give me a lot more information to work with about how
bluetoothd got to that point.
As before, please capture hcidump binary at the same time. Also please
include every bluetoothd syslog message starting from the start of the
experiment.
I appreciate your patience helping me to track down this bug.
Regards,
Peter Hurley
Sorry, forgot to set bluetoothd in debug mode.
Attached are my latest logs, 2 files, wep475a.*. Note in the syslog that
the first entry is timestamped way before the experiment was launched,
so the log should have everything that bluetoothd wrote for the current
experiment.
Hi Colin,
Well, the new logs did not recreate the "Rejecting request: remote
device can't provide MITM". However, they did show 2 things:
1. The host controller has a race condition bug which has been seen
before (see this thread
http://comments.gmane.org/gmane.linux.bluez.kernel/14286 for the really
technical discussion)
That's why the initial attempt by the device at connecting an RFCOMM
channel is rejected (@ 13:13:02.533713).
Nevertheless, the headset is found anyway and Bluez connects to the
headset. After establishing an insecure SDP link, Bluez attempts to open
an RFCOMM channel to the device, and
2. the kernel attempts to connect the RFCOMM channel prior to the link
being encrypted, so the device rejects the connection.
There were some last minute changes to 3.0 final that directly impacts
how this is supposed to work. However, even with those changes it's
unclear to me how #2 is happening.
Would you be willing to run the same experiment as before but with the
kernel bluetooth module enabled for debug output? If your kernel is
configured for dynamic debug (Kernel hacking/Enable dynamic printk()
support => Y), doing this is trivial:
# sudo su
# echo -n "module bluetooth +p"
> /sys/kernel/debug/dynamic_debug/control
< perform experiment>
# echo -n "module bluetooth -p"
> /sys/kernel/debug/dynamic_debug/control
Regards,
Peter Hurley
Peter, before I do this, let me just verify that my kernel is set up
right. I checked for dynamic printk and I am not clear that I have the
setting needed. Here is what my .config tells me for dynamic and printk
separately.
> cat .config | grep DYNAMIC
CONFIG_NETCONSOLE_DYNAMIC=y
CONFIG_DVB_DYNAMIC_MINORS=y
CONFIG_SND_DYNAMIC_MINORS=y
# CONFIG_USB_DYNAMIC_MINORS is not set
CONFIG_HAVE_DYNAMIC_FTRACE=y
CONFIG_DYNAMIC_DEBUG=y
> cat .config | grep PRINTK
CONFIG_PRINTK=y
CONFIG_SND_VERBOSE_PRINTK=y
CONFIG_PRINTK_TIME=y
# CONFIG_BOOT_PRINTK_DELAY is not set
CONFIG_EARLY_PRINTK=y
CONFIG_EARLY_PRINTK_DBGP=y
Could you confirm that I am ok to go?
--
---
Colin Beckingham
--
To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
