From owner-freebsd-bluetooth@FreeBSD.ORG Fri Jan 13 00:20:57 2006 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 2775016A420 for ; Fri, 13 Jan 2006 00:20:57 +0000 (GMT) (envelope-from scycoon@internode.on.net) Received: from ash25e.internode.on.net (ash25e.internode.on.net [203.16.214.182]) by mx1.FreeBSD.org (Postfix) with ESMTP id 9017243D46 for ; Fri, 13 Jan 2006 00:20:56 +0000 (GMT) (envelope-from scycoon@internode.on.net) Received: from internode.on.net (webmail1.adl2.internode.on.net [203.16.214.245]) by ash25e.internode.on.net (8.13.5/8.13.5) with ESMTP id k0D0KscH077378; Fri, 13 Jan 2006 10:50:54 +1030 (CST) (envelope-from scycoon@internode.on.net) Received: from 150.101.2.50 by HTTP Sender: scycoon@internode.on.net From: "scycoon@internode.on.net" To: Maksim Yevmenkin X-Mailer: scycoon - Internode Webmail v3.1r (http://www.internode.on.net/) X-Originating-IP: 150.101.2.50 Date: Fri, 13 Jan 2006 10:50:54 +1030 Message-id: <43c6f266.150.5ec4.2423@internode.on.net> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Cc: freebsd-bluetooth@freebsd.org Subject: Re: Bluetooth Device Failing to Initialize X-BeenThere: freebsd-bluetooth@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: scycoon@internode.on.net List-Id: Using Bluetooth in FreeBSD environments List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 13 Jan 2006 00:20:57 -0000 Max, This morning I thought I would cut out any posibility of hardware errors and bring the dongle and headset to work. Where I run; FreeBSD tardis 5.4-RELEASE FreeBSD 5.4-RELEASE #0 It has behaved exactly as I would have hoped. I can query the device, establish a connection and have had no problems at all. So, I still would like to get the device working at home. I will try your suggestions, and also some of Eric's, howto for FreeBSD 6 and get back to you. Thanks again Chriso > Chriso, > > > I have included the requested output below, > > thanks. lets see... > > [...] > > >>>Could not execute command "initialize". Device not > >>>configured > >> > >>this is *very* strange. > >> > >>1) did you check your /var/log/messages to see if device > > has detached? > > This is in the messages after I run /etc/rc.bluetooth > > after a fresh reboot; > > > > Jan 12 17:54:28 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x3, OCF=0x3. Timeout Jan 12 > 17:54:28 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=4 > > Jan 12 17:54:28 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:28 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > hmm... this does not make much sense to me :( what it > means is that the hci node tried to send command to the > device, but it did not get any response back from the > device in time (timed out). what happened next is that > the hci node received response back from the device, but > it did throw it away because it already timed out. > > i'm also concern about "ubt_request_complete2" error. it > might indicate that something is wrong at usb level. > > > Jan 12 17:54:33 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x4, OCF=0x9. Timeout Jan 12 > 17:54:33 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=10 > > Jan 12 17:54:33 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:33 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > here is the same sequence for another command > (READ_BD_ADDR) > > > Jan 12 17:54:38 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x4, OCF=0x3. Timeout Jan 12 > 17:54:38 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=12 > > Jan 12 17:54:38 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:38 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > and again (READ_LOCAL_FEATURES) > > > Jan 12 17:54:43 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x4, OCF=0x5. Timeout Jan 12 > 17:54:43 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=11 > > Jan 12 17:54:43 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:43 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > and again (READ_BUFFER_SIZE) > > > Jan 12 17:54:48 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x3, OCF=0x1a. Timeout Jan 12 > 17:54:48 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=4 > > Jan 12 17:54:48 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:48 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > and again (WRITE_SCAN_ENABLE) > > > Jan 12 17:54:53 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x3, OCF=0x24. Timeout Jan 12 > 17:54:53 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=4 > > Jan 12 17:54:53 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:53 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > and again (WRITE_UNIT_CLASS) > > > Jan 12 17:54:58 bigboy kernel: > > ng_hci_process_command_timeout: ubt0hci - unable to > > complete HCI command OGF=0x3, OCF=0x13. Timeout Jan 12 > 17:54:58 bigboy kernel: ng_hci_process_event: ubt0hci - > > got HCI event=0xe, length=4 > > Jan 12 17:54:58 bigboy kernel: complete_command: ubt0hci > > - no pending command, state=0x1 > > Jan 12 17:54:58 bigboy kernel: ubt_request_complete2: > > ubt0 - Control request failed. TIMEOUT (15) > > and again (CHANGE_LOCAL_NAME) > > also note interval between each chunks of errors - its 5 > second. which is a hci command timeout. > > >>2) can you please run as root the following commands > > > > bash-2.05b# ngctl types > > There are 7 total types: > > Type name Number of living nodes > > --------- ---------------------- > > socket 1 > > btsock_l2c 1 > > btsock_l2c_raw 1 > > btsock_hci_raw 1 > > l2cap 1 > > hci 1 > > ubt 1 > > > > bash-2.05b# ngctl li > > There are 7 total nodes: > > Name: ngctl704 Type: socket ID: > > 00000013 Num hooks: 0 Name: ubt0l2cap Type: > > l2cap ID: 0000000c Num hooks: 3 Name: > ubt0hci Type: hci ID: 00000008 Num > > hooks: 3 Name: btsock_l2c Type: btsock_l2c > > ID: 00000004 Num hooks: 1 Name: btsock_l2c_raw Type: > > btsock_l2c_raw ID: 00000003 Num hooks: 1 Name: > btsock_hci_raw Type: btsock_hci_raw ID: 00000002 Num > > hooks: 1 Name: ubt0 Type: ubt > ID: 00000001 Num hooks: 1 > > good. all nodes are still present and connected. > > > bash-2.05b# ngctl status ubt0: > > Status for "ubt0:": > > Hook: hook > > Flags: 0x30 > > Debug: 3 > > CMD queue: [have:0,max:12] > > ACL queue: [have:0,max:12] > > SCO queue: [have:0,max:12] > > looks good. > > > bash-2.05b# ngctl status ubt0hci: > > Status for "ubt0hci:": > > bdaddr 0:0:0:0:0:0 > > Hooks drv acl raw > > State 0x1 > > Queue cmd:0 > > Buffer cmd:1,acl:1,1,17,sco:1,1,10 > > aha! this is why "initialize" command failed. as i said > above, the hci node did not get any response back from > the device in time for every command in the > initialization sequence. so, as far as the hci node is > concerned the device was _not_ initialized correctly, i.e. > note that bdaddr is 0:0:0:0:0:0 etc. > > the reason you see correct output on the screen is because > data, received from the device, is copied to the "raw" > hook (where socket gets connected) _before_ they > processed by the hci node. > > this is a very strange failure mode that i have never seen > before. > > you could try to do a couple of things > > 1) comment out "reset" command in the rc.bluetooth script, > unplug/replug your device and run rc.bluetooth again. > > ## ${hccontrol} -n ${dev}hci reset || exit 1 > > 2) try to adjust the command timeout, i.e. add a couple of > lines before "reset" command > > ${sysctl} net.bluetooth.hci.command_timeout=10 > ${sysctl} net.bluetooth.hci.sockets.raw.ioctl_timeout=10 > > also, just to be on the safe side, could you please check > your /etc/devd.conf file and make sure you do not call > anything in response to ubt(4) attach/detach events. > > > also it would be nice if you could run hcidump (with > timestamp option) while you are running rc.bluetooth, > i.e. > > # hcidump -tX > > thanks, > max >