Description of problem: Since updateing the kernel from 2.6.9-5.0.5.EL to 2.6.9-11.EL the pairing didn't work. To reproduce the problem try the following: # hcitool scan Scanning ... 00:11:9F:C5:33:F4 Nokia HGvS 00:80:98:24:C7:20 LVM-Mobil 00:60:57:15:6F:B0 Nokia 6310i # rfcomm bind hci0 00:60:57:15:6F:B0 # echo "ATZ">/dev/rfcomm0 &>/dev/null
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