Bug 161314

You shouldn't have needed to re-pair the devices after updating the kernel. The
link key should have been stored. Do you mean that the RFCOMM connection fails?

How reproducable is this? Can you show 'hcidump -x' output while you attempt to
connect? Does l2ping work?

I know that we don't need to re-pair after a kernel update. We use Bluetooth
under Linux with round about 5000 Laptops ... and a pairing has to work after a
kernel Update don't you think so ;-) ?

With the # echo "ATZ">/dev/rfcomm0 &>/dev/null we initiate the pairing of two
"fresh" devices

The l2ping works:

[root@nc1756 ~]# l2ping 00:60:57:15:6F:B0
Ping: 00:60:57:15:6F:B0 from 00:80:98:54:45:02 (data size 20) ...
0 bytes from 00:60:57:15:6F:B0 id 200 time 36.79ms
0 bytes from 00:60:57:15:6F:B0 id 201 time 32.09ms
0 bytes from 00:60:57:15:6F:B0 id 202 time 33.06ms
0 bytes from 00:60:57:15:6F:B0 id 203 time 31.07ms
0 bytes from 00:60:57:15:6F:B0 id 204 time 39.09ms
0 bytes from 00:60:57:15:6F:B0 id 205 time 38.03ms
6 sent, 6 received, 0% loss
[root@nc1756 ~]#

I attached the output of hcidump -x 
You can read it with hcidump -r <filename>

Created attachment 116115 [details]
This file contains the output of hcidump -w hcidump.out -x. You can view it with hcidump -r hcidump.out

I can reproduce the problem here, I get this in the /var/log/messages:
Jun 29 10:28:47 bnocera hcid[4411]: pin_code_request (sba=00:08:F4:00:43:8D,
dba=00:60:57:1A:0A:6D)
Jun 29 10:29:13 bnocera hcid[4411]: link_key_notify (sba=00:08:F4:00:43:8D)
Jun 29 10:29:13 bnocera hcid[4411]: Saving link key 00:08:F4:00:43:8D
00:60:57:1A:0A:6D
Jun 29 10:29:35 bnocera hcid[4411]: pin_code_request (sba=00:08:F4:00:43:8D,
dba=00:60:57:1A:0A:6D)
Jun 29 10:30:00 bnocera hcid[4411]: link_key_notify (sba=00:08:F4:00:43:8D)
Jun 29 10:30:00 bnocera hcid[4411]: Replacing link key 00:08:F4:00:43:8D
00:60:57:1A:0A:6D
Jun 29 10:30:13 bnocera hcid[4411]: pin_code_request (sba=00:08:F4:00:43:8D,
dba=00:60:57:1A:0A:6D)
Jun 29 10:30:40 bnocera hcid[4411]: link_key_notify (sba=00:08:F4:00:43:8D)
Jun 29 10:30:40 bnocera hcid[4411]: Replacing link key 00:08:F4:00:43:8D
00:60:57:1A:0A:6D

The pairing helper is a "/sbin/mybluepin" script.
$ /sbin/mybluepin
PIN:1111

It works great with an earlier kernel (tested with 2.6.9-5.0.5, latest security
update for GA).

I can reproduce this now. What I see is that we end up invoking the pin helper
and bash tries to open /dev/tty. However, we're doing all this with the tty_sem
locked -- because we're in the middle of opening the /dev/rfcomm0 tty device.

So what happens here is that the PIN helper script doesn't actually run until
the PIN request has timed out and the attempt to open /dev/rfcomm0 has failed --
at which point tty_sem gets unlocked and the PIN helper continues. But it's too
late by then. 

Strangely, starting the connection with 'minicom rfcomm0' seems to work. I don't
know why (yet) but it might help as a workaround for now until I fix the real
problem.

Created attachment 116122 [details]
strace-failed-pairing.txt

Strace of hcid during 2 failed pairings.

Created attachment 116123 [details]
hcidump-failed-pairing.txt

"hcidump -x -t" output during 2 failed pairings.

Note the 20-second period between the PIN request and the PIN reply in the
hcidump. Note the disconnection request coming in from the remote device just
before the PIN reply. Looks like the same problem with tty_sem.

Created attachment 116124 [details]
strace-failed-pairing.txt

Better strace.

Minicom seems to achieve pairing merely by virtue of aborting its open() call
far too early, thus releasing the tty_sem and allowing the pairing to complete.
So the first attempt to connect with minicom will give a bogus error message
after this happens...

alarm(4)                                = 0
open("/dev/rfcomm0", O_RDWR|O_NONBLOCK) = -1 EINTR (Interrupted system call)
--- SIGALRM (Alarm clock) @ 0 (0) ---

... but the devices _will_ be paired then.

This problem is caused by a tty locking fix which was put into the U1 kernel in
an attempt to fix bug #152600.

We'll try to get this fixed properly. As a workaround in the meantime, you
should be able to trigger the pairing _without_ waiting in rfcomm_tty_open() --
i.e. by some means _other_ than an uninterrupted open of /dev/rfcomm0. Just
hitting ^C on your echo command ought to suffice, in fact.

Created attachment 116179 [details]
Patch

This ought to fix the problem.

An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on the solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2005-514.html

Erratum released, CRM autoclosed, closing

Internal Status set to 'Resolved'
Status set to: Closed by Tech
Resolution set to: 'RHEL 4 U4'

This event sent from IssueTracker by pdemauro 
 issue 75204