Bug 182979

With rawhide from 2006-06-16, my mouse no longer works at all.  I see in the logs:

Jun 17 12:41:11 cmathink hidd[2164]: HID create error 2 (No such file or directory)

Not really a Test1 blocker, moving to FC6blocker.

Does this still happen with current rawhide?

With an updated rawhide system as of 2006-09-11, I still do not have a working
Bluetooth mouse.  I get an SELinux error 'denied  { getattr } for  pid=2993
comm="hidd"' (on a different computer; let me know if you need the full
message).  I set SELinux to permissive mode and tried again, and I get (in
/var/log/messages):

HID create error 2 (No such file or directory)

Looking in /sys/class/input and /dev/input, there are only two mouse entries,
both for built-in devices (one for the touchpad and one for the TrackPoint).

strace hidd. Where is that error coming from?

It is trying to open /var/lib/bluetooth/00:0E:9B:DF:FF:F1/hidd.  The directory
exists, and there is a file called "features" in it.  I stopped the hidd and
bluetooth services, removed the directory, and restarted them, and got the same
thing (directory created with "features" as the only file) as soon as I move the
mouse.

I copied the "hidd" file from my FC5 install on that computer to that directory,
and then the mouse works.

As long as selinux is disabled, I cannot reproduce this.

With selinux in enforcing mode, I see this...
accept(4, {sa_family=AF_BLUETOOTH,
sa_data="\21\0\27~\300\224\n\0\0m\221\251\177\355"}, [10]) = 7
accept(5, {sa_family=AF_BLUETOOTH,
sa_data="\23\0\27~\300\224\n\0\0m\221\251\177\355"}, [10]) = 8
getsockname(7, 0x7fed8ff6, [10])        = -1 EACCES (Permission denied)
time(NULL)                              = 1159480772
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1323, ...}) = 0
send(6, "<27>Sep 28 22:59:32 hidd[1804]: HID create error 13 (Permission
denied)", 71, MSG_NOSIGNAL) = 71



...coupled with this in dmesg:

audit(1159480772.521:12): avc:  denied  { getattr } for  pid=1804 comm="hidd"
scontext=system_u:system_r:bluetooth_t:s0
tcontext=system_u:object_r:unlabeled_t:s0 tclass=socket


Quite why selinux is disallowing us from calling getsockname() on a socket we
just accepted, I'm not sure -- but we need to make it allow that.

I have SELinux in permissive mode.  I get:

poll([{fd=4, events=POLLIN|POLLERR|POLLHUP, revents=POLLIN}, {fd=5,
events=POLLIN|POLLERR|POLLHUP}], 2, -1) = 1
accept(4, {sa_family=AF_BLUETOOTH,
sa_data="\21\0\360\253;a\7\0\0s\17\376\374V"}, [10]) = 7
accept(5, {sa_family=AF_BLUETOOTH,
sa_data="\23\0\360\253;a\7\0\0s\17\376\374V"}, [10]) = 8 
getsockname(7, {sa_family=AF_BLUETOOTH,
sa_data="\21\0\361\377\337\233\16\0\n\0\0\0\350\2"}, [10]) = 0
getpeername(7, {sa_family=AF_BLUETOOTH,
sa_data="\21\0\360\253;a\7\0\n\0\0\0\350\2"}, [10]) = 0
open("/var/lib/bluetooth/00:0E:9B:DF:FF:F1/hidd", O_RDONLY) = -1 ENOENT (No such
file or directory)
time(NULL)                        = 1159489730
stat64("/etc/localtime", {st_dev=makedev(8, 8), st_ino=1013872,
st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096,
st_blocks=16, st_size=1279, st_atime=2006/09/28-19:28:50,
st_mtime=2006/09/13-15:23:06, st_ctime=2006/09/13-15:23:06}) = 0
stat64("/etc/localtime", {st_dev=makedev(8, 8), st_ino=1013872,
st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096,
st_blocks=16, st_size=1279, st_atime=2006/09/28-19:28:50,
st_mtime=2006/09/13-15:23:06, st_ctime=2006/09/13-15:23:06}) = 0
stat64("/etc/localtime", {st_dev=makedev(8, 8), st_ino=1013872,
st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096,
st_blocks=16, st_size=1279, st_atime=2006/09/28-19:28:50,
st_mtime=2006/09/13-15:23:06, st_ctime=2006/09/13-15:23:06}) = 0
send(6, "<27>Sep 28 19:28:50 hidd[3336]: HID create error 2 (No such file or
directory)", 78, MSG_NOSIGNAL) = 78

Ah, OK. You need to use the '-Z' option to hidd, which makes it allow
connections from devices it doesn't know about.

That or connect explicitly to the device in question by running (once) 

hidd -c 00:07:61:3b:ab:f0

After that it'll store the device information and will allow it to connect in
future.

Now, can you still reproduce the original problems you reported?

Which policy are you seeing this with?  What kernel? We have a working bluetooth
mouse in enforcing mode here?

This is whatever's default in FC6. I can give you access to the offending
machine, although it'll be an hour or so before I get there and can actually
make the mouse talk to it.

Okay, when I "hidd -c ...", it works.  I understand this is better from a
security point of view, however this is a significant change - where is it
documented that what just "(no)plug and play" in FC5 doesn't work without a
special command in FC6?

As to the original problems: I still see problems intermittantly, typically
after a cold start.  I just cold-booted my noteboot (after "hidd -c ...").  When
I got to the login screen, the mouse worked, but then it stopped.  I power
cycled the mouse, it didn't come back.  I started typing this paragraph, decided
to grab it again on a whim, and it worked for a few seconds and stopped again. 
Looking at the dmesg output, I see it listed as input{4,5,6}, so I assume it is
losing communication and then restarting somehow.

Yesterday (same kernel, etc.; yesterday's rawhide) I saw the lagging action (I
haven't seen the work for a few seconds and stop in a while).

I have an IBM Thinkpad.  If I "echo disable > /proc/acpi/ibm/bluetooth", the
device is disabled (I see USB removed messages so I guess it acts like a USB
unplug).  If I do that, wait a few seconds for things to settle, and then "echo
enable > /proc/acpi/ibm/bluetooth" (and wait a few seconds), the mouse works
fine.  When I see lagging, this also fixes it.

I haven't seen either issue in FC5 in a while IIRC.

Can you show output of 'hcidump -X -V -t' and annotate it with the behaviour
you're observing?

Created attachment 137668 [details]
hcidump output when mouse goes dead

This dump is from when I:

- cold booted the system
- after logging in, I turned the mouse on
- it came alive for a second, then went dead
- after a bit, it came alive again
- after a few seconds, it went dead again

Created attachment 137669 [details]
hcidump after bluetooth reset

This is a dump from:

- after the previous dump, I did "echo disable" > /proc/acpi/ibm/bluetooth,
waited a few seconds, and did "echo enable" > /proc/acpi/ibm/bluetooth
- the dump stopped when I disabled bluetooth, so after reenabling, I restarted
the dump
- when I moved the mouse, it reconnected and worked fine (no more dropouts)

Can you give times for each of the events you list, please? It would be useful
to match them up to the times in the hcidump output.

Removing from FC6Blocker. Even the simple 'hcid segfaults' bug which is known to
be fixed in the package we already have ready and tested is unfortunately not
going to make it -- so there's not a whelk's chance in a supernova of us fixing
_this_ one before FC6.

Chris, please could you upload your hcid.conf. We're interested in the rôle
switch and sniff options, in particular.

I have not changed any settings from the defaults provided (so hcid.conf was
straight from the RPM).

With FC6, I am not seeing problems often enough to debug (I've only had it
happen once or twice) except after a suspend to disk/resume cycle.