Date: Sat, 01 Oct 2005 23:32:55 -0500 From: Eric Anderson <anderson@centtech.com> To: Eric Anderson <anderson@centtech.com> Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current Message-ID: <433F62F7.3060607@centtech.com> In-Reply-To: <433F4B50.1050108@centtech.com> References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> <433F4B50.1050108@centtech.com>
next in thread | previous in thread | raw e-mail | index | archive | help
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@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@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@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@neutrino > [0m[1;32m~/bt[0m[1;1m ]#[0m [ 20:56:00 root@neutrino ~/bt ]# > hccontrol -n ubt0hci read_connection_list > bash: [: missing `]' > [1;1m[ [0m[1;32m21:06:52 [0m[1;1mroot@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@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@neutrino > [0m[1;32m~/bt[0m[1;1m ]#[0m /etc/rc.bluetooth stop ubt0 > [1;1m[ [0m[1;32m21:07:28 [0m[1;1mroot@neutrino > [0m[1;32m~/bt[0m[1;1m ]#[0m /etc/rc.bluetooth stop ubt0 > [1;1m[ [0m[1;32m21:07:29 [0m[1;1mroot@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@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@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@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@neutrino > [0m[1;32m~/bt[0m[1;1m ]#[0m killall bthidd > [1;1m[ [0m[1;32m21:08:34 [0m[1;1mroot@neutrino > [0m[1;32m~/bt[0m[1;1m ]#[0m killall hcsed cd > [1;1m[ [0m[1;32m21:08:38 [0m[1;1mroot@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@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@neutrino > [0m[1;32m~/bt[0m[1;1m ]#[0m kldunload ng_bluetooth > [1;1m[ [0m[1;32m21:08:50 [0m[1;1mroot@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. Also - how do I get my local bd_addr? Eric -- ------------------------------------------------------------------------ Eric Anderson Sr. Systems Administrator Centaur Technology Anything that works is better than anything that doesn't. ------------------------------------------------------------------------
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?433F62F7.3060607>