bluekitchen / btstack

Dual-mode Bluetooth stack, with small memory footprint.
http://bluekitchen-gmbh.com
Other
1.74k stars 618 forks source link

L2CAP Connection Oriented Channels examples #587

Closed Loc15 closed 7 months ago

Loc15 commented 7 months ago

Hi, I am writing a BTstack project with Pico W (RP2040), exactly I'm trying to do this, but I get L2CAP_CONNECTION_RESPONSE_RESULT_REFUSED_SECURITY after HCI_EVENT_PIN_CODE_REQUEST where I reversed Wii's Bluetooth address. I don't know really if doing well the implementation of L2CAP channels or if even it's possible to do this project with btstack .

To Reproduce

int btstack_main(int argc, const char * argv[]){
    (void)argc;
    (void)argv;

    // allow to get found by inquiry
    gap_discoverable_control(1);
    // use Limited Discoverable Mode; Peripheral;
    gap_set_class_of_device(0x2504);
    // set local name to be identified - zeroes will be replaced by actual BD ADDR
    gap_set_local_name(hid_device_name);
    // allow for role switch in general and sniff mode
    gap_set_default_link_policy_settings( LM_LINK_POLICY_ENABLE_SNIFF_MODE );
    // allow for role switch on outgoing connections - this allow HID Host to become master when we re-connect to it
    gap_set_allow_role_switch(true);

    gap_set_required_encryption_key_size(7);

    // L2CAP
    l2cap_init();

    l2cap_register_service(l2cap_handler, PSM_SDP, 0xffff, gap_get_security_level());
    l2cap_register_service(l2cap_handler, PSM_HID_INTERRUPT, 0xffff, gap_get_security_level());
    l2cap_register_service(l2cap_handler, PSM_HID_CONTROL, 0xffff, gap_get_security_level());

#ifdef ENABLE_BLE
    // Initialize LE Security Manager. Needed for cross-transport key derivation
    sm_init();
#endif

    // SDP Server
    sdp_init();
    memset(hid_service_buffer, 0, sizeof(hid_service_buffer));

    hid_sdp_record_t hid_sdp_record = {
        // hid sevice subclass 2504 Gamepad?, hid counntry code 33 US
        0x2504,
        33,
        1,
        1,
        1,
        0,
        0,
        0xFFFF,
        0xFFFF,
        3200,
        wiimote_bt_report_descriptor,
        sizeof(wiimote_bt_report_descriptor),
        hid_device_name
    };

    hid_create_sdp_record(hid_service_buffer, sdp_create_service_record_handle(), &hid_sdp_record);
    btstack_assert(de_get_len( hid_service_buffer) <= sizeof(hid_service_buffer));
    sdp_register_service(hid_service_buffer);

    // See https://www.bluetooth.com/specifications/assigned-numbers/company-identifiers if you don't have a USB Vendor ID and need a Bluetooth Vendor ID
    // device info: BlueKitchen GmbH, product 1, version 1
    device_id_create_sdp_record(pnp_service_buffer, sdp_create_service_record_handle(), DEVICE_ID_VENDOR_ID_SOURCE_BLUETOOTH, BLUETOOTH_COMPANY_ID_BLUEKITCHEN_GMBH, 1, 1);
    btstack_assert(de_get_len(pnp_service_buffer) <= sizeof(pnp_service_buffer));
    sdp_register_service(pnp_service_buffer);

    // HID Device
    hid_device_init(1, sizeof(wiimote_bt_report_descriptor),wiimote_bt_report_descriptor);

    // register for HCI events
    hci_event_callback_registration.callback = &packet_handler;
    hci_add_event_handler(&hci_event_callback_registration);

    // register for HID events
    hid_device_register_packet_handler(&packet_handler);

    // turn on!
    hci_power_control(HCI_POWER_ON);

    sscanf_bd_addr(remote_addr_string, wii_baddr);

    one_shot_timer_setup();

    return 0;
}

one_shot_timer_setup(); I setup a timer to try to connect every 1s directly to Wii with Bluetooth address calling this function:

void l2cap_outgoing_connection(bd_addr_t address) {
  l2cap_create_channel(l2cap_handler, address, PSM_SDP, 0xffff, &outgoing_sdp_cid);
  l2cap_create_channel(l2cap_handler, address, PSM_HID_CONTROL, 0xffff, &outgoing_control_cid);
  l2cap_create_channel(l2cap_handler, address, PSM_HID_INTERRUPT, 0xffff, &outgoing_interrupt_cid);
}

Expected behavior

HCI Packet Logs

