Bluetooth mouse breaks on -current
Eric Anderson
anderson at centtech.com
Tue Oct 4 05:16:37 PDT 2005
Eric Anderson wrote:
> Eric Anderson wrote:
>
>> Eric Anderson wrote:
>>
>>> Maksim Yevmenkin wrote:
>>>
>>>> Eric,
>>>>
>>>>>> Ok, I wish I could provide better information, but as of the last
>>>>>> couple of weeks (2 weeks maybe?), I've had this weird problem with
>>>>>> my bluetooth mouse (which had been working flawlessly until now).
>>>>>> Right in the middle of use, my mouse will die. It will lose
>>>>>> association (or whatever it's called). Actually, the mouse seems
>>>>>> to be ok, as I've tried it on another computer and it works just
>>>>>> fine with no changes. Once it dies, I have to muck with the
>>>>>> bthidcontrol forget, reboot, etc, so I'm not sure what I do to fix
>>>>>> it, but eventually it will be able to query the mouse again and
>>>>>> then bthidd will connect and everything will be fine.
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> very strange... i do not think i committed any significant change to
>>>> the bluetooth code in a few months.
>>>>
>>>>>> One thing I've noticed, is that now, when doing an l2ping, I get
>>>>>> this:
>>>>>> # l2ping -a mouse
>>>>>> 44 bytes from mouse seq_no=0 time=59990.660 ms result=0x23
>>>>>> Resource temporarily unavailable
>>>>>> 44 bytes from mouse seq_no=1 time=59990.834 ms result=0x23
>>>>>> Resource temporarily unavailable
>>>>>> 44 bytes from mouse seq_no=2 time=59990.821 ms result=0x23
>>>>>> Resource temporarily unavailable
>>>>>> 44 bytes from mouse seq_no=3 time=59990.885 ms result=0x23
>>>>>> Resource temporarily unavailable
>>>>>> 44 bytes from mouse seq_no=4 time=59990.879 ms result=0x23
>>>>>> Resource temporarily unavailable
>>>>>>
>>>>>> When my mouse is on or off. Also, pinging other devices, returns
>>>>>> either the same result, or sometimes it will return ~5000ms
>>>>>> returns, as if it can ping it, but it is slow - even when the
>>>>>> device isn't powered on!
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> i think its fine. what probably happens here is that bluetooth
>>>> thinks there is an active baseband connection to the device, but for
>>>> what ever reason no data is transferred (flow control issues?).
>>>> l2ping has default timeout of 60 seconds (time=59990.879) after that
>>>> msleep() call will timeout and return EAGAIN (35 decimal or 0x23)
>>>>
>>>>>> What do I need to do to help diagnose?
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> when this happens please do
>>>>
>>>> # hccontrol -n ubt0hci read_connection_list
>>>>
>>>> # l2control -a <bd_addr_of_LOCAL_device> read_connection_list
>>>>
>>>> # l2control -a <bd_addr_of_LOCAL_device> read_channel_list
>>>>
>>>> # btsockstat
>>>>
>>>> and send me the output. note: <bd_addr_of_LOCAL_device> means
>>>> bd_addr of the device connected to the computer, not mouse.
>>>>
>>>>> Seems that rebooting my FreeBSD laptop clears it up - so I'm
>>>>> thinking it has to do with the netgraph/bluetooth modules..
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> you probably right. if you have time, you could try to revert your
>>>> src/ tree to, say, month ago and see if you still have the problem.
>>>> using the few iterations you could find the date after which your
>>>> mouse no longer works. this would help me a lot to figure out what
>>>> change caused this.
>>>>
>>>> also i would like to know if anybody else has the same issues.
>>>
>>>
>>>
>>>
>>> Just letting you know that I haven't had a problem since cvsuping src
>>> and rebuilding world/kernel..
>>
>>
>>
>> It's back at it again. About 10-15 minutes into a buildworld, I
>> started losing my mouse. If I hit a button on the mouse, it would
>> come back (it was just losing the connection, as if the mouse went to
>> sleep, or had low batteries). I did that a few times, until it
>> finally stopped working altogether. I swapped batteries thinking this
>> was the problem, however the batteries were pretty fresh still, but
>> the new batts did not make a difference.
>>
>> I noticed in /var/log/messages:
>> [beginning of problems]
>> Oct 1 19:58:41 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed interrupt connection
>> Oct 1 19:58:42 neutrino kernel: ng_l2cap_process_discon_req:
>> ubt0l2cap - unexpected L2CAP_DisconnectReq message. Channel does not
>> exist, cid=107
>> Oct 1 20:01:03 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:01:03 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:09:47 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed control connection
>> Oct 1 20:09:48 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:09:48 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:15:14 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed control connection
>> Oct 1 20:15:14 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:15:14 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:15:22 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed control connection
>> Oct 1 20:15:22 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:15:22 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:15:34 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed control connection
>> Oct 1 20:15:34 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:15:34 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:15:40 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed control connection
>> Oct 1 20:15:41 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:15:41 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:16:08 neutrino bthidd[603]: Remote device 00:0c:55:01:bf:39
>> has closed control connection
>> Oct 1 20:30:27 neutrino bthidd[603]: Accepted control connection from
>> 00:0c:55:01:bf:39
>> Oct 1 20:30:27 neutrino bthidd[603]: Accepted interrupt connection
>> from 00:0c:55:01:bf:39
>> Oct 1 20:54:50 neutrino kernel: kbd1 at vkbd1
>>
>> [died completely at that vkbd message]
>>
>> Oct 1 21:01:16 neutrino su: anderson to root on /dev/ttyp2
>> Oct 1 21:06:22 neutrino kernel: ng_hci_process_command_timeout:
>> ubt0hci - unable to complete HCI command OGF=0x1, OCF=0x1. Timeout
>> Oct 1 21:06:22 neutrino kernel: ubt_request_complete2: ubt0 - Control
>> request failed. TIMEOUT (15)
>> Oct 1 21:07:39 neutrino kernel: ng_hci_process_command_timeout:
>> ubt0hci - unable to complete HCI command OGF=0x3, OCF=0x3. Timeout
>> Oct 1 21:07:39 neutrino kernel: ubt_request_complete2: ubt0 - Control
>> request failed. TIMEOUT (15)
>>
>> [those were me trying to do commands to find my own bd_addr so I could
>> follow your instructions on what to do next, but I kept getting timeouts]
>>
>> Oct 1 21:08:34 neutrino bthidd[13548]: Got signal 15, total number of
>> signals 1
>>
>> [so then I killed bthidd]
>>
>> Oct 1 21:09:33 neutrino kernel: ubt0: detached
>>
>> [and tried unloading the modules so I could reload them]
>>
>> The next step was a 'kldunload vkbd' which caused an instant reboot of
>> my system.
>>
>> Here's a typescript from what I was doing - it's truncated at the
>> bottom because (I believe) it had not synced the blocks to disk before
>> the instant reboot:
>>
>> Script started on Sat Oct 1 20:56:25 2005
>> [1;1m[ [0m[1;32m20:56:25 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m hccontrol -n ubt0hci
>> read_connection_list
>> Remote BD_ADDR Handle Type Mode Role Encrypt Pending Queue State
>> mouse 42 ACL 2 MAST NONE 2 0 OPEN
>> [1;1m[ [0m[1;32m20:56:37 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m l2control -a hccontrol -n ubt0hci
>> inquiry
>> l2control: hccontrol: Unknown host
>> [1;1m[ [0m[1;32m21:06:52 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m -su: btcontrol: command not found
>> bash: -su:: command not found
>> [1;1m[ [0m[1;32m21:06:52 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m [ 20:56:00 root at neutrino ~/bt ]#
>> hccontrol -n ubt0hci read_connection_list
>> bash: [: missing `]'
>> [1;1m[ [0m[1;32m21:06:52 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m [Khccontrol -n ubto0hci inquiry
>> Could not execute command "inquiry". Operation timed out
>> [1;1m[ [0m[1;32m21:07:14 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m /etc/rc.bluetooth stop
>> Usage:
>> /etc/rc.bluetooth start device
>> or
>> /etc/rc.bluetooth stop device
>> [1;1m[ [0m[1;32m21:07:23 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m /etc/rc.bluetooth stop ubt0
>> [1;1m[ [0m[1;32m21:07:28 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m /etc/rc.bluetooth stop ubt0
>> [1;1m[ [0m[1;32m21:07:29 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m
>> /etc/rc.bluetooth stop ubt0 art ubt0
>> Could not execute command "reset". Operation timed out
>> [1;1m[ [0m[1;32m21:07:40 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m kldstat
>> Id Refs Address Size Name
>> 1 37 0xc0400000 4e3420 kernel
>> 2 1 0xc08e4000 56c8 vesa.ko
>> 3 2 0xc08ea000 1c6c8 linux.ko
>> 4 1 0xc0907000 5e28 snd_ich.ko
>> 5 2 0xc090d000 244e0 sound.ko
>> 6 7 0xc0932000 22258 usb.ko
>> 7 1 0xc0955000 5df8 ugen.ko
>> 8 1 0xc095b000 4098 ums.ko
>> 9 1 0xc0960000 7a38 umass.ko
>> 10 1 0xc0968000 4344 acpi_video.ko
>> 11 1 0xc096d000 1e530 radeon.ko
>> 12 2 0xc098c000 10eec drm.ko
>> 13 1 0xc099d000 2720 acpi_sony.ko
>> 14 1 0xc09a0000 2d90 wlan_wep.ko
>> 15 1 0xc09a3000 942c cpufreq.ko
>> 16 6 0xc09ad000 d900 netgraph.ko
>> 17 1 0xc09bb000 80c4 ng_ubt.ko
>> 18 1 0xc09c4000 68cc vkbd.ko
>> 19 1 0xc2718000 6000 linprocfs.ko
>> 20 4 0xc2a34000 2000 ng_bluetooth.ko
>> 21 1 0xc2a36000 d000 ng_hci.ko
>> 22 1 0xc2a43000 10000 ng_l2cap.ko
>> 23 1 0xc2a5c000 19000 ng_btsocket.ko
>> 24 1 0xc2a77000 4000 ng_socket.ko
>> 25 1 0xc6cb8000 5000 geom_label.ko
>> [1;1m[ [0m[1;32m21:08:08 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m kldunload ng_socket
>> kldunload: can't unload file: Device busy
>> [1;1m[ [0m[1;32m21:08:24 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m kldunload ng_socket
>> btsocket
>> kldunload: can't unload file: Device busy
>> [1;1m[ [0m[1;32m21:08:29 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m killall bthidd
>> [1;1m[ [0m[1;32m21:08:34 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m killall hcsed cd
>> [1;1m[ [0m[1;32m21:08:38 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m
>> ]#[0m killall
>> hcsecdbthiddldunload ng_btsocket[2Psocket
>> kldunload: can't unload file: Device busy
>> [1;1m[ [0m[1;32m21:08:40 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m
>> kldunload ng_socket[5Pillall hcsecdbthiddldunload
>> ng_btsocket
>> kldunload: can't unload file: Device busy
>> [1;1m[ [0m[1;32m21:08:42 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m kldunload ng_bluetooth
>> [1;1m[ [0m[1;32m21:08:50 [0m[1;1mroot at neutrino
>> [0m[1;32m~/bt[0m[1;1m ]#[0m kldunload ng_bluetooth[1Ptsocket[2Psocket[5Pillall
>> hcsecdbthiddldunload ng_btsocket[2Psocketstat[K
>>
>> Id Refs Address Size Name
>> 1
>>
>> [thats where it ends]
>>
>> And now, even after reboot, I can no longer see by bluetooth mouse.
I'm trying a different bluetooth mouse now, just in case.
However, I see this in my dmesg output, when I can't use bluetooth:
ng_hci_process_command_timeout: ubt0hci - unable to complete HCI command
OGF=0x3, OCF=0x3. Timeout
Can you give me a clue as to what that is really telling me?
Eric
--
------------------------------------------------------------------------
Eric Anderson Sr. Systems Administrator Centaur Technology
Anything that works is better than anything that doesn't.
------------------------------------------------------------------------
More information about the freebsd-bluetooth
mailing list