Looks like the discovery process fails if the SPD record is larger than 277 bytes.
Log below show a 'used size 310' which might be significant. This was working back in may, when I created the octopud example, but if failing now with same code base.
simon@womble:~/btstack-git-svn$ sudo src/BTdaemon BTdaemon started config.h: HAVE_RFCOMM Socket created at /tmp/BTstack Server up and running ... socket_connection_accept new connection 5 Nr Connections changed, new 1 hci_power_control: 1, current mode 0 New state: 1 Bluetooth status: 1 hci_read_buffer_size: used size 310, count 10, packet types 7f18 New state: 2 Bluetooth status: 2 SDP_REGISTER_SERVICE_RECORD size 277 Connection_incoming: 00:26:e2:ed:91:01, type 1 sending hci_accept_connection_request Connection_complete (status=0) 00:26:e2:ed:91:01 New connection: handle 42, 00:26:e2:ed:91:01 New nr connections: 1 Bluetooth status: 3 signaling handler code 4, state 6 signaling handler code 5, state 6 signaling handler code 6, state 7 Connection closed: handle 42, 00:26:e2:ed:91:01 New nr connections: 0
Bluetooth status: 2
Comment #1
Posted on Sep 29, 2011 by Swift Oxhi. if possible, please use the hci_dump facitlity to create hcidump or packetlogger logs. They contain all information.
I've recently rewritten (also) the SDP part to use 52 Bytes ACL packets in a minimal configuration. SDP can serve snippets of large records.
If I remember correctly the SDP record for WeBe++ is on a similar size, I can double check that.
Comment #2
Posted on Sep 30, 2011 by Quick Wombatrunning my code as
simon@womble:~/btstack-git-svn$ sudo ./example/octopud HCI_STATE_WORKING RFCOMM channel 1 was assigned to OctoPud1 by BTdaemon RFCOMM_EVENT_SERVICE_REGISTERED RFCOMM channel 2 was assigned to OctoPud2 by BTdaemon RFCOMM_EVENT_SERVICE_REGISTERED RFCOMM channel 3 was assigned to OctoPud3 by BTdaemon RFCOMM_EVENT_SERVICE_REGISTERED RFCOMM channel 4 was assigned to OctoPud4 by BTdaemon RFCOMM_EVENT_SERVICE_REGISTERED Using PIN 0000
^Csimon@womble:~/btstack-git-svn$
BTstack fails as
simon@womble:~/btstack-git-svn$ sudo ./src/BTdaemon BTdaemon started config.h: HAVE_RFCOMM Socket created at /tmp/BTstack Server up and running ... socket_connection_accept new connection 5 Nr Connections changed, new 1 hci_power_control: 1, current mode 0 New state: 1 Bluetooth status: 1 hci_read_buffer_size: used size 310, count 10, packet types 7f18 New state: 2 Bluetooth status: 2 SDP_REGISTER_SERVICE_RECORD size 290 SDP_REGISTER_SERVICE_RECORD size 290 SDP_REGISTER_SERVICE_RECORD size 290 SDP_REGISTER_SERVICE_RECORD size 290 Connection_incoming: 00:26:e2:ed:91:01, type 1 sending hci_accept_connection_request Connection_complete (status=0) 00:26:e2:ed:91:01 New connection: handle 42, 00:26:e2:ed:91:01 New nr connections: 1 Bluetooth status: 3 signaling handler code 4, state 6 signaling handler code 5, state 6 signaling handler code 6, state 7
simon@womble:~/btstack-git-svn$
Client device (LG Expo) hangs/timeouts when probing for services.
- octopud.c 19.07KB
- hci_dump.txt 6.23KB
- hci_dump.pklg 4.48KB
Comment #3
Posted on Sep 30, 2011 by Quick Wombatworking example with only 1 rfcomm port enabled and a smaller SDP record.
simon@womble:~/btstack-git-svn$ sudo ./src/BTdaemon BTdaemon started config.h: HAVE_RFCOMM Socket created at /tmp/BTstack Server up and running ... socket_connection_accept new connection 5 Nr Connections changed, new 1 hci_power_control: 1, current mode 0 New state: 1 Bluetooth status: 1 hci_read_buffer_size: used size 310, count 10, packet types 7f18 New state: 2 Bluetooth status: 2 SDP_REGISTER_SERVICE_RECORD size 147 Connection_incoming: 00:26:e2:ed:91:01, type 1 sending hci_accept_connection_request Connection_complete (status=0) 00:26:e2:ed:91:01 New connection: handle 42, 00:26:e2:ed:91:01 New nr connections: 1 Bluetooth status: 3 signaling handler code 4, state 6 signaling handler code 5, state 6 signaling handler code 6, state 7 Connection closed: handle 42, 00:26:e2:ed:91:01 New nr connections: 0 Bluetooth status: 2 Connection_incoming: 00:26:e2:ed:91:01, type 1 sending hci_accept_connection_request Connection_complete (status=0) 00:26:e2:ed:91:01 New connection: handle 43, 00:26:e2:ed:91:01 New nr connections: 1 Bluetooth status: 3 signaling handler code 4, state 6 signaling handler code 5, state 6 signaling handler code 6, state 7 rfcomm_max_frame_size_for_l2cap_mtu: 306 -> 300 L2CAP_EVENT_INCOMING_CONNECTION (l2cap_cid 0x42) for PSM_RFCOMM => acceptsignaling handler code 4, state 6 signaling handler code 5, state 6 L2CAP_EVENT_CHANNEL_OPENED for PSM_RFCOMM rfcomm_max_frame_size_for_l2cap_mtu: 306 -> 300 Received SABM #0 Sending UA #0 Multiplexer up and running Received UIH Parameter Negotiation Command for #2 rfcomm_channel_create for service 0x855b508, channel 1 --- begin -> Inform app Received Accept Connction Sending UIH Parameter Negotiation Respond for #2 Received SABM #2 Sending UA #2 Received MSC CMD for #2, Sending MSC CMD for #2 Sending MSC RSP for #2 Providing credits for #2 Received MSC RSP for #2 rfcomm_channel_opened! Sending UA after DISC for #2 Received DISC #0, (ougoing = 0) Sending UA #0 Closing down multiplexer signaling handler code 6, state 8 Connection closed: handle 43, 00:26:e2:ed:91:01 New nr connections: 0 Bluetooth status: 2 Nr Connections changed, new 0 No active client connection for 10 seconds -> POWER OFF hci_power_control: 0, current mode 2 New state: 3 Bluetooth status: 1 HCI_STATE_HALTING HCI_STATE_HALTING, calling off hci_power_control_off hci_power_control_off - hci_transport closed hci_power_control_off - control closed HCI_STATE_HALTING, emitting state New state: 0 Bluetooth status: 1
HCI_STATE_HALTING, done
- hci_dump.pklg 4.77KB
- hci_dump.txt 14.09KB
Comment #4
Posted on Oct 8, 2011 by Swift Oxhi. thanks for the logs. I don't see an error here, so far. The SDP record itself seems to be complete. With ACL Buffer size of 310 the 303 bytes packet should be fine.
Could you run hcidump on the linux side, too, and rerun the version with the large SDP record. I'm wondering if somehow the record doesn't get received in full. (and attach the logs from both sides)
Comment #5
Posted on Oct 11, 2011 by Quick WombatI seem to be seeing a segfault at present when doing a SDP browse from a remote machine to BTstack running my octopud example.
This occurs immediately if I have a large SDP record, or multiple records (rfcomm ports). This can also occur with a single/small record on the second browse, providing BTstack enters 'idle' - as indicated with "Bluetooth status: 2".
The segfault appears to be corrupt pointer being processed by the HCI layer.
Starting program: /home/simon/btstack-git-svn/src/BTdaemon BTdaemon started config.h: HAVE_RFCOMM Socket created at /tmp/BTstack Server up and running ... socket_connection_accept new connection 7 Nr Connections changed, new 1 hci_power_control: 1, current mode 0 New state: 1 Bluetooth status: 1 hci_read_buffer_size: used size 310, count 10, packet types 7f18 New state: 2 Bluetooth status: 2 SDP_REGISTER_SERVICE_RECORD size 147 Connection_incoming: 00:0f:b3:99:6b:cc, type 1 sending hci_accept_connection_request Connection_complete (status=0) 00:0f:b3:99:6b:cc New connection: handle 42, 00:0f:b3:99:6b:cc New nr connections: 1 Bluetooth status: 3 signaling handler code 4, state 6 signaling handler code 5, state 6 signaling handler code 6, state 7 Connection closed: handle 42, 00:0f:b3:99:6b:cc New nr connections: 0 Bluetooth status: 2 Connection_incoming: 00:0f:b3:99:6b:cc, type 1 sending hci_accept_connection_request Connection_complete (status=0) 00:0f:b3:99:6b:cc New connection: handle 43, 00:0f:b3:99:6b:cc New nr connections: 1 Bluetooth status: 3 signaling handler code 4, state 6 signaling handler code 5, state 6 signaling handler code 6, state 7
Program received signal SIGSEGV, Segmentation fault. 0x0804fe28 in l2cap_run () at l2cap.c:342 342 switch (channel->state){ (gdb) p *channel Cannot access memory at address 0x480
(gdb)
- bt_hci_dump.pklg 3.11KB
- bt_hci_dump.txt 8.3KB
- linux_hci_dump.txt 11.14KB
- linux_hci_dump.hcidump 2.51KB
Comment #6
Posted on Oct 14, 2011 by Quick WombatI might have a lead on this... browsing from my phone onto BlueGiga WT41 on serial port it reports a 'remote_mtu' of 512 and this functions up to (maximum) 8 records.
However when browsing with PC the 'remote_mtu' is 1024. If I have more that 2 records I'm getting segfaults, caused by memory corruption.
Where does BTstack determine the MTU of the local hardware, and specify it for it's local buffers? Simon
Comment #7
Posted on Oct 14, 2011 by Quick Wombatyes, SDP server is writing out of scope of the SDP record and corrupting other variables which it should not touch.
This is triggered by browsing from a Win7 PC, but not from phone.
'defered_list' is the linked list I am using for storing delay packets. It is nominally NULL.
-- Breakpoint 2, spd_append_range (context=0xbfffefbc, len=2, data=0x805b3a1 "\b\377\t") at sdp_util.c:362 362 memcpy(context->buffer, &data[context->startOffset], remainder_len); (gdb) p *context $11 = {buffer = 0x805a7f3 "", startOffset = 0, maxBytes = 93, usedBytes = 86, attributeIDList = 0x805a595 "5\005\n", complete = 1} (gdb) c Continuing.
Breakpoint 2, spd_append_range (context=0xbfffefbc, len=3, data=0xbfffef2d "\t") at sdp_util.c:362 362 memcpy(context->buffer, &data[context->startOffset], remainder_len); (gdb) c Continuing.
Breakpoint 2, spd_append_range (context=0xbfffefbc, len=12, data=0x805b3a6 "6") at sdp_util.c:362 362 memcpy(context->buffer, &data[context->startOffset], remainder_len); (gdb) p *context $12 = {buffer = 0x805a7f8 "\001", startOffset = 0, maxBytes = 88, usedBytes = 91, attributeIDList = 0x805a595 "5\005\n", complete = 1} (gdb) c Continuing. Hardware watchpoint 1: defered_list
Old value = (linked_list_t) 0x0 New value = (linked_list_t) 0x10901 0xb7ee25e3 in ?? () from /lib/i386-linux-gnu/libc.so.6 (gdb) p *defered_list Cannot access memory at address 0x10901 (gdb) p &defered_list $13 = (linked_list_t *) 0x805a800 (gdb) bt
0 0xb7ee25e3 in ?? () from /lib/i386-linux-gnu/libc.so.6
1 0x0804a585 in spd_append_range (context=0xbfffefbc, len=12, data=0x805b3a6 "6") at sdp_util.c:362
2 0x0804a6e0 in sdp_traversal_filter_attributes (attributeID=9, attributeValue=0x805b3a6 "6", type=DE_DES,
size=DE_SIZE_VAR_16, my_context=0xbfffefbc) at sdp_util.c:399
3 0x0804a273 in sdp_attribute_list_traverse_sequence (element=0x805b348 "6",
handler=0x804a5cb <sdp_traversal_filter_attributes>, context=0xbfffefbc) at sdp_util.c:259
4 0x0804a758 in sdp_filter_attributes_in_attributeIDList (record=0x805b348 "6", attributeIDList=0x805a595 "5\005\n",
startOffset=0, maxBytes=179, usedBytes=0xbffff036, buffer=0x805a79d "\t") at sdp_util.c:417
5 0x08055d60 in sdp_handle_service_search_attribute_request (packet=0x805a589 "\006", remote_mtu=200) at sdp.c:522
6 0x08055fd0 in sdp_packet_handler (packet_type=6 '\006', channel=64, packet=0x805a589 "\006", size=20) at sdp.c:600
7 0x0804f384 in l2cap_dispatch (channel=0x805d420, type=6 '\006', data=0x805a589 "\006", size=20) at l2cap.c:106
8 0x080510b1 in l2cap_acl_handler (packet=0x805a581 "* \030", size=28) at l2cap.c:917
9 0x080510fc in l2cap_packet_handler (packet_type=2 '\002', packet=0x805a581 "* \030", size=28) at l2cap.c:927
10 0x0804cbe4 in acl_handler (packet=0x805a581 "* \030", size=28) at hci.c:317
11 0x0804d5fa in packet_handler (packet_type=2 '\002', packet=0x805a581 "* \030", size=28) at hci.c:616
12 0x0804efc6 in h4_deliver_packet () at hci_transport_h4.c:228
13 0x0804f0d9 in h4_statemachine () at hci_transport_h4.c:263
14 0x0804f160 in h4_process (ds=0x805d060) at hci_transport_h4.c:293
15 0x08049844 in posix_execute () at run_loop_posix.c:166
16 0x080494ed in run_loop_execute () at run_loop.c:114
17 0x08056e5b in main (argc=1, argv=0xbffff3e4) at ../example/octopud.c:570
Comment #8
Posted on Mar 16, 2012 by Swift Ox(No comment was entered for this change.)
Status: Fixed
Labels:
Type-Defect
Priority-Medium