[00:00:00.001] LOG -- btstack_tlv_flash_bank.c.491: found bank 0
[00:00:00.004] LOG -- btstack_tlv_flash_bank.c.227: test erased: bank 0, offset 704
[00:00:00.012] LOG -- btstack_tlv_flash_bank.c.526: Flash clean after last found tag
[00:00:00.019] LOG -- btstack_tlv_flash_bank.c.541: write offset 2c0
[00:00:00.025] LOG -- btstack_tlv.c.48: TLV Instance 1002D4C4
[00:00:00.031] LOG -- le_device_db_tlv.c.159: num valid le device entries 0
[00:00:00.037] LOG -- l2cap.c.4796: L2CAP_REGISTER_SERVICE psm 0x1 mtu 65535
[00:00:00.044] LOG -- l2cap.c.4796: L2CAP_REGISTER_SERVICE psm 0x13 mtu 65535
[00:00:00.051] LOG -- l2cap.c.4796: L2CAP_REGISTER_SERVICE psm 0x11 mtu 65535
[00:00:00.058] LOG -- l2cap.c.4796: L2CAP_REGISTER_SERVICE psm 0x1 mtu 65535
[00:00:00.064] LOG -- l2cap.c.4801: register: PSM 1 already registered
[00:00:00.071] LOG -- l2cap.c.4796: L2CAP_REGISTER_SERVICE psm 0x13 mtu 100
[00:00:00.077] LOG -- l2cap.c.4801: register: PSM 19 already registered
[00:00:00.083] LOG -- l2cap.c.4796: L2CAP_REGISTER_SERVICE psm 0x11 mtu 100
[00:00:00.090] LOG -- l2cap.c.4801: register: PSM 17 already registered
[00:00:00.097] LOG -- hci.c.5207: hci_power_control: 1, current mode 0
[00:00:00.972] LOG -- hci.c.7684: BTSTACK_EVENT_STATE 1
[00:00:00.974] EVT <= 60 01 01 
[00:00:00.978] CMD => 03 0C 00 
[00:00:00.980] EVT <= 6E 00 
[00:00:01.022] EVT <= 0E 04 01 03 0C 00 
[00:00:01.023] CMD => 01 10 00 
[00:00:01.026] EVT <= 6E 00 
[00:00:01.029] EVT <= 0E 0C 01 01 10 00 0B 00 00 0B 31 01 10 23 
[00:00:01.034] LOG -- hci.c.2841: Treat Cypress/Infineon as Broadcom
[00:00:01.040] LOG -- hci.c.2849: Manufacturer: 0x000f
[00:00:01.045] CMD => 14 0C 00 
[00:00:01.048] EVT <= 6E 00 
[00:00:01.051] EVT <= 0E FC 01 14 0C 00 53 44 49 4F 20 33 37 5F 34 4D 20 77 6C 62 67 61 5F 42 55 20 52 50 49 00 00 00 00 00 00 00 
[00:00:01.119] LOG -- hci.c.2695: local name: SDIO 37_4M wlbga_BU RPI
[00:00:01.125] CMD => 02 10 00 
[00:00:01.128] EVT <= 6E 00 
[00:00:01.131] EVT <= 0E 44 01 02 10 00 FF FF FF 03 CC FF 0F FF FF FF FC 1F F2 0F E8 FE 3F F7 8F FF 1C 00 04 00 61 F7 FF FF 7F F8 
[00:00:01.151] LOG -- hci.c.2663: Command 0x00 supported 2/5
[00:00:01.156] LOG -- hci.c.2663: Command 0x01 supported 10/4
[00:00:01.162] LOG -- hci.c.2663: Command 0x02 supported 14/7
[00:00:01.167] LOG -- hci.c.2663: Command 0x03 supported 18/3
[00:00:01.172] LOG -- hci.c.2663: Command 0x04 supported 20/4
[00:00:01.178] LOG -- hci.c.2663: Command 0x05 supported 22/2
[00:00:01.183] LOG -- hci.c.2663: Command 0x06 supported 24/6
[00:00:01.189] LOG -- hci.c.2663: Command 0x07 supported 32/1
[00:00:01.194] LOG -- hci.c.2663: Command 0x08 supported 32/3
[00:00:01.200] LOG -- hci.c.2663: Command 0x09 supported 32/6
[00:00:01.205] LOG -- hci.c.2663: Command 0x0a supported 34/0
[00:00:01.211] LOG -- hci.c.2663: Command 0x0b supported 35/1
[00:00:01.216] LOG -- hci.c.2663: Command 0x0c supported 35/3
[00:00:01.222] LOG -- hci.c.2668: Local supported commands summary 00001fff
[00:00:01.228] LOG -- btstack_crypto.c.1121: controller supports ECDH operation: 1
[00:00:01.236] LOG -- hci.c.1868: Set Public BD ADDR to 28:CD:C1:06:5C:6B
[00:00:01.242] CMD => 01 FC 06 6B 5C 06 C1 CD 28 
[00:00:01.247] EVT <= 6E 00 
[00:00:01.250] EVT <= 0E 04 01 01 FC 00 
[00:00:01.253] CMD => 09 10 00 
[00:00:01.256] EVT <= 6E 00 
[00:00:01.259] EVT <= 0E 0A 01 09 10 00 6B 5C 06 C1 CD 28 
[00:00:01.264] LOG -- hci.c.2792: Local Address, Status: 0x00: Addr: 28:CD:C1:06:5C:6B
[00:00:01.271] CMD => 05 10 00 
[00:00:01.274] EVT <= 6E 00 
[00:00:01.277] EVT <= 0E 0B 01 05 10 00 FD 03 40 08 00 0A 00 
[00:00:01.282] LOG -- hci.c.2710: hci_read_buffer_size: ACL size module 1021 -> used 1021, count 3 / SCO size 64, count 3
[00:00:01.293] CMD => 03 10 00 
[00:00:01.296] EVT <= 6E 00 
[00:00:01.299] EVT <= 0E 0C 01 03 10 00 BF FE CF FE DB FF 7B 87 
[00:00:01.304] LOG -- hci.c.2826: ACL Packet types ff1e
[00:00:01.309] LOG -- hci.c.2830: SCO Packet types 03ff - eSCO 1
[00:00:01.315] LOG -- hci.c.2833: BR/EDR support 1, LE support 1
[00:00:01.320] CMD => 33 0C 07 00 04 78 03 00 03 00 
[00:00:01.325] EVT <= 6E 00 
[00:00:01.328] EVT <= 0E 04 01 33 0C 00 
[00:00:01.331] CMD => 31 0C 01 03 
[00:00:01.335] EVT <= 6E 00 
[00:00:01.338] EVT <= 0E 04 01 31 0C 00 
[00:00:01.341] CMD => 01 0C 08 FF FF FF FF FF FF FF 3F 
[00:00:01.346] EVT <= 6E 00 
[00:00:01.349] EVT <= 0E 04 01 01 0C 00 
[00:00:01.352] CMD => 63 0C 08 00 00 00 02 00 00 00 00 
[00:00:01.357] EVT <= 6E 00 
[00:00:01.360] EVT <= 0E 04 01 63 0C 00 
[00:00:01.363] CMD => 56 0C 01 01 
[00:00:01.367] EVT <= 6E 00 
[00:00:01.472] EVT <= 0E 04 01 56 0C 00 
[00:00:01.473] CMD => 45 0C 01 00 
[00:00:01.476] EVT <= 6E 00 
[00:00:01.479] EVT <= 0E 04 01 45 0C 00 
[00:00:01.482] CMD => 7A 0C 01 01 
[00:00:01.485] EVT <= 6E 00 
[00:00:01.488] EVT <= 0E 04 01 7A 0C 00 
[00:00:01.491] CMD => 2F 0C 01 01 
[00:00:01.495] EVT <= 6E 00 
[00:00:01.498] EVT <= 0E 04 01 2F 0C 00 
[00:00:01.501] CMD => 5B 0C 01 01 
[00:00:01.504] EVT <= 6E 00 
[00:00:01.507] EVT <= 0E 04 01 5B 0C 00 
[00:00:01.510] LOG -- hci.c.2115: BCM: Route SCO data via HCI transport
[00:00:01.516] CMD => 1C FC 05 01 00 00 00 00 
[00:00:01.521] EVT <= 6E 00 
[00:00:01.524] EVT <= 0E 04 01 1C FC 00 
[00:00:01.527] CMD => 02 20 00 
[00:00:01.530] EVT <= 6E 00 
[00:00:01.533] EVT <= 0E 07 01 02 20 00 FB 00 08 
[00:00:01.537] LOG -- hci.c.2740: hci_le_read_buffer_size: acl size 251, acl count 8
[00:00:01.544] CMD => 6D 0C 02 01 00 
[00:00:01.548] EVT <= 6E 00 
[00:00:01.551] EVT <= 0E 04 01 6D 0C 00 
[00:00:01.554] CMD => 01 20 08 FF FD FF FF 07 00 00 00 
[00:00:01.559] EVT <= 6E 00 
[00:00:01.562] EVT <= 0E 04 01 01 20 00 
[00:00:01.565] CMD => 0F 20 00 
[00:00:01.568] EVT <= 6E 00 
[00:00:01.571] EVT <= 0E 05 01 0F 20 00 80 
[00:00:01.574] LOG -- hci.c.2753: hci_le_read_white_list_size: size 128
[00:00:01.581] CMD => 24 0C 03 04 25 00 
[00:00:01.585] EVT <= 6E 00 
[00:00:01.588] EVT <= 0E 04 01 24 0C 00 
[00:00:01.591] CMD => 13 0C F8 4E 69 6E 74 65 6E 64 6F 20 52 56 4C 2D 43 4E 54 2D 30 31 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
[00:00:01.659] EVT <= 6E 00 
[00:00:01.661] EVT <= 0E 04 01 13 0C 00 
[00:00:01.664] CMD => 52 0C F1 00 14 09 4E 69 6E 74 65 6E 64 6F 20 52 56 4C 2D 43 4E 54 2D 30 31 00 00 00 00 00 00 00 00 00 00 00 
[00:00:01.730] EVT <= 6E 00 
[00:00:01.733] EVT <= 0E 04 01 52 0C 00 
[00:00:01.736] CMD => 0F 08 02 04 00 
[00:00:01.740] EVT <= 6E 00 
[00:00:01.743] EVT <= 0E 04 01 0F 08 00 
[00:00:01.746] CMD => 18 0C 02 00 60 
[00:00:01.750] EVT <= 6E 00 
[00:00:01.752] EVT <= 0E 04 01 18 0C 00 
[00:00:01.756] CMD => 1A 0C 01 03 
[00:00:01.759] EVT <= 6E 00 
[00:00:01.762] EVT <= 0E 04 01 1A 0C 00 
[00:00:01.765] EVT <= 66 02 01 01 
[00:00:01.768] CMD => 0B 20 07 01 E0 01 30 00 00 00 
[00:00:01.773] EVT <= 6E 00 
[00:00:01.776] EVT <= 0E 04 01 0B 20 00 
[00:00:01.779] LOG -- hci.c.1805: hci_init_done -> HCI_STATE_WORKING
[00:00:01.785] LOG -- hci.c.7684: BTSTACK_EVENT_STATE 2
[00:00:01.790] EVT <= 60 01 02 
[00:00:01.793] LOG -- sm.c.3726: HCI Working!
[00:00:01.797] LOG -- btstack_tlv_flash_bank.c.373: Found tag '534d4552' at position 188
[00:00:01.805] LOG -- sm.c.3733: ER from TLV
[00:00:01.809] LOG -- btstack_util.c.314: ER     96B8303BAF080829541FD956EFB748AE
[00:00:01.816] LOG -- btstack_tlv_flash_bank.c.373: Found tag '534d4952' at position 212
[00:00:01.824] LOG -- sm.c.3678: IR from TLV
[00:00:01.828] LOG -- btstack_util.c.314: IR     069DD9F6F7C3301AE1422B32FDA23451
[00:00:01.835] LOG -- hci.c.8531: hci_le_set_own_address_type: old 0, new 0
[00:00:01.842] LOG -- sm.c.2140: DKG_CALC_IRK started
[00:00:01.847] LOG -- btstack_util.c.314: irk    3383E5C779D9398024FAF0AF8FB44F72
[00:00:01.856] LOG -- sm.c.2151: DKG_CALC_DHK started
[00:00:01.859] LOG -- btstack_util.c.314: dhk    DAA2F0CCE97108E3F01E4A5BFC8D9397
[00:00:01.983] LOG -- l2cap.c.2501: create channel addr D8:6B:F7:79:63:26 psm 0x1 mtu 65535 -> local mtu 1691, sec level 0
[00:00:01.992] LOG -- l2cap.c.2466: create channel 20005D30, local_cid 0x0041
[00:00:01.998] LOG -- hci.c.7295: Create_connection to D8:6B:F7:79:63:26
[00:00:02.005] LOG -- hci.c.316: create_connection_for_addr D8:6B:F7:79:63:26, type fd
[00:00:02.012] LOG -- hci.c.7314: conn state 0
[00:00:02.017] CMD => 05 04 0D 26 63 79 F7 6B D8 18 CC 00 00 00 00 01 
[00:00:02.023] EVT <= 6E 00 
[00:00:02.026] LOG -- l2cap.c.2501: create channel addr D8:6B:F7:79:63:26 psm 0x11 mtu 65535 -> local mtu 1691, sec level 2
[00:00:02.036] LOG -- l2cap.c.2466: create channel 20005C7C, local_cid 0x0042
[00:00:02.043] LOG -- l2cap.c.2501: create channel addr D8:6B:F7:79:63:26 psm 0x13 mtu 65535 -> local mtu 1691, sec level 2
[00:00:02.054] LOG -- l2cap.c.2466: create channel 20005BC8, local_cid 0x0043
[00:00:02.062] EVT <= 0F 04 00 01 05 04 
[00:00:02.065] LOG -- hci.c.7295: Create_connection to D8:6B:F7:79:63:26
[00:00:02.071] LOG -- hci.c.7314: conn state 1
[00:00:02.075] LOG -- hci.c.7295: Create_connection to D8:6B:F7:79:63:26
[00:00:02.081] LOG -- hci.c.7314: conn state 1
[00:00:02.212] EVT <= 12 08 00 26 63 79 F7 6B D8 01 
[00:00:02.460] EVT <= 03 0B 13 0B 00 26 63 79 F7 6B D8 01 00 
[00:00:02.463] LOG -- hci.c.3564: Connection_complete (status=19) D8:6B:F7:79:63:26
[00:00:02.470] LOG -- hci.c.2502: Outgoing connection to D8:6B:F7:79:63:26 failed
[00:00:02.478] LOG -- l2cap.c.1135: L2CAP_EVENT_CHANNEL_OPENED status 0x13 addr D8:6B:F7:79:63:26 handle 0xffff psm 0x1 local_cid0
[00:00:02.495] LOG -- l2cap.c.1152: ERTM mode 0, fcs enabled 0
[00:00:02.500] EVT <= 70 18 13 26 63 79 F7 6B D8 FF FF 01 00 41 00 00 00 9B 06 A0 02 00 00 00 00 00 
channel open
L2CAP connection failed (cid 65, status 0x13)
[00:00:02.514] LOG -- l2cap.c.2472: free channel 20005D30, local_cid 0x0041
[00:00:02.521] LOG -- l2cap.c.1410: l2cap_stop_rtx for local cid 0x41
[00:00:02.527] LOG -- l2cap.c.358: Stop Retransmission timer
[00:00:02.533] LOG -- l2cap.c.344: Stop Monitor timer
[00:00:02.537] LOG -- l2cap.c.1135: L2CAP_EVENT_CHANNEL_OPENED status 0x13 addr D8:6B:F7:79:63:26 handle 0xffff psm 0x11 local_ci0
[00:00:02.555] LOG -- l2cap.c.1152: ERTM mode 0, fcs enabled 0
[00:00:02.560] EVT <= 70 18 13 26 63 79 F7 6B D8 FF FF 11 00 42 00 00 00 9B 06 A0 02 00 00 00 00 00 
channel open
L2CAP connection failed (cid 66, status 0x13)
[00:00:02.574] LOG -- l2cap.c.2472: free channel 20005C7C, local_cid 0x0042
[00:00:02.581] LOG -- l2cap.c.1410: l2cap_stop_rtx for local cid 0x42
[00:00:02.587] LOG -- l2cap.c.358: Stop Retransmission timer
[00:00:02.593] LOG -- l2cap.c.344: Stop Monitor timer
[00:00:02.597] LOG -- l2cap.c.1135: L2CAP_EVENT_CHANNEL_OPENED status 0x13 addr D8:6B:F7:79:63:26 handle 0xffff psm 0x13 local_ci0
[00:00:02.615] LOG -- l2cap.c.1152: ERTM mode 0, fcs enabled 0
[00:00:02.620] EVT <= 70 18 13 26 63 79 F7 6B D8 FF FF 13 00 43 00 00 00 9B 06 A0 02 00 00 00 00 00 
channel open
L2CAP connection failed (cid 67, status 0x13)
[00:00:02.635] LOG -- l2cap.c.2472: free channel 20005BC8, local_cid 0x0043
[00:00:02.641] LOG -- l2cap.c.1410: l2cap_stop_rtx for local cid 0x43
[00:00:02.647] LOG -- l2cap.c.358: Stop Retransmission timer
[00:00:02.653] LOG -- l2cap.c.344: Stop Monitor timer
[00:00:03.062] LOG -- l2cap.c.2501: create channel addr D8:6B:F7:79:63:26 psm 0x1 mtu 65535 -> local mtu 1691, sec level 0
[00:00:03.070] LOG -- l2cap.c.2466: create channel 20005BC8, local_cid 0x0044
[00:00:03.077] LOG -- hci.c.7295: Create_connection to D8:6B:F7:79:63:26
[00:00:03.083] LOG -- hci.c.316: create_connection_for_addr D8:6B:F7:79:63:26, type fd
[00:00:03.091] LOG -- hci.c.7314: conn state 0
[00:00:03.095] CMD => 05 04 0D 26 63 79 F7 6B D8 18 CC 00 00 00 00 01 
[00:00:03.102] EVT <= 6E 00 
[00:00:03.104] LOG -- l2cap.c.2501: create channel addr D8:6B:F7:79:63:26 psm 0x11 mtu 65535 -> local mtu 1691, sec level 2
[00:00:03.115] LOG -- l2cap.c.2466: create channel 20005C7C, local_cid 0x0045
[00:00:03.122] LOG -- l2cap.c.2501: create channel addr D8:6B:F7:79:63:26 psm 0x13 mtu 65535 -> local mtu 1691, sec level 2
[00:00:03.133] LOG -- l2cap.c.2466: create channel 20005D30, local_cid 0x0046
[00:00:03.140] EVT <= 0F 04 00 01 05 04 
[00:00:03.143] LOG -- hci.c.7295: Create_connection to D8:6B:F7:79:63:26
[00:00:03.150] LOG -- hci.c.7314: conn state 1
[00:00:03.154] LOG -- hci.c.7295: Create_connection to D8:6B:F7:79:63:26
[00:00:03.160] LOG -- hci.c.7314: conn state 1
[00:00:03.362] EVT <= 12 08 00 26 63 79 F7 6B D8 01 
[00:00:03.515] EVT <= 03 0B 00 0B 00 26 63 79 F7 6B D8 01 00 
[00:00:03.517] LOG -- hci.c.3564: Connection_complete (status=0) D8:6B:F7:79:63:26
[00:00:03.525] LOG -- hci.c.3601: New connection: handle 11, D8:6B:F7:79:63:26
[00:00:03.532] LOG -- hci.c.7753: BTSTACK_EVENT_NR_CONNECTIONS_CHANGED 1
[00:00:03.538] EVT <= 61 01 01 
[00:00:03.541] LOG -- l2cap.c.2374: connection complete con_handle 000b - for channel 20005BC8 cid 0x0044
[00:00:03.550] LOG -- l2cap.c.2374: connection complete con_handle 000b - for channel 20005C7C cid 0x0045
[00:00:03.560] CMD => 1B 04 02 0B 00 
[00:00:03.563] EVT <= 6E 00 
[00:00:03.566] ACL => 0B 00 0C 00 08 00 01 00 02 01 04 00 01 00 44 00 
[00:00:03.572] EVT <= 6E 00 
[00:00:03.574] LOG -- l2cap.c.1410: l2cap_stop_rtx for local cid 0x44
[00:00:03.580] LOG -- l2cap.c.1447: l2cap_start_rtx for local cid 0x44
[00:00:03.587] LOG -- l2cap.c.2374: connection complete con_handle 000b - for channel 20005D30 cid 0x0046
[00:00:03.597] EVT <= 0F 04 00 01 1B 04 
[00:00:03.600] EVT <= CD 09 0B 00 00 26 63 79 F7 6B D8 
[00:00:03.605] LOG -- sm.c.2263: LE Device Lookup: not found
[00:00:03.610] EVT <= CE 09 0B 00 00 26 63 79 F7 6B D8 
[00:00:03.616] EVT <= 0B 0B 00 0B 00 FF FF 8D FE 9B F9 00 80 
[00:00:03.620] CMD => 1C 04 03 0B 00 01 
[00:00:03.624] EVT <= 6E 00 
[00:00:03.627] EVT <= 13 05 01 0B 00 01 00 
[00:00:03.631] EVT <= 05 04 00 0B 00 13 
[00:00:03.634] LOG -- l2cap.c.1135: L2CAP_EVENT_CHANNEL_OPENED status 0x6a addr D8:6B:F7:79:63:26 handle 0xb psm 0x13 local_cid 00
[00:00:03.651] LOG -- l2cap.c.1152: ERTM mode 0, fcs enabled 0
[00:00:03.657] EVT <= 70 18 6A 26 63 79 F7 6B D8 0B 00 13 00 46 00 00 00 9B 06 A0 02 00 00 00 00 00 
channel open
L2CAP connection failed (cid 70, status 0x6a)
[00:00:03.671] LOG -- l2cap.c.2472: free channel 20005D30, local_cid 0x0046
[00:00:03.678] LOG -- l2cap.c.1410: l2cap_stop_rtx for local cid 0x46
[00:00:03.684] LOG -- l2cap.c.358: Stop Retransmission timer
[00:00:03.689] LOG -- l2cap.c.344: Stop Monitor timer
[00:00:03.694] LOG -- l2cap.c.1135: L2CAP_EVENT_CHANNEL_OPENED status 0x6a addr D8:6B:F7:79:63:26 handle 0xb psm 0x11 local_cid 00
[00:00:03.711] LOG -- l2cap.c.1152: ERTM mode 0, fcs enabled 0
[00:00:03.717] EVT <= 70 18 6A 26 63 79 F7 6B D8 0B 00 11 00 45 00 00 00 9B 06 A0 02 00 00 00 00 00 

