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 ��.n��������+%������w��{.n�����{��� �^n�r������&��z�ޗ�zf���h���~����������_��+v���)ߣ�
