From owner-freebsd-bluetooth@FreeBSD.ORG Sun Oct 2 02:52:14 2005 Return-Path: X-Original-To: freebsd-bluetooth@freebsd.org Delivered-To: freebsd-bluetooth@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id A178516A41F for ; Sun, 2 Oct 2005 02:52:14 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from mh1.centtech.com (moat3.centtech.com [207.200.51.50]) by mx1.FreeBSD.org (Postfix) with ESMTP id 2DDC443D45 for ; Sun, 2 Oct 2005 02:52:13 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from [192.168.42.23] (andersonbox3.centtech.com [192.168.42.23]) by mh1.centtech.com (8.13.1/8.13.1) with ESMTP id j922qCFj095118; Sat, 1 Oct 2005 21:52:12 -0500 (CDT) (envelope-from anderson@centtech.com) Message-ID: <433F4B50.1050108@centtech.com> Date: Sat, 01 Oct 2005 21:52:00 -0500 From: Eric Anderson User-Agent: Mozilla/5.0 (X11; U; FreeBSD i386; en-US; rv:1.7.11) Gecko/20050914 X-Accept-Language: en-us, en MIME-Version: 1.0 To: Maksim Yevmenkin References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> In-Reply-To: <432AC7E9.5060206@centtech.com> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: ClamAV 0.82/1106/Fri Sep 30 12:17:17 2005 on mh1.centtech.com X-Virus-Status: Clean Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 02 Oct 2005 02:52:14 -0000 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 read_connection_list >> >> # l2control -a read_channel_list >> >> # btsockstat >> >> and send me the output. note: 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 [ 20:56:25 root@neutrino ~/bt ]# 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 [ 20:56:37 root@neutrino ~/bt ]# l2control -a hccontrol -n ubt0hci inquiry l2control: hccontrol: Unknown host [ 21:06:52 root@neutrino ~/bt ]# -su: btcontrol: command not found bash: -su:: command not found [ 21:06:52 root@neutrino ~/bt ]# [ 20:56:00 root@neutrino ~/bt ]# hccontrol -n ubt0hci read_connection_list bash: [: missing `]' [ 21:06:52 root@neutrino ~/bt ]# hccontrol -n ubto0hci inquiry Could not execute command "inquiry". Operation timed out [ 21:07:14 root@neutrino ~/bt ]# /etc/rc.bluetooth stop Usage: /etc/rc.bluetooth start device or /etc/rc.bluetooth stop device [ 21:07:23 root@neutrino ~/bt ]# /etc/rc.bluetooth stop ubt0 [ 21:07:28 root@neutrino ~/bt ]# /etc/rc.bluetooth stop ubt0 [ 21:07:29 root@neutrino ~/bt ]# /etc/rc.bluetooth stop ubt0       art ubt0 Could not execute command "reset". Operation timed out [ 21:07:40 root@neutrino ~/bt ]# 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 [ 21:08:08 root@neutrino ~/bt ]# kldunload ng_socket kldunload: can't unload file: Device busy [ 21:08:24 root@neutrino ~/bt ]# kldunload ng_socket      btsocket kldunload: can't unload file: Device busy [ 21:08:29 root@neutrino ~/bt ]# killall bthidd [ 21:08:34 root@neutrino ~/bt ]# killall hcsed cd [ 21:08:38 root@neutrino ~/bt ]# killall hcsecdbthiddldunload ng_btsocketsocket kldunload: can't unload file: Device busy [ 21:08:40 root@neutrino ~/bt ]# kldunload ng_socketillall hcsecdbthiddldunload ng_btsocket kldunload: can't unload file: Device busy [ 21:08:42 root@neutrino ~/bt ]# kldunload ng_bluetooth [ 21:08:50 root@neutrino ~/bt ]# kldunload ng_bluetoothtsocketsocketillall hcsecdbthiddldunload ng_btsocketsocketstat Id Refs Address Size Name 1 [thats where it ends] And now, even after reboot, I can no longer see by bluetooth mouse. Eric -- ------------------------------------------------------------------------ Eric Anderson Sr. Systems Administrator Centaur Technology Anything that works is better than anything that doesn't. ------------------------------------------------------------------------ From owner-freebsd-bluetooth@FreeBSD.ORG Sun Oct 2 04:33:09 2005 Return-Path: X-Original-To: freebsd-bluetooth@freebsd.org Delivered-To: freebsd-bluetooth@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id E4A2516A420 for ; Sun, 2 Oct 2005 04:33:09 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from mh2.centtech.com (moat3.centtech.com [207.200.51.50]) by mx1.FreeBSD.org (Postfix) with ESMTP id 736C943D48 for ; Sun, 2 Oct 2005 04:33:09 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from [192.168.42.23] (andersonbox3.centtech.com [192.168.42.23]) by mh2.centtech.com (8.13.1/8.13.1) with ESMTP id j924X7Tb077167; Sat, 1 Oct 2005 23:33:08 -0500 (CDT) (envelope-from anderson@centtech.com) Message-ID: <433F62F7.3060607@centtech.com> Date: Sat, 01 Oct 2005 23:32:55 -0500 From: Eric Anderson User-Agent: Mozilla/5.0 (X11; U; FreeBSD i386; en-US; rv:1.7.11) Gecko/20050914 X-Accept-Language: en-us, en MIME-Version: 1.0 To: Eric Anderson References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> <433F4B50.1050108@centtech.com> In-Reply-To: <433F4B50.1050108@centtech.com> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: ClamAV 0.82/1106/Fri Sep 30 12:17:17 2005 on mh2.centtech.com X-Virus-Status: Clean Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 02 Oct 2005 04:33:10 -0000 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 read_connection_list >>> >>> # l2control -a read_channel_list >>> >>> # btsockstat >>> >>> and send me the output. note: 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 > [ 20:56:25 root@neutrino > ~/bt ]# 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 > [ 20:56:37 root@neutrino > ~/bt ]# l2control -a hccontrol -n ubt0hci inquiry > l2control: hccontrol: Unknown host > [ 21:06:52 root@neutrino > ~/bt ]# -su: btcontrol: command not found > bash: -su:: command not found > [ 21:06:52 root@neutrino > ~/bt ]# [ 20:56:00 root@neutrino ~/bt ]# > hccontrol -n ubt0hci read_connection_list > bash: [: missing `]' > [ 21:06:52 root@neutrino > ~/bt ]# hccontrol -n ubto0hci inquiry > Could not execute command "inquiry". Operation timed out > [ 21:07:14 root@neutrino > ~/bt ]# /etc/rc.bluetooth stop > Usage: > /etc/rc.bluetooth start device > or > /etc/rc.bluetooth stop device > [ 21:07:23 root@neutrino > ~/bt ]# /etc/rc.bluetooth stop ubt0 > [ 21:07:28 root@neutrino > ~/bt ]# /etc/rc.bluetooth stop ubt0 > [ 21:07:29 root@neutrino > ~/bt ]# /etc/rc.bluetooth > stop ubt0       art ubt0 > Could not execute command "reset". Operation timed out > [ 21:07:40 root@neutrino > ~/bt ]# 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 > [ 21:08:08 root@neutrino > ~/bt ]# kldunload ng_socket > kldunload: can't unload file: Device busy > [ 21:08:24 root@neutrino > ~/bt ]# kldunload ng_socket      > btsocket > kldunload: can't unload file: Device busy > [ 21:08:29 root@neutrino > ~/bt ]# killall bthidd > [ 21:08:34 root@neutrino > ~/bt ]# killall hcsed cd > [ 21:08:38 root@neutrino > ~/bt ]# > killall hcsecdbthiddldunload > ng_btsocketsocket > kldunload: can't unload file: Device busy > [ 21:08:40 root@neutrino > ~/bt ]# kldunload > ng_socketillall > hcsecdbthiddldunload ng_btsocket > kldunload: can't unload file: Device busy > [ 21:08:42 root@neutrino > ~/bt ]# kldunload ng_bluetooth > [ 21:08:50 root@neutrino > ~/bt ]# kldunload ng_bluetoothtsocketsocketillall > hcsecdbthiddldunload ng_btsocketsocketstat > > 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. ------------------------------------------------------------------------ From owner-freebsd-bluetooth@FreeBSD.ORG Tue Oct 4 12:16:37 2005 Return-Path: X-Original-To: freebsd-bluetooth@freebsd.org Delivered-To: freebsd-bluetooth@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id ED34216A41F for ; Tue, 4 Oct 2005 12:16:36 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from mh1.centtech.com (moat3.centtech.com [207.200.51.50]) by mx1.FreeBSD.org (Postfix) with ESMTP id 705B043D4C for ; Tue, 4 Oct 2005 12:16:36 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from [10.177.171.220] (neutrino.centtech.com [10.177.171.220]) by mh1.centtech.com (8.13.1/8.13.1) with ESMTP id j94CGZWL046876; Tue, 4 Oct 2005 07:16:35 -0500 (CDT) (envelope-from anderson@centtech.com) Message-ID: <43427296.6090404@centtech.com> Date: Tue, 04 Oct 2005 07:16:22 -0500 From: Eric Anderson User-Agent: Mozilla/5.0 (X11; U; FreeBSD i386; en-US; rv:1.7.11) Gecko/20050914 X-Accept-Language: en-us, en MIME-Version: 1.0 To: Maksim Yevmenkin References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> <433F4B50.1050108@centtech.com> <433F62F7.3060607@centtech.com> In-Reply-To: <433F62F7.3060607@centtech.com> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: ClamAV 0.82/1109/Mon Oct 3 17:06:28 2005 on mh1.centtech.com X-Virus-Status: Clean Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 04 Oct 2005 12:16:37 -0000 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 read_connection_list >>>> >>>> # l2control -a read_channel_list >>>> >>>> # btsockstat >>>> >>>> and send me the output. note: 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 >> [ 20:56:25 root@neutrino >> ~/bt ]# 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 >> [ 20:56:37 root@neutrino >> ~/bt ]# l2control -a hccontrol -n ubt0hci >> inquiry >> l2control: hccontrol: Unknown host >> [ 21:06:52 root@neutrino >> ~/bt ]# -su: btcontrol: command not found >> bash: -su:: command not found >> [ 21:06:52 root@neutrino >> ~/bt ]# [ 20:56:00 root@neutrino ~/bt ]# >> hccontrol -n ubt0hci read_connection_list >> bash: [: missing `]' >> [ 21:06:52 root@neutrino >> ~/bt ]# hccontrol -n ubto0hci inquiry >> Could not execute command "inquiry". Operation timed out >> [ 21:07:14 root@neutrino >> ~/bt ]# /etc/rc.bluetooth stop >> Usage: >> /etc/rc.bluetooth start device >> or >> /etc/rc.bluetooth stop device >> [ 21:07:23 root@neutrino >> ~/bt ]# /etc/rc.bluetooth stop ubt0 >> [ 21:07:28 root@neutrino >> ~/bt ]# /etc/rc.bluetooth stop ubt0 >> [ 21:07:29 root@neutrino >> ~/bt ]# >> /etc/rc.bluetooth stop ubt0       art ubt0 >> Could not execute command "reset". Operation timed out >> [ 21:07:40 root@neutrino >> ~/bt ]# 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 >> [ 21:08:08 root@neutrino >> ~/bt ]# kldunload ng_socket >> kldunload: can't unload file: Device busy >> [ 21:08:24 root@neutrino >> ~/bt ]# kldunload ng_socket      >> btsocket >> kldunload: can't unload file: Device busy >> [ 21:08:29 root@neutrino >> ~/bt ]# killall bthidd >> [ 21:08:34 root@neutrino >> ~/bt ]# killall hcsed cd >> [ 21:08:38 root@neutrino >> ~/bt >> ]# killall >> hcsecdbthiddldunload ng_btsocketsocket >> kldunload: can't unload file: Device busy >> [ 21:08:40 root@neutrino >> ~/bt ]# >> kldunload ng_socketillall hcsecdbthiddldunload >> ng_btsocket >> kldunload: can't unload file: Device busy >> [ 21:08:42 root@neutrino >> ~/bt ]# kldunload ng_bluetooth >> [ 21:08:50 root@neutrino >> ~/bt ]# kldunload ng_bluetoothtsocketsocketillall >> hcsecdbthiddldunload ng_btsocketsocketstat >> >> 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. ------------------------------------------------------------------------ From owner-freebsd-bluetooth@FreeBSD.ORG Tue Oct 4 17:30:21 2005 Return-Path: X-Original-To: freebsd-bluetooth@freebsd.org Delivered-To: freebsd-bluetooth@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 9B9ED16A41F for ; Tue, 4 Oct 2005 17:30:21 +0000 (GMT) (envelope-from maksim.yevmenkin@savvis.net) Received: from ismybrain.com (ismybrain.com [64.246.42.25]) by mx1.FreeBSD.org (Postfix) with ESMTP id 1D62C43D45 for ; Tue, 4 Oct 2005 17:30:20 +0000 (GMT) (envelope-from maksim.yevmenkin@savvis.net) Received: from [10.254.186.111] (localhost.localdomain [127.0.0.1]) by ismybrain.com (8.11.6/8.11.6) with ESMTP id j94HUAV16648; Tue, 4 Oct 2005 13:30:10 -0400 Message-ID: <4342BC20.8000001@savvis.net> Date: Tue, 04 Oct 2005 10:30:08 -0700 From: Maksim Yevmenkin User-Agent: Mozilla Thunderbird 1.0.2 (X11/20050404) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Eric Anderson References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> <433F4B50.1050108@centtech.com> <433F62F7.3060607@centtech.com> <43427296.6090404@centtech.com> In-Reply-To: <43427296.6090404@centtech.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 04 Oct 2005 17:30:21 -0000 Eric, [...] >>> 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. ok >>> 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 this looks like the mouse is loosing the connection and trying to re-connect. >>> [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) this is bad. something screwed up at usb level. basically we are trying to send commands to the local device (not mouse) and it does not respond. what is the model/make of the local bluetooth device (not mouse)? was buildworld still running? if buildworld was running can you tell what the load was? what scheduler are you using BSD or ULE? are you running with WITNESS enabled? also how fast is the cpu on your machine? >>> [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 ok, this is really bad. usb device should not just detach by itself (unless you pull it out). >>> [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. ok, i will look into this. >>> 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: it somewhat hard to read :( >>> 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 hmm... local device thinks that it still has connection to the mouse >>> l2control -a hccontrol -n ubt0hci inquiry >>> l2control: hccontrol: Unknown host ?? i'm not really sure what were you trying to do here. to read BD_ADDR of local device just do hccontrol -n ubt0hci read_bd_addr >>> [ 21:06:52 root@neutrino >>> ~/bt ]# -su: btcontrol: command not found >>> bash: -su:: command not found ??? >>> [ 21:06:52 root@neutrino >>> ~/bt ]# [ 20:56:00 root@neutrino ~/bt ]# >>> hccontrol -n ubt0hci read_connection_list >>> bash: [: missing `]' ??? >>> hccontrol -n ubto0hci inquiry >>> Could not execute command "inquiry". Operation timed out seems like typo. 'ubto0hci' instead of 'ubt0hci' >>> /etc/rc.bluetooth stop >>> Usage: >>> /etc/rc.bluetooth start device >>> or >>> /etc/rc.bluetooth stop device ??? >>> /etc/rc.bluetooth stop ubt0 >>> /etc/rc.bluetooth stop ubt0 why issue the command twice? >>> /etc/rc.bluetooth start ubt0 >>> Could not execute command "reset". Operation timed out this usually mean that communication between local bluetooth device and the local stack is broken. it could be that local device already detached it self (as shown in your /var/log/messages). >>> 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 that looks fine >>> kldunload ng_socket >>> kldunload: can't unload file: Device busy >>> kldunload ng_btsocket >>> kldunload: can't unload file: Device busy you can not unload ng_{k,bt}socket modules. freebsd does not yet allow to unload protocol families. the rest of the script is not very interesting. basically, you do not have to kldunload/kldload modules. just rc.bluetooth stop/start should be enough to reset stack to its default state. >>> And now, even after reboot, I can no longer see by bluetooth mouse. strange. does BD_ADDR of the mouse appears in /var/db/bthidd.hids file? if yes, then do 1) bthidcontrol -a BD_ADDR_of_the_mouse forget 2) press 'connect' button on your mouse 3) restart bthidd(8) note: depending on your mouse you may or may not need to run hcsecd(8). if your mouse requires authentication please look at mouse manual for pin code etc. > I'm trying a different bluetooth mouse now, just in case. i doubt mouse is the problem > 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? the line above tells you that host (freebsd) tried to send hci command with OGF=0x3 (group field) and OCF=0x3 (command field) to the bluetooth device ubt0 via ubt0hci netgraph node and this request has timed out. hci command with OGF=0x3 (group field) and OCF=0x3 means "Reset" which is the first command rc.bluetooth script will send to the device. possible reasons for timeout: 1) device is not present 2) communication between device and the host is broken (at usb level) 3) stack was not setup correctly you can run # ngctl li to see what netgraph nodes are present and if they are connected. for example, on my system # ngctl li There are 7 total nodes: Name: ngctl19807 Type: socket ID: 00000023 Num hooks: 0 Name: ubt0l2cap Type: l2cap ID: 0000001d Num hooks: 3 Name: ubt0hci Type: hci ID: 00000019 Num hooks: 3 Name: ubt0 Type: ubt ID: 00000015 Num hooks: 1 Name: btsock_l2c Type: btsock_l2c ID: 00000005 Num hooks: 1 Name: btsock_l2c_raw Type: btsock_l2c_raw ID: 00000004 Num hooks: 1 Name: btsock_hci_raw Type: btsock_hci_raw ID: 00000003 Num hooks: 1 "ubt0" node (type ubt) is the device driver node. if you see "num hooks" set to 1 then node is connected to the stack. "ubt0hci" node (type hci) is the hci node for ubt0 device. if you see "num hooks" set to 3 then everything should be fine. "ubt0l2cap" is similar to "ubt0hci" except its l2cap node. so far, the only thing i see is that communication between bluetooth device and the host was broken. at this point, i can not tell exactly why this happened. the only thing i can suggest is to run # hcidump -w dump.file while doing buildword and using bluetooth mouse. then when things start to go bad terminate hcidump and send me dump.file thanks, max From owner-freebsd-bluetooth@FreeBSD.ORG Tue Oct 4 18:50:38 2005 Return-Path: X-Original-To: freebsd-bluetooth@freebsd.org Delivered-To: freebsd-bluetooth@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 8031716A422 for ; Tue, 4 Oct 2005 18:50:38 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from mh1.centtech.com (moat3.centtech.com [207.200.51.50]) by mx1.FreeBSD.org (Postfix) with ESMTP id 7E89843D45 for ; Tue, 4 Oct 2005 18:50:33 +0000 (GMT) (envelope-from anderson@centtech.com) Received: from [10.177.171.220] (neutrino.centtech.com [10.177.171.220]) by mh1.centtech.com (8.13.1/8.13.1) with ESMTP id j94IoWat056519; Tue, 4 Oct 2005 13:50:32 -0500 (CDT) (envelope-from anderson@centtech.com) Message-ID: <4342CEEB.5010501@centtech.com> Date: Tue, 04 Oct 2005 13:50:19 -0500 From: Eric Anderson User-Agent: Mozilla/5.0 (X11; U; FreeBSD i386; en-US; rv:1.7.11) Gecko/20050914 X-Accept-Language: en-us, en MIME-Version: 1.0 To: Maksim Yevmenkin References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> <433F4B50.1050108@centtech.com> <433F62F7.3060607@centtech.com> <43427296.6090404@centtech.com> <4342BC20.8000001@savvis.net> In-Reply-To: <4342BC20.8000001@savvis.net> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: ClamAV 0.82/1109/Mon Oct 3 17:06:28 2005 on mh1.centtech.com X-Virus-Status: Clean Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 04 Oct 2005 18:50:38 -0000 Maksim Yevmenkin wrote: > Eric, > > [...] > >>>> 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. > > > ok > >>>> 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 > > > this looks like the mouse is loosing the connection and trying to > re-connect. Correct - the mouse would just stop working while I was using it, and this particular mouse needs a button click to tell it to re-connect (as if it was in power save mode). The reconnects you see, are me clicking buttons to get it to come back alive. >>>> [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) > > > this is bad. something screwed up at usb level. basically we are trying > to send commands to the local device (not mouse) and it does not respond. I agree - almost seems as though it's a faulty usb bluetooth adapter. > what is the model/make of the local bluetooth device (not mouse)? It's a built-in bluetooth adapter in my Sony laptop: ubt0: ALPS UGX, rev 1.10/11.68, addr 3 ubt0: ALPS UGX, rev 1.10/11.68, addr 3 ubt0: Interface 0 endpoints: interrupt=0x81, bulk-in=0x82, bulk-out=0x2 ubt0: Interface 1 (alt.config 5) endpoints: isoc-in=0x83, isoc-out=0x3; wMaxPacketSize=49; nframes=6, buffer size=294 > was buildworld still running? Yes > if buildworld was running can you tell what the load was? I can't recall what the load was at the time, but the CPU was close to 100% utilized. > what scheduler are you using BSD or ULE? ULE > are you running with WITNESS enabled? No. > also how fast is the cpu on your machine? 1500MHZ. Full dmesg, and other info here: http://www.googlebit.com/freebsd/ Look for the most recent date. >>>> [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 > > > ok, this is really bad. usb device should not just detach by itself > (unless you pull it out). Actually, that was me flipping the switch (enable/disable wireless, including bluetooth) on the laptop. >>>> [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. > > > ok, i will look into this. > >>>> 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: > > > it somewhat hard to read :( Yea, sorry - with no mouse, I could not copy/paste the xterm session easily, so a cat | mail ... etc had to work. :) >>>> 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 > > > hmm... local device thinks that it still has connection to the mouse > >>>> l2control -a hccontrol -n ubt0hci inquiry >>>> l2control: hccontrol: Unknown host > > > ?? i'm not really sure what were you trying to do here. to read BD_ADDR > of local device just do > > hccontrol -n ubt0hci read_bd_addr Ok - that's all I was trying to do. Thanks! >>>> [ 21:06:52 root@neutrino >>>> ~/bt ]# -su: btcontrol: command not found >>>> bash: -su:: command not found > > > ??? > >>>> [ 21:06:52 root@neutrino >>>> ~/bt ]# [ 20:56:00 root@neutrino ~/bt ]# >>>> hccontrol -n ubt0hci read_connection_list >>>> bash: [: missing `]' > > > ??? It's a typescript, so you see all my mistakes too :) >>>> hccontrol -n ubto0hci inquiry >>>> Could not execute command "inquiry". Operation timed out > > > seems like typo. 'ubto0hci' instead of 'ubt0hci' Woops. However, I think it gave a timeout error using the right name anyhow. >>>> /etc/rc.bluetooth stop >>>> Usage: >>>> /etc/rc.bluetooth start device >>>> or >>>> /etc/rc.bluetooth stop device > > > ??? > >>>> /etc/rc.bluetooth stop ubt0 >>>> /etc/rc.bluetooth stop ubt0 > > > why issue the command twice? Thought possibly the second run would give me a warning that it wasn't started, if the stop had successfully worked the first time. >>>> /etc/rc.bluetooth start ubt0 >>>> Could not execute command "reset". Operation timed out > > > this usually mean that communication between local bluetooth device and > the local stack is broken. it could be that local device already > detached it self (as shown in your /var/log/messages). > >>>> 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 > > > that looks fine > >>>> kldunload ng_socket >>>> kldunload: can't unload file: Device busy > > > >>> kldunload ng_btsocket > >>> kldunload: can't unload file: Device busy > > you can not unload ng_{k,bt}socket modules. freebsd does not yet allow > to unload protocol families. > > the rest of the script is not very interesting. basically, you do not > have to kldunload/kldload modules. just rc.bluetooth stop/start should > be enough to reset stack to its default state. Ok - however doing the stop/start didn't seem to do anything for me. >>>> And now, even after reboot, I can no longer see by bluetooth mouse. > > > strange. does BD_ADDR of the mouse appears in /var/db/bthidd.hids file? > if yes, then do Yes, it is indeed in there, and I tried the 'forget', but got the timeout. > 1) bthidcontrol -a BD_ADDR_of_the_mouse forget > 2) press 'connect' button on your mouse > 3) restart bthidd(8) > > note: depending on your mouse you may or may not need to run hcsecd(8). > if your mouse requires authentication please look at mouse manual for > pin code etc. Doesn't seem to need it. >> I'm trying a different bluetooth mouse now, just in case. > > > i doubt mouse is the problem > >> 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? > > > the line above tells you that host (freebsd) tried to send hci command > with OGF=0x3 (group field) and OCF=0x3 (command field) to the bluetooth > device ubt0 via ubt0hci netgraph node and this request has timed out. > > hci command with OGF=0x3 (group field) and OCF=0x3 means "Reset" which > is the first command rc.bluetooth script will send to the device. > possible reasons for timeout: > > 1) device is not present > 2) communication between device and the host is broken (at usb level) > 3) stack was not setup correctly > > you can run > > # ngctl li > > to see what netgraph nodes are present and if they are connected. for > example, on my system > > # ngctl li > There are 7 total nodes: > Name: ngctl19807 Type: socket ID: 00000023 Num hooks: 0 > Name: ubt0l2cap Type: l2cap ID: 0000001d Num hooks: 3 > Name: ubt0hci Type: hci ID: 00000019 Num hooks: 3 > Name: ubt0 Type: ubt ID: 00000015 Num hooks: 1 > Name: btsock_l2c Type: btsock_l2c ID: 00000005 Num hooks: 1 > Name: btsock_l2c_raw Type: btsock_l2c_raw ID: 00000004 Num hooks: 1 > Name: btsock_hci_raw Type: btsock_hci_raw ID: 00000003 Num hooks: 1 > > "ubt0" node (type ubt) is the device driver node. if you see "num hooks" > set to 1 then node is connected to the stack. > > "ubt0hci" node (type hci) is the hci node for ubt0 device. if you see > "num hooks" set to 3 then everything should be fine. > > "ubt0l2cap" is similar to "ubt0hci" except its l2cap node. > > > so far, the only thing i see is that communication between bluetooth > device and the host was broken. at this point, i can not tell exactly > why this happened. the only thing i can suggest is to run > > # hcidump -w dump.file > > while doing buildword and using bluetooth mouse. then when things start > to go bad terminate hcidump and send me dump.file Ok - I'll give this a try. Thanks for the help! Eric -- ------------------------------------------------------------------------ Eric Anderson Sr. Systems Administrator Centaur Technology Anything that works is better than anything that doesn't. ------------------------------------------------------------------------ From owner-freebsd-bluetooth@FreeBSD.ORG Tue Oct 4 21:28:58 2005 Return-Path: X-Original-To: freebsd-bluetooth@freebsd.org Delivered-To: freebsd-bluetooth@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 331E316A41F for ; Tue, 4 Oct 2005 21:28:58 +0000 (GMT) (envelope-from maksim.yevmenkin@savvis.net) Received: from mta13.adelphia.net (mta13.mail.adelphia.net [68.168.78.44]) by mx1.FreeBSD.org (Postfix) with ESMTP id 7534A43D49 for ; Tue, 4 Oct 2005 21:28:57 +0000 (GMT) (envelope-from maksim.yevmenkin@savvis.net) Received: from [192.168.1.254] (really [70.32.199.60]) by mta13.adelphia.net (InterMail vM.6.01.05.02 201-2131-123-102-20050715) with ESMTP id <20051004212856.IHQU23334.mta13.adelphia.net@[192.168.1.254]>; Tue, 4 Oct 2005 17:28:56 -0400 Message-ID: <4342F41A.1050706@savvis.net> Date: Tue, 04 Oct 2005 14:28:58 -0700 From: Maksim Yevmenkin User-Agent: Mozilla Thunderbird 0.7.1 (Windows/20040626) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Eric Anderson References: <431F388E.2010204@centtech.com> <43217D56.3050508@centtech.com> <4321D6C4.6050300@savvis.net> <432AC7E9.5060206@centtech.com> <433F4B50.1050108@centtech.com> <433F62F7.3060607@centtech.com> <43427296.6090404@centtech.com> <4342BC20.8000001@savvis.net> <4342CEEB.5010501@centtech.com> In-Reply-To: <4342CEEB.5010501@centtech.com> Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth mouse breaks on -current X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 04 Oct 2005 21:28:58 -0000 Eric, [...] >> this looks like the mouse is loosing the connection and trying to >> re-connect. > > Correct - the mouse would just stop working while I was using it, and > this particular mouse needs a button click to tell it to re-connect (as > if it was in power save mode). The reconnects you see, are me clicking > buttons to get it to come back alive. fine >>>>> [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) >> >> this is bad. something screwed up at usb level. basically we are >> trying to send commands to the local device (not mouse) and it does >> not respond. > > I agree - almost seems as though it's a faulty usb bluetooth adapter. well, may be. may be not. since the load is high during buildworld i wonder if this has something to do with interrupt latency. >> what is the model/make of the local bluetooth device (not mouse)? > > It's a built-in bluetooth adapter in my Sony laptop: > > ubt0: ALPS UGX, rev 1.10/11.68, addr 3 > ubt0: ALPS UGX, rev 1.10/11.68, addr 3 > ubt0: Interface 0 endpoints: interrupt=0x81, bulk-in=0x82, bulk-out=0x2 > ubt0: Interface 1 (alt.config 5) endpoints: isoc-in=0x83, isoc-out=0x3; > wMaxPacketSize=49; nframes=6, buffer size=294 thanks >> was buildworld still running? > > Yes > >> if buildworld was running can you tell what the load was? > > I can't recall what the load was at the time, but the CPU was close to > 100% utilized. hmm... >> what scheduler are you using BSD or ULE? > > ULE can you please try BSD? just to see if it makes any difference. also try to disable PREEMPTION (with both ULE and BSD). >> are you running with WITNESS enabled? > > No. good >> also how fast is the cpu on your machine? > > 1500MHZ. hmm... 1.5ghz, i wonder why your cpu is close to 100% during buildworld. it would be nice to know how much time system spends in "sys" etc. you have pretty fast cpu, so its kinda strange. > Full dmesg, and other info here: > > http://www.googlebit.com/freebsd/ > > Look for the most recent date. thanks >>>>> Oct 1 21:09:33 neutrino kernel: ubt0: detached >> >> ok, this is really bad. usb device should not just detach by itself >> (unless you pull it out). > > Actually, that was me flipping the switch (enable/disable wireless, > including bluetooth) on the laptop. ah, i see. [...] thanks, max