Environment: (please complete the following information):

mringwal commented 7 months ago

If you open the hci log in wireshark after converting it with tool/create_packet_log.py (see attached file), we can see 2 connection attempts. Weirdly, there's a role change event before the connection has been established. 200ms there's a connection complete, remote terminated.

The second is a bit better. The role change also comes before the successful connection complete - so this might be ok. Then, BTstack queries the remote features and also tries to open an SDP connection, but gets no result for the Read Remote Extended Features requests or gets a response for the L2CAP request, before the remote disconnect.

There's no PIN Request in the HCI log.

While BTstack can handle the 3 parallel L2CAP connections, I'd set them up one by one. Also, as this will be an HID Device, I would suggest to try the hid_keyboard / hid_mouse example although the behaviour should be the same. Can you try with a support USB Bluetooth dongle on a mac/linux/windows and port/libusb or port/windows-winusb?

There's no issue in BTstack. Feel free to post on the mailing list about your progress with the Wii.

loc15-wii.pklg.zip

Loc15 commented 7 months ago

I don't gonna lie man, I'm little lost. I compile the emulator try to connect to wii but before of that, I erase all wii remote pairing pressing sync button on the console. I found that try to connect directly with the mac address the emulator doesn't work, it's doesn't connect. But if I put the emulator on listen for incoming connections mode it connect after you press sync button on the console, and after that I can to connect directly with the mac address. I got logs from wireshark for both cases.
What would be a better way to emulate what is in the search_wii file with btstack? Thanks for your help. connect_direct.pcapng.zip search_wii.pcapng.zip

mringwal commented 7 months ago

According to this Wii Emulator, the Wii must initiate the first connecting and start the pairing. So you need to make the Wii connect to your BTstack app. Before it connects, it will do an Inquiry and all it receives are the Class of Device and the Remote Name. In the log, they use CoD 0x2504 and change the name to "Nintendo RVL-CNT-01". You can set these two e.g. in the hid_keyboard_demo and try to connect from Wii. After that, you're almost done. I'm closing this as this it not an issue of the stack, just your application.

Again, Feel free to post on the mailing list about your progress with the Wii. @ricardoquesada from bluepad32 might have some ideas as well.

ricardoquesada commented 7 months ago

@Loc15: this might help you:

From: https://wiibrew.org/wiki/Wiimote#Bluetooth_Pairing:

If connecting by holding down the 1+2 buttons, the PIN is the bluetooth address of the wiimote backwards, if connecting by pressing the "sync" button on the back of the wiimote, then the PIN is the bluetooth address of the host backwards.

If you need to debug it from the "wii" side, as @mringwal mentioned, you can try running Bluepad32 on another device (picow,esp32,linux or macos) and see why it be sending incorrect packets.

Loc15 commented 7 months ago

@ricardoquesada I try on bluepad32 and it connect:

properties:
bp.bt.allow_en = false
No TLV for bp.bt.allowlist, returning default value
bp.bt.allowlist = <empty>
bp.ble.enabled = true
bp.gap.inq_len = 3
bp.gap.level = 2
bp.gap.max_len = 5
bp.gap.min_len = 4
bp.mouse.scale = 1.000000
No TLV for bp.version, returning default value
bp.version = '4.0.3'
bp.virt_dev_en = false
BR/EDR scan -> 1
BLE scan -> 1
posix_on_oob_event: Bluetooth enabled: 1
Device found: 28:CD:C1:06:5C:6B with COD: 0x002504, pageScan 1, clock offset 0x5a0d, rssi 234 dBm, name 'Nintendo RVL-CNT-01'
Creating device: 28:CD:C1:06:5C:6B (idx=0)
uni_bt_process_fsm, bd addr:28:CD:C1:06:5C:6B,  state: 4, incoming:0
uni_bt_process_fsm: Starting L2CAP connection
--> HCI_EVENT_CONNECTION_COMPLETE
SM_EVENT_IDENTITY_RESOLVING_STARTED
Identity resolving failed for 28:CD:C1:06:5C:6B

--> HCI_EVENT_LINK_KEY_REQUEST:
SSP User Confirmation Request with numeric value '926270'
SSP User Confirmation Auto accept
--> HCI_EVENT_AUTHENTICATION_COMPLETE_EVENT: status=0, handle=0x0001
L2CAP_EVENT_CHANNEL_OPENED (channel=0x0041)
PSM: 0x0011, local CID=0x0041, remote CID=0x0041, handle=0x0001, incoming=0, local MTU=1691, remote MTU=100, addr=28:CD:C1:06:5C:6B
HID Control opened, cid 0x41
uni_bt_process_fsm, bd addr:28:CD:C1:06:5C:6B,  state: 10, incoming:0
uni_bt_process_fsm: Create L2CAP interrupt connection
L2CAP_EVENT_CHANNEL_OPENED (channel=0x0042)
PSM: 0x0013, local CID=0x0042, remote CID=0x0042, handle=0x0001, incoming=0, local MTU=1691, remote MTU=100, addr=28:CD:C1:06:5C:6B
HID Interrupt opened, cid 0x42
Device 28:CD:C1:06:5C:6B is connected
posix: device connected: 0x55a29bbffe80
uni_bt_process_fsm, bd addr:28:CD:C1:06:5C:6B,  state: 12, incoming:0
uni_bt_process_fsm: starting SDP query
-----------> sdp_query_start()
Starting SDP VID/PID query for 28:CD:C1:06:5C:6B
Vendor ID: 0x057e - Product ID: 0x0306
Duplicate controller entry found for VID 0x0f0d PID 0x00ed (83,437)
Duplicate controller entry found for VID 0x146b PID 0x0d10 (100,101)
Duplicate controller entry found for VID 0x0e6f PID 0x02a1 (311,483)
Duplicate controller entry found for VID 0x0e6f PID 0x02a2 (312,484)
Duplicate controller entry found for VID 0x0e6f PID 0x02a5 (315,485)
Duplicate controller entry found for VID 0x0e6f PID 0x02a7 (317,440)
Duplicate controller entry found for VID 0x0e6f PID 0x02a8 (318,443)
Duplicate controller entry found for VID 0x0e6f PID 0x02bd (331,487)
Duplicate controller entry found for VID 0x0e6f PID 0x02bf (333,488)
Duplicate controller entry found for VID 0x0e6f PID 0x02c0 (334,489)
Duplicate controller entry found for VID 0x0e6f PID 0x02c6 (340,490)
Device detected as Wii controller: 0x23
uni_bt_process_fsm, bd addr:28:CD:C1:06:5C:6B,  state: 6, incoming:0
uni_bt_process_fsm: querying HID descriptor
Device 28:CD:C1:06:5C:6B does not need a HID descriptor, skipping query.
<----------- sdp_query_end()
uni_bt_process_fsm, bd addr:28:CD:C1:06:5C:6B,  state: 8, incoming:0
uni_bt_process_fsm: Device is ready
fsm: req_status
Device cannot connect in time, deleting:
    btaddr: 28:CD:C1:06:5C:6B
    bt: handle=1 (ACL), hids_cid=0, ctrl_cid=0x0041, intr_cid=0x0042, cod=0x00002504, flags=0x00003b00, incoming=0
    model: vid=0x057e, pid=0x0306, model='Wii', name='Nintendo RVL-CNT-01'
    battery: 0 / 255, type=unknown
    Wii: device 'Unknown', extension 'N/A'
Disconnecting device: 28:CD:C1:06:5C:6B
posix: device disconnected: 0x55a29bbffe80
Deleting device: 28:CD:C1:06:5C:6B
L2CAP_EVENT_CHANNEL_CLOSED: 0x0042 (channel=0x0042)
Couldn't not find hid_device for cid = 0x0042
L2CAP_EVENT_CHANNEL_CLOSED: 0x0041 (channel=0x0041)
Couldn't not find hid_device for cid = 0x0041
--> HCI_EVENT_DISCONNECTION_COMPLETE
^CCTRL-C - SIGINT received, shutting down..

but on the console... doesn't work

ricardoquesada commented 7 months ago

mmm... I wouldn't k now then :(

ricardoquesada commented 7 months ago

mmm... wait... it says "Device cannot connect in time, deleting".

That means that it couldn't finish the setup. Probably Wii console is sending you a request, and you are not answering it.

Loc15 commented 7 months ago

but it already connected right? because on wii console it even fail to create l2cap connection

ricardoquesada commented 7 months ago

It connected at L2CAP level... but it didn't finish the setup.

But if you are having issues at L2CAP level, then I wouldn't know.

Loc15 commented 7 months ago

When bluepad send fsm: req_status and calls uni_hid_device_send_intr_report function should I get this data on L2CAP_DATA_PACKET event right ?

ricardoquesada commented 7 months ago

yes, I guess... in the end it calls l2cap_send(), so it should trigger a L2CAP_DATA_PACKET ... but not 100% sure

Loc15 commented 7 months ago

so it should trigger a L2CAP_DATA_PACKET

Yeah, that was what I thought, but no data arrives at that event. So weird.

Loc15 commented 7 months ago

@mringwal Hey man, one question, how to set a inquire access code ? I found this on internet : hci_send_cmd(&hci_inquiry, HCI_INQUIRY_LIMITED, INQUIRY_INTERVAL, 0); but after this the search stop. I'm using the gap_inquiry.c example. I enabled DUT mode too before. I want to set IAC to 0x9E8B00. Thanks.

mringwal commented 7 months ago

you can call

/**

Loc15 commented 7 months ago

@mringwal Thanks mate. I've been able to progress in the development, but now I'm getting this error Ignore invalid report data packet, invalid size and I can't receive data from the Wii. Do you know what I'm doing wrong ? log_invalid report.zip

Loc15 commented 7 months ago

Fixed, it was a error in the HID descriptor

mringwal commented 7 months ago

Excellent. My guess would have been: either your HID report had the wrong length, or your HID descriptor isn't valid/does not match.

Loc15 commented 7 months ago

@mringwal Everything was going smoothly, and then, a new error occurred. When opening a game or application, the Wii disconnect from the Wiimote, which it's normal. But when attempting to reconnect (following the same process to connect to the Wii before), the connection failed. I can't get complete wireshark file because it's too many info from the first connect until open a game then I just gonna show the part where the connection fails. I tried to connect doing hid_device_connect new_error.zip

mringwal commented 7 months ago

@loc15 In the log, you (re)connect to the Wii, start authentication. During this the link key stored in the first connection is used, but this does not seem to be the correct one. The difference is that BTstack has stored the link key. You could delete the link key before (re)connect using gap_delete_bonding(bd_addr) or even gap_delete_all_link_keys. Please check the Wii WiiBrew Wiki to see how re-connect works.

Loc15 commented 6 months ago

@mringwal Erasing pico's flash make it work and it reconnects but still doesn't work on homebrew, I guess it better than nothing. Thanks for all mate.