Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Security] Bluedroid ignore +6 PIN (IDFGH-3854) #5760

Closed
ghost opened this issue Aug 19, 2020 · 22 comments
Closed

[Security] Bluedroid ignore +6 PIN (IDFGH-3854) #5760

ghost opened this issue Aug 19, 2020 · 22 comments
Labels
Resolution: Cannot Reproduce Issue cannot be reproduced

Comments

@ghost
Copy link

ghost commented Aug 19, 2020

  • Development Kit: -
  • Kit version: DevKitC: v4
  • Module or chip used: ESP32-WROOM-32D
  • IDF version: v4.2-dev-1905-g625bd5eb1
  • Build System: idf.py
  • Compiler version: xtensa-esp32-elf-gcc (crosstool-NG esp-2020r2) 8.2.0
  • Operating System: Windows
  • (Windows only) environment type: ESP Command Prompt
  • Power Supply: USB

The Bluedroid BLE stack take only first six digit for PIN, and ignore completely the rest.

1: Use example: gatt_security_server
2: Build & Flash
3: In your Phone/Tablet search and pair with ESP

The PIN is 123456, but you can correctly pair with 123456999999, that's because Bluedroid BLE stack take only first six digit.

@github-actions github-actions bot changed the title [Security] Bluedroid ignore +6 PIN [Security] Bluedroid ignore +6 PIN (IDFGH-3854) Aug 19, 2020
@xiewenxiang
Copy link
Collaborator

Hi dragahassan,

I tried to reproduce the problem you mentioned, when I entered the wrong key or long sizes key, all of these will pair fail.
So, I want to confirm with you thar do you have checked the status bit for ESP_GAP_BLE_AUTH_CMPL_EVT?

In ESP-IDF, there is actually a check for smp passkey.

esp-idf/components/bt/host/bluedroid/stack/smp/smp_api.c

#define BTM_MAX_PASSKEY_VAL (999999)
#define BTM_MIN_PASSKEY_VAL (0)


void SMP_PasskeyReply (BD_ADDR bd_addr, UINT8 res, UINT32 passkey)
{
    tSMP_CB *p_cb = & smp_cb;
    UINT8   failure = SMP_PASSKEY_ENTRY_FAIL;

    SMP_TRACE_EVENT ("SMP_PasskeyReply: Key: %d  Result:%d",
                     passkey, res);

    /* If timeout already expired or has been canceled, ignore the reply */
    if (p_cb->cb_evt != SMP_PASSKEY_REQ_EVT) {
        SMP_TRACE_WARNING ("SMP_PasskeyReply() - Wrong State: %d", p_cb->state);
        return;
    }

    if (memcmp (bd_addr, p_cb->pairing_bda, BD_ADDR_LEN) != 0) {
        SMP_TRACE_ERROR ("SMP_PasskeyReply() - Wrong BD Addr");
        return;
    }

    if (btm_find_dev (bd_addr) == NULL) {
        SMP_TRACE_ERROR ("SMP_PasskeyReply() - no dev CB");
        return;
    }

    if (passkey > BTM_MAX_PASSKEY_VAL || res != SMP_SUCCESS) {
        SMP_TRACE_WARNING ("SMP_PasskeyReply() - Wrong key len: %d or passkey entry fail", passkey);
        /* send pairing failure */
        smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &failure);

    } else if (p_cb->selected_association_model == SMP_MODEL_SEC_CONN_PASSKEY_ENT) {
        smp_sm_event(&smp_cb, SMP_SC_KEY_READY_EVT, &passkey);
    } else {
        smp_convert_string_to_tk(p_cb->tk, passkey);
    }

    return;
}

@ghost
Copy link
Author

ghost commented Aug 20, 2020

I just start completely everything from scratch to be sure, and this security problem still exist.

0: I create a new Windows 10 Virtualbox! (because my OS have multiple modified ESP-IDF)

1: Setup ESP IDF using esp-idf-tools-setup-2.3.exe (Select new setup for Python & Git)
2: Set OUT capability in file example_ble_sec_gatts_demo.c from ESP_IO_CAP_NONE to ESP_IO_CAP_OUT
3: Build idf.py -p COM3 build
4: Clean ESP32 device idf.py -p COM3 erase_flash
5: Flash idf.py -p COM3 flash

In your Phone/Tablet search and pair for ESP_BLE_SECURITY, when ask for PIN set the correct pin 123456 then add random numbers.. like full PIN will be 123456789012., the pairing will success!.

@ghost
Copy link
Author

ghost commented Aug 20, 2020

Correct PIN is 123456, I set PIN 123456789012 from LG Phone (Android 10).

pair status = success

I (526) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (572) BTDM_INIT: BT controller compile version [c1cbe45]
I (572) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (682) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (922) SEC_GATTS_DEMO: app_main init bluetooth
I (1062) SEC_GATTS_DEMO: The number handle = 8
I (1092) SEC_GATTS_DEMO: advertising start success
I (14072) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
I (14442) SEC_GATTS_DEMO: The passkey Notify number:123456
W (37732) BT_SMP: FOR LE SC LTK IS USED INSTEAD OF STK
I (37912) SEC_GATTS_DEMO: key type = ESP_LE_KEY_LENC
I (37912) SEC_GATTS_DEMO: key type = ESP_LE_KEY_PENC
I (37912) SEC_GATTS_DEMO: key type = ESP_LE_KEY_LID
I (38242) SEC_GATTS_DEMO: key type = ESP_LE_KEY_PID
I (38242) SEC_GATTS_DEMO: remote BD_ADDR: 5112441c7493
I (38242) SEC_GATTS_DEMO: address type = 1
I (38242) SEC_GATTS_DEMO: pair status = success
I (38252) SEC_GATTS_DEMO: auth mode = ESP_LE_AUTH_REQ_SC_MITM_BOND
I (38262) SEC_GATTS_DEMO: Bonded devices number : 1

I (38262) SEC_GATTS_DEMO: Bonded devices list : 1

I (38272) SEC_GATTS_DEMO: 51 12 44 1c 74 93

@ghost
Copy link
Author

ghost commented Aug 20, 2020

Correct PIN is 123456, I set PIN 090909010203.

pair status = fail

I (526) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (560) BTDM_INIT: BT controller compile version [c1cbe45]
I (560) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (660) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (900) SEC_GATTS_DEMO: app_main init bluetooth
I (1050) SEC_GATTS_DEMO: The number handle = 8
I (1080) SEC_GATTS_DEMO: advertising start success
I (18150) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
I (18440) SEC_GATTS_DEMO: The passkey Notify number:123456
W (24130) BT_SMP: Commitment check fails

I (24140) SEC_GATTS_DEMO: remote BD_ADDR: 5112441c7493
I (24150) SEC_GATTS_DEMO: address type = 1
I (24150) SEC_GATTS_DEMO: pair status = fail
I (24150) SEC_GATTS_DEMO: fail reason = 0x51
I (24150) SEC_GATTS_DEMO: Bonded devices number : 0

I (24160) SEC_GATTS_DEMO: Bonded devices list : 0

W (27130) BT_BTM: btm_sec_clr_temp_auth_service() - no dev CB

I (27140) SEC_GATTS_DEMO: ESP_GATTS_DISCONNECT_EVT, disconnect reason 0x16
I (27160) SEC_GATTS_DEMO: advertising start success

@ghost
Copy link
Author

ghost commented Aug 20, 2020

VirtualBox_Windows_10_64_20_08_2020_11_42_38

@chegewara
Copy link
Contributor

Just idea, maybe smartphone is truncating passkey to only 6 digits?
As you can see on screenshot its only 6 digits displayed.

@ghost
Copy link
Author

ghost commented Aug 20, 2020

@chegewara No, because the phone allow 12 digit, also the same thing on Asus tablet., and the log The passkey Notify number:123456 it's not the pin received but the ESP pin.

@ghost
Copy link
Author

ghost commented Aug 20, 2020

@chegewara in other hand maybe you are right, ESP set max pin len to 6 maybe, so device truncating the pin even if user set 12 digit!.

@ghost
Copy link
Author

ghost commented Aug 20, 2020

Correct PIN is 123456, I set PIN 123456666666.

SMP Verbose log:

I (0) cpu_start: App cpu up.
I (444) heap_init: Initializing. RAM available for dynamic allocation:
I (451) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (457) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (463) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (469) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (475) heap_init: At 3FFC9100 len 00016F00 (91 KiB): DRAM
I (481) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (488) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (494) heap_init: At 40092E04 len 0000D1FC (52 KiB): IRAM
I (500) cpu_start: Pro cpu start user code
I (519) spi_flash: detected chip: generic
I (519) spi_flash: flash io: dio
W (519) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (530) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (576) BTDM_INIT: BT controller compile version [c1cbe45]
I (576) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (676) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (916) SEC_GATTS_DEMO: app_main init bluetooth
D (916) BT_SMP: SMP_Init
D (916) BT_SMP: SMDBG l2c smp_l2cap_if_init
D (1006) BT_SMP: SMP_Register state=0
D (1056) BT_SMP: smp_encrypt_data

I (1066) SEC_GATTS_DEMO: The number handle = 8
D (1076) BT_SMP: static passkey 123456
I (1096) SEC_GATTS_DEMO: advertising start success
D (34206) BT_SMP: SMDBG l2c smp_connect_callback

I (34206) SEC_GATTS_DEMO: ESP_GATTS_CONNECT_EVT
D (34206) BT_SMP: SMP_Pair state=0 br_state=0 flag=0x0

D (34216) BT_SMP: SMDBG l2c smp_connect_callback

D (34216) BT_SMP: smp_connect_callback()  for pairing BDA: 416d2dc5d8d1  Event: connected

D (34226) BT_SMP: main smp_sm_event

D (34226) BT_SMP: SMP Role: Slave State: [SMP_STATE_IDLE (0)], Event: [L2CAP_CONN_EVT (18)]
D (34236) BT_SMP: State change: SMP_STATE_IDLE(0) ==> SMP_STATE_WAIT_APP_RSP(1)
D (34246) BT_SMP: smp_send_app_cback p_cb->cb_evt=1

D (34256) BT_SMP: io_cap = 4
D (34256) BT_SMP: callback_rc=0  p_cb->cb_evt=1

D (34256) BT_SMP: rcvd auth_req: 0x0d, io_cap: 0                         loc_oob_flag: 0 loc_enc_size: 16,local_i_key: 0x03, local_r_key: 0x03

D (34276) BT_SMP: lmp_version_below LMP version 9 < 8
D (34276) BT_SMP: set auth_req: 0x0d, local_i_key: 0x03, local_r_key: 0x03

D (34286) BT_SMP: main smp_sm_event

D (34286) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_APP_RSP (1)], Event: [API_IO_RSP_EVT (20)]
D (34296) BT_SMP: State change: SMP_STATE_WAIT_APP_RSP(1) ==> SMP_STATE_PAIR_REQ_RSP(3)
D (34306) BT_SMP: smp_process_io_response

D (34306) BT_SMP: State change: SMP_STATE_PAIR_REQ_RSP(3) ==> SMP_STATE_SEC_REQ_PENDING(2)
D (34316) BT_SMP: smp_send_cmd on l2cap cmd_code=0xb

D (34326) BT_SMP: smp_build_security_request

D (34326) BT_SMP: opcode=11 auth_req=0xd
D (34336) BT_SMP: smp_send_msg_to_L2CAP
D (34336) BT_SMP: result state = SMP_STATE_SEC_REQ_PENDING

D (34346) BT_SMP: smp_send_app_cback return

D (34346) BT_SMP: result state = SMP_STATE_SEC_REQ_PENDING

D (34426) BT_SMP:
SMDBG l2c smp_data_received

D (34426) BT_SMP: main smp_sm_event

D (34426) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_REQ_PENDING (2)], Event: [PAIRING_REQ_EVT (1)]
D (34436) BT_SMP: State change: SMP_STATE_SEC_REQ_PENDING(2) ==> SMP_STATE_PAIR_REQ_RSP(3)
D (34446) BT_SMP: smp_proc_pair_cmd

D (34446) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x01

D (34456) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x01

D (34456) BT_SMP: smp_pairing_request_response_parameters_are_valid for cmd code 0x01

D (34466) BT_SMP: smp_select_association_model

D (34476) BT_SMP: smp_select_association_model p_cb->peer_io_caps = 4 p_cb->local_io_capability = 0

D (34476) BT_SMP: smp_select_association_model p_cb->peer_oob_flag = 0 p_cb->loc_oob_flag = 0

D (34486) BT_SMP: smp_select_association_model p_cb->peer_auth_req = 0x2d p_cb->loc_auth_req = 0x0d

D (34496) BT_SMP: smp_select_association_model p_cb->secure_connections_only_mode_required = FALSE

D (34506) BT_SMP: use_sc_process = 1

D (34516) BT_SMP: smp_select_association_model_secure_connections

D (34516) BT_SMP: smp_get_auth_mode model 7
D (34526) BT_SMP: smp_send_pair_rsp

D (34526) BT_SMP: smp_send_cmd on l2cap cmd_code=0x2

D (34526) BT_SMP: smp_build_pairing_cmd
D (34536) BT_SMP: smp_send_msg_to_L2CAP
D (34536) BT_SMP: smp_decide_association_model Association Model = 7

D (34546) BT_SMP: sec_level=0

D (34546) BT_SMP: main smp_sm_event

D (34556) BT_SMP: SMP Role: Slave State: [SMP_STATE_PAIR_REQ_RSP (3)], Event: [PUBLIC_KEY_EXCHANGE_REQ_EVT (27)]
D (34566) BT_SMP: State change: SMP_STATE_PAIR_REQ_RSP(3) ==> SMP_STATE_PUBLIC_KEY_EXCH(7)
D (34576) BT_SMP: smp_create_private_key
D (34576) BT_SMP: result state = SMP_STATE_PUBLIC_KEY_EXCH

D (34576) BT_SMP: result state = SMP_STATE_PUBLIC_KEY_EXCH

D (34586) BT_SMP: smp_rand_back state=0x9
D (34586) BT_SMP: smp_continue_private_key_creation state=0x9

D (34596) BT_SMP: smp_rand_back state=0xa
D (34606) BT_SMP: smp_continue_private_key_creation state=0xa

D (34606) BT_SMP: smp_rand_back state=0xb
D (34616) BT_SMP: smp_continue_private_key_creation state=0xb

D (34616) BT_SMP: smp_rand_back state=0xc
D (34626) BT_SMP: smp_continue_private_key_creation state=0xc

D (34626) BT_SMP: smp_process_private_key
D (34726) BT_SMP: main smp_sm_event

D (34726) BT_SMP: SMP Role: Slave State: [SMP_STATE_PUBLIC_KEY_EXCH (7)], Event: [LOCAL_PUBLIC_KEY_CRTD_EVT (28)]
D (34726) BT_SMP: State change: SMP_STATE_PUBLIC_KEY_EXCH(7) ==> SMP_STATE_PUBLIC_KEY_EXCH(7)
D (34736) BT_SMP: smp_wait_for_both_public_keys

D (34736) BT_SMP: result state = SMP_STATE_PUBLIC_KEY_EXCH

D (34746) BT_SMP:
SMDBG l2c smp_data_received

D (34746) BT_SMP: main smp_sm_event

D (34756) BT_SMP: SMP Role: Slave State: [SMP_STATE_PUBLIC_KEY_EXCH (7)], Event: [PAIR_PUBLIC_KEY_EVT (12)]
D (34766) BT_SMP: State change: SMP_STATE_PUBLIC_KEY_EXCH(7) ==> SMP_STATE_PUBLIC_KEY_EXCH(7)
D (34776) BT_SMP: smp_process_pairing_public_key
D (34776) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0c

D (34786) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0c

D (34796) BT_SMP: smp_wait_for_both_public_keys

D (34796) BT_SMP: main smp_sm_event

D (34796) BT_SMP: SMP Role: Slave State: [SMP_STATE_PUBLIC_KEY_EXCH (7)], Event: [BOTH_PUBLIC_KEYS_RCVD_EVT (29)]
D (34806) BT_SMP: State change: SMP_STATE_PUBLIC_KEY_EXCH(7) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (34816) BT_SMP: smp_both_have_public_keys

D (34826) BT_SMP: smp_compute_dhkey

D (34906) BT_SMP: smp_send_pair_public_key

D (34906) BT_SMP: smp_send_cmd on l2cap cmd_code=0xc

D (34906) BT_SMP: smp_build_pair_public_key_cmd

D (34916) BT_SMP: smp_send_msg_to_L2CAP
D (34916) BT_SMP: main smp_sm_event

D (34916) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [SEC_CONN_DHKEY_COMPLETE_EVT (30)]
D (34936) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (34936) BT_SMP: smp_start_secure_connection_phase1

D (34946) BT_SMP: p_cb->sec_level =4 (SMP_SEC_AUTHENTICATED)

D (34956) BT_SMP: Need to generate SC Passkey

D (34956) BT_SMP: smp_generate_passkey use static passkey 123456
D (34966) BT_SMP: main smp_sm_event

D (34966) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [KEY_READY_EVT (16)]
D (34976) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (34986) BT_SMP: smp_start_passkey_verification

D (34986) BT_SMP: smp_start_nonce_generation
D (34996) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (34996) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (35006) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (35016) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (35016) BT_SMP: smp_rand_back state=0xd
D (35026) BT_SMP: smp_finish_nonce_generation
I (35026) SEC_GATTS_DEMO: The passkey Notify number:123456
D (35036) BT_SMP: smp_rand_back state=0xe
D (35036) BT_SMP: smp_process_new_nonce round 0
D (35046) BT_SMP: main smp_sm_event

D (35046) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (35056) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (35066) BT_SMP: smp_process_local_nonce

D (35066) BT_SMP: smp_calculate_local_commitment

D (35076) BT_SMP: random: 0x40, round: 0, i: 0, j: 0

D (35076) BT_SMP: smp_calculate_random_input ri=0x80

D (35086) BT_SMP: smp_calculate_f4
D (35086) BT_SMP: aes_cipher_msg_auth_code
D (35096) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (35096) BT_SMP:  cmac_generate_subkey
D (35106) BT_SMP: smp_encrypt_data

D (35106) BT_SMP: cmac_subkey_cont
D (35106) BT_SMP: leftshift_onebit
D (35116) BT_SMP: leftshift_onebit
D (35116) BT_SMP: cmac_prepare_last_block
D (35116) BT_SMP: flag = 0 round = 5
D (35126) BT_SMP: smp_xor_128

D (35126) BT_SMP: cmac_aes_k_calculate
D (35136) BT_SMP: smp_xor_128

D (35136) BT_SMP: smp_encrypt_data

D (35136) BT_SMP: smp_xor_128

D (35146) BT_SMP: smp_encrypt_data

D (35146) BT_SMP: smp_xor_128

D (35146) BT_SMP: smp_encrypt_data

D (35156) BT_SMP: smp_xor_128

D (35156) BT_SMP: smp_encrypt_data

D (35156) BT_SMP: smp_xor_128

D (35166) BT_SMP: smp_encrypt_data

D (35166) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (35166) BT_SMP: p_mac[0] = 0x86 p_mac[1] = 0x8d p_mac[2] = 0x55 p_mac[3] = 0xae
D (35176) BT_SMP: p_mac[4] = 0x68 p_mac[5] = 0x42 p_mac[6] = 0x4c p_mac[7] = 0x52
D (35186) BT_SMP: local commitment calculation is completed
D (35186) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (45626) BT_SMP:
SMDBG l2c smp_data_received

D (45636) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (45636) BT_SMP: main smp_sm_event

D (45636) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (45646) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (45656) BT_SMP: smp_process_pairing_commitment
D (45656) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (45666) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (45676) BT_SMP: smp_send_commitment
D (45676) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (45686) BT_SMP: smp_build_pairing_commitment_cmd

D (45686) BT_SMP: smp_send_msg_to_L2CAP
D (45696) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (45766) BT_SMP:
SMDBG l2c smp_data_received

D (45766) BT_SMP: main smp_sm_event

D (45766) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (45776) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (45776) BT_SMP: smp_proc_rand

D (45786) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (45786) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (45796) BT_SMP: smp_process_peer_nonce start

D (45806) BT_SMP: smp_check_commitment

D (45806) BT_SMP: smp_calculate_peer_commitment
D (45806) BT_SMP: random: 0x40, round: 0, i: 0, j: 0

D (45816) BT_SMP: smp_calculate_random_input ri=0x80

D (45826) BT_SMP: smp_calculate_f4
D (45826) BT_SMP: aes_cipher_msg_auth_code
D (45826) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (45836) BT_SMP:  cmac_generate_subkey
D (45836) BT_SMP: smp_encrypt_data

D (45846) BT_SMP: cmac_subkey_cont
D (45846) BT_SMP: leftshift_onebit
D (45846) BT_SMP: leftshift_onebit
D (45856) BT_SMP: cmac_prepare_last_block
D (45856) BT_SMP: flag = 0 round = 5
D (45866) BT_SMP: smp_xor_128

D (45866) BT_SMP: cmac_aes_k_calculate
D (45866) BT_SMP: smp_xor_128

D (45876) BT_SMP: smp_encrypt_data

D (45876) BT_SMP: smp_xor_128

D (45876) BT_SMP: smp_encrypt_data

D (45886) BT_SMP: smp_xor_128

D (45886) BT_SMP: smp_encrypt_data

D (45886) BT_SMP: smp_xor_128

D (45896) BT_SMP: smp_encrypt_data

D (45896) BT_SMP: smp_xor_128

D (45896) BT_SMP: smp_encrypt_data

D (45906) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (45906) BT_SMP: p_mac[0] = 0x6e p_mac[1] = 0x81 p_mac[2] = 0x79 p_mac[3] = 0x31
D (45916) BT_SMP: p_mac[4] = 0xa3 p_mac[5] = 0x69 p_mac[6] = 0x3c p_mac[7] = 0x81
D (45926) BT_SMP: peer commitment calculation is completed

D (45926) BT_SMP: Commitment check succeeds

D (45936) BT_SMP: smp_send_rand

D (45936) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (45936) BT_SMP: smp_build_rand_cmd

D (45946) BT_SMP: smp_send_msg_to_L2CAP
D (45946) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (45956) BT_SMP: smp_start_nonce_generation
D (45966) BT_SMP: smp_process_peer_nonce end

D (45966) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (45976) BT_SMP: smp_rand_back state=0xd
D (45976) BT_SMP: smp_finish_nonce_generation
D (45986) BT_SMP: smp_rand_back state=0xe
D (45986) BT_SMP: smp_process_new_nonce round 1
D (45986) BT_SMP: main smp_sm_event

D (45996) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (46006) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (46016) BT_SMP: smp_process_local_nonce

D (46016) BT_SMP: smp_calculate_local_commitment

D (46026) BT_SMP: random: 0x40, round: 1, i: 0, j: 1

D (46026) BT_SMP: smp_calculate_random_input ri=0x80

D (46036) BT_SMP: smp_calculate_f4
D (46036) BT_SMP: aes_cipher_msg_auth_code
D (46036) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (46046) BT_SMP:  cmac_generate_subkey
D (46046) BT_SMP: smp_encrypt_data

D (46056) BT_SMP: cmac_subkey_cont
D (46056) BT_SMP: leftshift_onebit
D (46056) BT_SMP: smp_xor_128

D (46066) BT_SMP: leftshift_onebit
D (46066) BT_SMP: smp_xor_128

D (46066) BT_SMP: cmac_prepare_last_block
D (46076) BT_SMP: flag = 0 round = 5
D (46076) BT_SMP: smp_xor_128

D (46086) BT_SMP: cmac_aes_k_calculate
D (46086) BT_SMP: smp_xor_128

D (46086) BT_SMP: smp_encrypt_data

D (46096) BT_SMP: smp_xor_128

D (46096) BT_SMP: smp_encrypt_data

D (46096) BT_SMP: smp_xor_128

D (46106) BT_SMP: smp_encrypt_data

D (46106) BT_SMP: smp_xor_128

D (46106) BT_SMP: smp_encrypt_data

D (46116) BT_SMP: smp_xor_128

D (46116) BT_SMP: smp_encrypt_data

D (46116) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (46126) BT_SMP: p_mac[0] = 0x3a p_mac[1] = 0x2f p_mac[2] = 0x96 p_mac[3] = 0x5d
D (46136) BT_SMP: p_mac[4] = 0x73 p_mac[5] = 0xa5 p_mac[6] = 0x9e p_mac[7] = 0x88
D (46136) BT_SMP: local commitment calculation is completed
D (46146) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (46156) BT_SMP:
SMDBG l2c smp_data_received

D (46156) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (46166) BT_SMP: main smp_sm_event

D (46166) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (46176) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (46186) BT_SMP: smp_process_pairing_commitment
D (46186) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (46196) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (46206) BT_SMP: smp_send_commitment
D (46206) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (46216) BT_SMP: smp_build_pairing_commitment_cmd

D (46216) BT_SMP: smp_send_msg_to_L2CAP
D (46226) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (46306) BT_SMP:
SMDBG l2c smp_data_received

D (46306) BT_SMP: main smp_sm_event

D (46306) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (46316) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (46316) BT_SMP: smp_proc_rand

D (46326) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (46326) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (46336) BT_SMP: smp_process_peer_nonce start

D (46346) BT_SMP: smp_check_commitment

D (46346) BT_SMP: smp_calculate_peer_commitment
D (46346) BT_SMP: random: 0x40, round: 1, i: 0, j: 1

D (46356) BT_SMP: smp_calculate_random_input ri=0x80

D (46366) BT_SMP: smp_calculate_f4
D (46366) BT_SMP: aes_cipher_msg_auth_code
D (46366) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (46376) BT_SMP:  cmac_generate_subkey
D (46376) BT_SMP: smp_encrypt_data

D (46386) BT_SMP: cmac_subkey_cont
D (46386) BT_SMP: leftshift_onebit
D (46386) BT_SMP: smp_xor_128

D (46396) BT_SMP: leftshift_onebit
D (46396) BT_SMP: smp_xor_128

D (46396) BT_SMP: cmac_prepare_last_block
D (46406) BT_SMP: flag = 0 round = 5
D (46406) BT_SMP: smp_xor_128

D (46406) BT_SMP: cmac_aes_k_calculate
D (46416) BT_SMP: smp_xor_128

D (46416) BT_SMP: smp_encrypt_data

D (46426) BT_SMP: smp_xor_128

D (46426) BT_SMP: smp_encrypt_data

D (46426) BT_SMP: smp_xor_128

D (46436) BT_SMP: smp_encrypt_data

D (46436) BT_SMP: smp_xor_128

D (46436) BT_SMP: smp_encrypt_data

D (46446) BT_SMP: smp_xor_128

D (46446) BT_SMP: smp_encrypt_data

D (46446) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (46456) BT_SMP: p_mac[0] = 0x80 p_mac[1] = 0x3d p_mac[2] = 0xb2 p_mac[3] = 0x0f
D (46466) BT_SMP: p_mac[4] = 0x0a p_mac[5] = 0xbd p_mac[6] = 0x1e p_mac[7] = 0x04
D (46466) BT_SMP: peer commitment calculation is completed

D (46476) BT_SMP: Commitment check succeeds

D (46476) BT_SMP: smp_send_rand

D (46486) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (46486) BT_SMP: smp_build_rand_cmd

D (46496) BT_SMP: smp_send_msg_to_L2CAP
D (46496) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (46506) BT_SMP: smp_start_nonce_generation
D (46506) BT_SMP: smp_process_peer_nonce end

D (46516) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (46516) BT_SMP: smp_rand_back state=0xd
D (46526) BT_SMP: smp_finish_nonce_generation
D (46526) BT_SMP: smp_rand_back state=0xe
D (46536) BT_SMP: smp_process_new_nonce round 2
D (46536) BT_SMP: main smp_sm_event

D (46536) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (46546) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (46556) BT_SMP: smp_process_local_nonce

D (46566) BT_SMP: smp_calculate_local_commitment

D (46566) BT_SMP: random: 0x40, round: 2, i: 0, j: 2

D (46576) BT_SMP: smp_calculate_random_input ri=0x80

D (46576) BT_SMP: smp_calculate_f4
D (46586) BT_SMP: aes_cipher_msg_auth_code
D (46586) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (46596) BT_SMP:  cmac_generate_subkey
D (46596) BT_SMP: smp_encrypt_data

D (46596) BT_SMP: cmac_subkey_cont
D (46606) BT_SMP: leftshift_onebit
D (46606) BT_SMP: leftshift_onebit
D (46616) BT_SMP: cmac_prepare_last_block
D (46616) BT_SMP: flag = 0 round = 5
D (46616) BT_SMP: smp_xor_128

D (46626) BT_SMP: cmac_aes_k_calculate
D (46626) BT_SMP: smp_xor_128

D (46626) BT_SMP: smp_encrypt_data

D (46636) BT_SMP: smp_xor_128

D (46636) BT_SMP: smp_encrypt_data

D (46636) BT_SMP: smp_xor_128

D (46646) BT_SMP: smp_encrypt_data

D (46646) BT_SMP: smp_xor_128

D (46646) BT_SMP: smp_encrypt_data

D (46656) BT_SMP: smp_xor_128

D (46656) BT_SMP: smp_encrypt_data

D (46656) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (46666) BT_SMP: p_mac[0] = 0x18 p_mac[1] = 0x17 p_mac[2] = 0x5f p_mac[3] = 0x51
D (46676) BT_SMP: p_mac[4] = 0x15 p_mac[5] = 0xc0 p_mac[6] = 0x6b p_mac[7] = 0x1b
D (46676) BT_SMP: local commitment calculation is completed
D (46686) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (46696) BT_SMP:
SMDBG l2c smp_data_received

D (46696) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (46706) BT_SMP: main smp_sm_event

D (46706) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (46716) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (46726) BT_SMP: smp_process_pairing_commitment
D (46736) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (46736) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (46746) BT_SMP: smp_send_commitment
D (46746) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (46756) BT_SMP: smp_build_pairing_commitment_cmd

D (46756) BT_SMP: smp_send_msg_to_L2CAP
D (46766) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (46846) BT_SMP:
SMDBG l2c smp_data_received

D (46846) BT_SMP: main smp_sm_event

D (46846) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (46856) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (46856) BT_SMP: smp_proc_rand

D (46866) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (46866) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (46876) BT_SMP: smp_process_peer_nonce start

D (46886) BT_SMP: smp_check_commitment

D (46886) BT_SMP: smp_calculate_peer_commitment
D (46886) BT_SMP: random: 0x40, round: 2, i: 0, j: 2

D (46896) BT_SMP: smp_calculate_random_input ri=0x80

D (46906) BT_SMP: smp_calculate_f4
D (46906) BT_SMP: aes_cipher_msg_auth_code
D (46906) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (46916) BT_SMP:  cmac_generate_subkey
D (46916) BT_SMP: smp_encrypt_data

D (46926) BT_SMP: cmac_subkey_cont
D (46926) BT_SMP: leftshift_onebit
D (46926) BT_SMP: smp_xor_128

D (46936) BT_SMP: leftshift_onebit
D (46936) BT_SMP: smp_xor_128

D (46936) BT_SMP: cmac_prepare_last_block
D (46946) BT_SMP: flag = 0 round = 5
D (46946) BT_SMP: smp_xor_128

D (46946) BT_SMP: cmac_aes_k_calculate
D (46956) BT_SMP: smp_xor_128

D (46956) BT_SMP: smp_encrypt_data

D (46966) BT_SMP: smp_xor_128

D (46966) BT_SMP: smp_encrypt_data

D (46966) BT_SMP: smp_xor_128

D (46976) BT_SMP: smp_encrypt_data

D (46976) BT_SMP: smp_xor_128

D (46976) BT_SMP: smp_encrypt_data

D (46986) BT_SMP: smp_xor_128

D (46986) BT_SMP: smp_encrypt_data

D (46986) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (46996) BT_SMP: p_mac[0] = 0x2a p_mac[1] = 0x6c p_mac[2] = 0x8a p_mac[3] = 0x0e
D (47006) BT_SMP: p_mac[4] = 0x5b p_mac[5] = 0xdf p_mac[6] = 0x7d p_mac[7] = 0x8a
D (47006) BT_SMP: peer commitment calculation is completed

D (47016) BT_SMP: Commitment check succeeds

D (47016) BT_SMP: smp_send_rand

D (47026) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (47026) BT_SMP: smp_build_rand_cmd

D (47036) BT_SMP: smp_send_msg_to_L2CAP
D (47036) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (47046) BT_SMP: smp_start_nonce_generation
D (47046) BT_SMP: smp_process_peer_nonce end

D (47056) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (47056) BT_SMP: smp_rand_back state=0xd
D (47066) BT_SMP: smp_finish_nonce_generation
D (47066) BT_SMP: smp_rand_back state=0xe
D (47076) BT_SMP: smp_process_new_nonce round 3
D (47076) BT_SMP: main smp_sm_event

D (47076) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (47086) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (47096) BT_SMP: smp_process_local_nonce

D (47106) BT_SMP: smp_calculate_local_commitment

D (47106) BT_SMP: random: 0x40, round: 3, i: 0, j: 3

D (47116) BT_SMP: smp_calculate_random_input ri=0x80

D (47116) BT_SMP: smp_calculate_f4
D (47126) BT_SMP: aes_cipher_msg_auth_code
D (47126) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (47136) BT_SMP:  cmac_generate_subkey
D (47136) BT_SMP: smp_encrypt_data

D (47136) BT_SMP: cmac_subkey_cont
D (47146) BT_SMP: leftshift_onebit
D (47146) BT_SMP: leftshift_onebit
D (47156) BT_SMP: cmac_prepare_last_block
D (47156) BT_SMP: flag = 0 round = 5
D (47156) BT_SMP: smp_xor_128

D (47166) BT_SMP: cmac_aes_k_calculate
D (47166) BT_SMP: smp_xor_128

D (47166) BT_SMP: smp_encrypt_data

D (47176) BT_SMP: smp_xor_128

D (47176) BT_SMP: smp_encrypt_data

D (47176) BT_SMP: smp_xor_128

D (47186) BT_SMP: smp_encrypt_data

D (47186) BT_SMP: smp_xor_128

D (47186) BT_SMP: smp_encrypt_data

D (47196) BT_SMP: smp_xor_128

D (47196) BT_SMP: smp_encrypt_data

D (47196) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (47206) BT_SMP: p_mac[0] = 0x0d p_mac[1] = 0xb4 p_mac[2] = 0xb1 p_mac[3] = 0xc3
D (47216) BT_SMP: p_mac[4] = 0x7d p_mac[5] = 0xe3 p_mac[6] = 0x88 p_mac[7] = 0x76
D (47216) BT_SMP: local commitment calculation is completed
D (47226) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (47236) BT_SMP:
SMDBG l2c smp_data_received

D (47236) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (47246) BT_SMP: main smp_sm_event

D (47246) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (47256) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (47266) BT_SMP: smp_process_pairing_commitment
D (47276) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (47276) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (47286) BT_SMP: smp_send_commitment
D (47286) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (47296) BT_SMP: smp_build_pairing_commitment_cmd

D (47296) BT_SMP: smp_send_msg_to_L2CAP
D (47306) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (47386) BT_SMP:
SMDBG l2c smp_data_received

D (47386) BT_SMP: main smp_sm_event

D (47386) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (47396) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (47396) BT_SMP: smp_proc_rand

D (47406) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (47406) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (47416) BT_SMP: smp_process_peer_nonce start

D (47426) BT_SMP: smp_check_commitment

D (47426) BT_SMP: smp_calculate_peer_commitment
D (47426) BT_SMP: random: 0x40, round: 3, i: 0, j: 3

D (47436) BT_SMP: smp_calculate_random_input ri=0x80

D (47446) BT_SMP: smp_calculate_f4
D (47446) BT_SMP: aes_cipher_msg_auth_code
D (47446) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (47456) BT_SMP:  cmac_generate_subkey
D (47456) BT_SMP: smp_encrypt_data

D (47466) BT_SMP: cmac_subkey_cont
D (47466) BT_SMP: leftshift_onebit
D (47466) BT_SMP: leftshift_onebit
D (47476) BT_SMP: cmac_prepare_last_block
D (47476) BT_SMP: flag = 0 round = 5
D (47486) BT_SMP: smp_xor_128

D (47486) BT_SMP: cmac_aes_k_calculate
D (47486) BT_SMP: smp_xor_128

D (47496) BT_SMP: smp_encrypt_data

D (47496) BT_SMP: smp_xor_128

D (47496) BT_SMP: smp_encrypt_data

D (47506) BT_SMP: smp_xor_128

D (47506) BT_SMP: smp_encrypt_data

D (47506) BT_SMP: smp_xor_128

D (47516) BT_SMP: smp_encrypt_data

D (47516) BT_SMP: smp_xor_128

D (47516) BT_SMP: smp_encrypt_data

D (47526) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (47526) BT_SMP: p_mac[0] = 0x17 p_mac[1] = 0x7e p_mac[2] = 0x5b p_mac[3] = 0xc3
D (47536) BT_SMP: p_mac[4] = 0xed p_mac[5] = 0x68 p_mac[6] = 0x22 p_mac[7] = 0x2a
D (47546) BT_SMP: peer commitment calculation is completed

D (47546) BT_SMP: Commitment check succeeds

D (47556) BT_SMP: smp_send_rand

D (47556) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (47556) BT_SMP: smp_build_rand_cmd

D (47566) BT_SMP: smp_send_msg_to_L2CAP
D (47566) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (47576) BT_SMP: smp_start_nonce_generation
D (47586) BT_SMP: smp_process_peer_nonce end

D (47586) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (47596) BT_SMP: smp_rand_back state=0xd
D (47596) BT_SMP: smp_finish_nonce_generation
D (47606) BT_SMP: smp_rand_back state=0xe
D (47606) BT_SMP: smp_process_new_nonce round 4
D (47606) BT_SMP: main smp_sm_event

D (47616) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (47626) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (47636) BT_SMP: smp_process_local_nonce

D (47636) BT_SMP: smp_calculate_local_commitment

D (47646) BT_SMP: random: 0x40, round: 4, i: 0, j: 4

D (47646) BT_SMP: smp_calculate_random_input ri=0x80

D (47656) BT_SMP: smp_calculate_f4
D (47656) BT_SMP: aes_cipher_msg_auth_code
D (47656) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (47666) BT_SMP:  cmac_generate_subkey
D (47666) BT_SMP: smp_encrypt_data

D (47676) BT_SMP: cmac_subkey_cont
D (47676) BT_SMP: leftshift_onebit
D (47686) BT_SMP: leftshift_onebit
D (47686) BT_SMP: cmac_prepare_last_block
D (47686) BT_SMP: flag = 0 round = 5
D (47696) BT_SMP: smp_xor_128

D (47696) BT_SMP: cmac_aes_k_calculate
D (47696) BT_SMP: smp_xor_128

D (47706) BT_SMP: smp_encrypt_data

D (47706) BT_SMP: smp_xor_128

D (47706) BT_SMP: smp_encrypt_data

D (47716) BT_SMP: smp_xor_128

D (47716) BT_SMP: smp_encrypt_data

D (47716) BT_SMP: smp_xor_128

D (47726) BT_SMP: smp_encrypt_data

D (47726) BT_SMP: smp_xor_128

D (47726) BT_SMP: smp_encrypt_data

D (47736) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (47736) BT_SMP: p_mac[0] = 0x1c p_mac[1] = 0x59 p_mac[2] = 0xba p_mac[3] = 0xc6
D (47746) BT_SMP: p_mac[4] = 0xe4 p_mac[5] = 0x79 p_mac[6] = 0x08 p_mac[7] = 0xef
D (47756) BT_SMP: local commitment calculation is completed
D (47756) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (47766) BT_SMP:
SMDBG l2c smp_data_received

D (47766) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (47776) BT_SMP: main smp_sm_event

D (47786) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (47796) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (47796) BT_SMP: smp_process_pairing_commitment
D (47806) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (47816) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (47816) BT_SMP: smp_send_commitment
D (47826) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (47826) BT_SMP: smp_build_pairing_commitment_cmd

D (47836) BT_SMP: smp_send_msg_to_L2CAP
D (47836) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (47966) BT_SMP:
SMDBG l2c smp_data_received

D (47976) BT_SMP: main smp_sm_event

D (47976) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (47976) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (47986) BT_SMP: smp_proc_rand

D (47986) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (47996) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (48006) BT_SMP: smp_process_peer_nonce start

D (48006) BT_SMP: smp_check_commitment

D (48016) BT_SMP: smp_calculate_peer_commitment
D (48016) BT_SMP: random: 0x40, round: 4, i: 0, j: 4

D (48026) BT_SMP: smp_calculate_random_input ri=0x80

D (48026) BT_SMP: smp_calculate_f4
D (48026) BT_SMP: aes_cipher_msg_auth_code
D (48036) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (48036) BT_SMP:  cmac_generate_subkey
D (48046) BT_SMP: smp_encrypt_data

D (48046) BT_SMP: cmac_subkey_cont
D (48056) BT_SMP: leftshift_onebit
D (48056) BT_SMP: leftshift_onebit
D (48056) BT_SMP: smp_xor_128

D (48066) BT_SMP: cmac_prepare_last_block
D (48066) BT_SMP: flag = 0 round = 5
D (48066) BT_SMP: smp_xor_128

D (48076) BT_SMP: cmac_aes_k_calculate
D (48076) BT_SMP: smp_xor_128

D (48076) BT_SMP: smp_encrypt_data

D (48086) BT_SMP: smp_xor_128

D (48086) BT_SMP: smp_encrypt_data

D (48086) BT_SMP: smp_xor_128

D (48096) BT_SMP: smp_encrypt_data

D (48096) BT_SMP: smp_xor_128

D (48096) BT_SMP: smp_encrypt_data

D (48106) BT_SMP: smp_xor_128

D (48106) BT_SMP: smp_encrypt_data

D (48106) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (48116) BT_SMP: p_mac[0] = 0x84 p_mac[1] = 0xca p_mac[2] = 0xe7 p_mac[3] = 0x2f
D (48126) BT_SMP: p_mac[4] = 0xf8 p_mac[5] = 0xeb p_mac[6] = 0x32 p_mac[7] = 0x82
D (48126) BT_SMP: peer commitment calculation is completed

D (48136) BT_SMP: Commitment check succeeds

D (48136) BT_SMP: smp_send_rand

D (48146) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (48146) BT_SMP: smp_build_rand_cmd

D (48156) BT_SMP: smp_send_msg_to_L2CAP
D (48156) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (48166) BT_SMP: smp_start_nonce_generation
D (48166) BT_SMP: smp_process_peer_nonce end

D (48176) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (48186) BT_SMP: smp_rand_back state=0xd
D (48186) BT_SMP: smp_finish_nonce_generation
D (48196) BT_SMP: smp_rand_back state=0xe
D (48196) BT_SMP: smp_process_new_nonce round 5
D (48196) BT_SMP: main smp_sm_event

D (48206) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (48216) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (48226) BT_SMP: smp_process_local_nonce

D (48226) BT_SMP: smp_calculate_local_commitment

D (48226) BT_SMP: random: 0x40, round: 5, i: 0, j: 5

D (48236) BT_SMP: smp_calculate_random_input ri=0x80

D (48236) BT_SMP: smp_calculate_f4
D (48246) BT_SMP: aes_cipher_msg_auth_code
D (48246) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (48256) BT_SMP:  cmac_generate_subkey
D (48256) BT_SMP: smp_encrypt_data

D (48266) BT_SMP: cmac_subkey_cont
D (48266) BT_SMP: leftshift_onebit
D (48266) BT_SMP: smp_xor_128

D (48276) BT_SMP: leftshift_onebit
D (48276) BT_SMP: cmac_prepare_last_block
D (48276) BT_SMP: flag = 0 round = 5
D (48286) BT_SMP: smp_xor_128

D (48286) BT_SMP: cmac_aes_k_calculate
D (48286) BT_SMP: smp_xor_128

D (48296) BT_SMP: smp_encrypt_data

D (48296) BT_SMP: smp_xor_128

D (48306) BT_SMP: smp_encrypt_data

D (48306) BT_SMP: smp_xor_128

D (48306) BT_SMP: smp_encrypt_data

D (48316) BT_SMP: smp_xor_128

D (48316) BT_SMP: smp_encrypt_data

D (48316) BT_SMP: smp_xor_128

D (48326) BT_SMP: smp_encrypt_data

D (48326) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (48326) BT_SMP: p_mac[0] = 0x3e p_mac[1] = 0x80 p_mac[2] = 0x39 p_mac[3] = 0xd7
D (48336) BT_SMP: p_mac[4] = 0x85 p_mac[5] = 0x94 p_mac[6] = 0xeb p_mac[7] = 0x39
D (48346) BT_SMP: local commitment calculation is completed
D (48346) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (48356) BT_SMP:
SMDBG l2c smp_data_received

D (48366) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (48366) BT_SMP: main smp_sm_event

D (48376) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (48386) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (48396) BT_SMP: smp_process_pairing_commitment
D (48396) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (48406) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (48406) BT_SMP: smp_send_commitment
D (48416) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (48416) BT_SMP: smp_build_pairing_commitment_cmd

D (48426) BT_SMP: smp_send_msg_to_L2CAP
D (48426) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (48506) BT_SMP:
SMDBG l2c smp_data_received

D (48516) BT_SMP: main smp_sm_event

D (48516) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (48516) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (48526) BT_SMP: smp_proc_rand

D (48526) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (48536) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (48546) BT_SMP: smp_process_peer_nonce start

D (48546) BT_SMP: smp_check_commitment

D (48556) BT_SMP: smp_calculate_peer_commitment
D (48556) BT_SMP: random: 0x40, round: 5, i: 0, j: 5

D (48566) BT_SMP: smp_calculate_random_input ri=0x80

D (48566) BT_SMP: smp_calculate_f4
D (48566) BT_SMP: aes_cipher_msg_auth_code
D (48576) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (48576) BT_SMP:  cmac_generate_subkey
D (48586) BT_SMP: smp_encrypt_data

D (48586) BT_SMP: cmac_subkey_cont
D (48596) BT_SMP: leftshift_onebit
D (48596) BT_SMP: smp_xor_128

D (48596) BT_SMP: leftshift_onebit
D (48606) BT_SMP: cmac_prepare_last_block
D (48606) BT_SMP: flag = 0 round = 5
D (48606) BT_SMP: smp_xor_128

D (48616) BT_SMP: cmac_aes_k_calculate
D (48616) BT_SMP: smp_xor_128

D (48616) BT_SMP: smp_encrypt_data

D (48626) BT_SMP: smp_xor_128

D (48626) BT_SMP: smp_encrypt_data

D (48626) BT_SMP: smp_xor_128

D (48636) BT_SMP: smp_encrypt_data

D (48636) BT_SMP: smp_xor_128

D (48636) BT_SMP: smp_encrypt_data

D (48646) BT_SMP: smp_xor_128

D (48646) BT_SMP: smp_encrypt_data

D (48646) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (48656) BT_SMP: p_mac[0] = 0x35 p_mac[1] = 0x5e p_mac[2] = 0x12 p_mac[3] = 0x8a
D (48666) BT_SMP: p_mac[4] = 0x40 p_mac[5] = 0xd0 p_mac[6] = 0x22 p_mac[7] = 0x8b
D (48666) BT_SMP: peer commitment calculation is completed

D (48676) BT_SMP: Commitment check succeeds

D (48676) BT_SMP: smp_send_rand

D (48686) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (48686) BT_SMP: smp_build_rand_cmd

D (48696) BT_SMP: smp_send_msg_to_L2CAP
D (48696) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (48706) BT_SMP: smp_start_nonce_generation
D (48706) BT_SMP: smp_process_peer_nonce end

D (48716) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (48726) BT_SMP: smp_rand_back state=0xd
D (48726) BT_SMP: smp_finish_nonce_generation
D (48736) BT_SMP: smp_rand_back state=0xe
D (48736) BT_SMP: smp_process_new_nonce round 6
D (48736) BT_SMP: main smp_sm_event

D (48746) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (48756) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (48766) BT_SMP: smp_process_local_nonce

D (48766) BT_SMP: smp_calculate_local_commitment

D (48766) BT_SMP: random: 0x40, round: 6, i: 0, j: 6

D (48776) BT_SMP: smp_calculate_random_input ri=0x81

D (48776) BT_SMP: smp_calculate_f4
D (48786) BT_SMP: aes_cipher_msg_auth_code
D (48786) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (48796) BT_SMP:  cmac_generate_subkey
D (48796) BT_SMP: smp_encrypt_data

D (48806) BT_SMP: cmac_subkey_cont
D (48806) BT_SMP: leftshift_onebit
D (48806) BT_SMP: leftshift_onebit
D (48816) BT_SMP: cmac_prepare_last_block
D (48816) BT_SMP: flag = 0 round = 5
D (48816) BT_SMP: smp_xor_128

D (48826) BT_SMP: cmac_aes_k_calculate
D (48826) BT_SMP: smp_xor_128

D (48826) BT_SMP: smp_encrypt_data

D (48836) BT_SMP: smp_xor_128

D (48836) BT_SMP: smp_encrypt_data

D (48846) BT_SMP: smp_xor_128

D (48846) BT_SMP: smp_encrypt_data

D (48846) BT_SMP: smp_xor_128

D (48856) BT_SMP: smp_encrypt_data

D (48856) BT_SMP: smp_xor_128

D (48856) BT_SMP: smp_encrypt_data

D (48866) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (48866) BT_SMP: p_mac[0] = 0x64 p_mac[1] = 0x7f p_mac[2] = 0x05 p_mac[3] = 0x39
D (48876) BT_SMP: p_mac[4] = 0x5c p_mac[5] = 0xb0 p_mac[6] = 0xcc p_mac[7] = 0xff
D (48886) BT_SMP: local commitment calculation is completed
D (48886) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (48896) BT_SMP:
SMDBG l2c smp_data_received

D (48896) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (48906) BT_SMP: main smp_sm_event

D (48906) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (48916) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (48926) BT_SMP: smp_process_pairing_commitment
D (48936) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (48936) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (48946) BT_SMP: smp_send_commitment
D (48946) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (48956) BT_SMP: smp_build_pairing_commitment_cmd

D (48956) BT_SMP: smp_send_msg_to_L2CAP
D (48966) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (49096) BT_SMP:
SMDBG l2c smp_data_received

D (49096) BT_SMP: main smp_sm_event

D (49096) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (49106) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (49106) BT_SMP: smp_proc_rand

D (49116) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (49116) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (49126) BT_SMP: smp_process_peer_nonce start

D (49136) BT_SMP: smp_check_commitment

D (49136) BT_SMP: smp_calculate_peer_commitment
D (49146) BT_SMP: random: 0x40, round: 6, i: 0, j: 6

D (49146) BT_SMP: smp_calculate_random_input ri=0x81

D (49156) BT_SMP: smp_calculate_f4
D (49156) BT_SMP: aes_cipher_msg_auth_code
D (49156) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (49166) BT_SMP:  cmac_generate_subkey
D (49166) BT_SMP: smp_encrypt_data

D (49176) BT_SMP: cmac_subkey_cont
D (49176) BT_SMP: leftshift_onebit
D (49176) BT_SMP: leftshift_onebit
D (49186) BT_SMP: cmac_prepare_last_block
D (49186) BT_SMP: flag = 0 round = 5
D (49196) BT_SMP: smp_xor_128

D (49196) BT_SMP: cmac_aes_k_calculate
D (49196) BT_SMP: smp_xor_128

D (49206) BT_SMP: smp_encrypt_data

D (49206) BT_SMP: smp_xor_128

D (49206) BT_SMP: smp_encrypt_data

D (49216) BT_SMP: smp_xor_128

D (49216) BT_SMP: smp_encrypt_data

D (49216) BT_SMP: smp_xor_128

D (49226) BT_SMP: smp_encrypt_data

D (49226) BT_SMP: smp_xor_128

D (49226) BT_SMP: smp_encrypt_data

D (49236) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (49236) BT_SMP: p_mac[0] = 0x0b p_mac[1] = 0xa3 p_mac[2] = 0x9a p_mac[3] = 0x2a
D (49246) BT_SMP: p_mac[4] = 0xff p_mac[5] = 0xcc p_mac[6] = 0x77 p_mac[7] = 0x22
D (49256) BT_SMP: peer commitment calculation is completed

D (49256) BT_SMP: Commitment check succeeds

D (49266) BT_SMP: smp_send_rand

D (49266) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (49266) BT_SMP: smp_build_rand_cmd

D (49276) BT_SMP: smp_send_msg_to_L2CAP
D (49276) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (49286) BT_SMP: smp_start_nonce_generation
D (49296) BT_SMP: smp_process_peer_nonce end

D (49296) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (49306) BT_SMP: smp_rand_back state=0xd
D (49306) BT_SMP: smp_finish_nonce_generation
D (49316) BT_SMP: smp_rand_back state=0xe
D (49316) BT_SMP: smp_process_new_nonce round 7
D (49316) BT_SMP: main smp_sm_event

D (49326) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (49336) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (49346) BT_SMP: smp_process_local_nonce

D (49346) BT_SMP: smp_calculate_local_commitment

D (49356) BT_SMP: random: 0x40, round: 7, i: 0, j: 7

D (49356) BT_SMP: smp_calculate_random_input ri=0x80

D (49366) BT_SMP: smp_calculate_f4
D (49366) BT_SMP: aes_cipher_msg_auth_code
D (49366) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (49376) BT_SMP:  cmac_generate_subkey
D (49376) BT_SMP: smp_encrypt_data

D (49386) BT_SMP: cmac_subkey_cont
D (49386) BT_SMP: leftshift_onebit
D (49396) BT_SMP: smp_xor_128

D (49396) BT_SMP: leftshift_onebit
D (49396) BT_SMP: cmac_prepare_last_block
D (49406) BT_SMP: flag = 0 round = 5
D (49406) BT_SMP: smp_xor_128

D (49406) BT_SMP: cmac_aes_k_calculate
D (49416) BT_SMP: smp_xor_128

D (49416) BT_SMP: smp_encrypt_data

D (49416) BT_SMP: smp_xor_128

D (49426) BT_SMP: smp_encrypt_data

D (49426) BT_SMP: smp_xor_128

D (49426) BT_SMP: smp_encrypt_data

D (49436) BT_SMP: smp_xor_128

D (49436) BT_SMP: smp_encrypt_data

D (49436) BT_SMP: smp_xor_128

D (49446) BT_SMP: smp_encrypt_data

D (49446) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (49456) BT_SMP: p_mac[0] = 0x6d p_mac[1] = 0x1d p_mac[2] = 0x5b p_mac[3] = 0xbf
D (49456) BT_SMP: p_mac[4] = 0x11 p_mac[5] = 0x35 p_mac[6] = 0xbb p_mac[7] = 0x6e
D (49466) BT_SMP: local commitment calculation is completed
D (49476) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (49476) BT_SMP:
SMDBG l2c smp_data_received

D (49486) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (49496) BT_SMP: main smp_sm_event

D (49496) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (49506) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (49516) BT_SMP: smp_process_pairing_commitment
D (49516) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (49526) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (49536) BT_SMP: smp_send_commitment
D (49536) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (49536) BT_SMP: smp_build_pairing_commitment_cmd

D (49546) BT_SMP: smp_send_msg_to_L2CAP
D (49546) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (49636) BT_SMP:
SMDBG l2c smp_data_received

D (49636) BT_SMP: main smp_sm_event

D (49636) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (49646) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (49646) BT_SMP: smp_proc_rand

D (49656) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (49656) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (49666) BT_SMP: smp_process_peer_nonce start

D (49676) BT_SMP: smp_check_commitment

D (49676) BT_SMP: smp_calculate_peer_commitment
D (49676) BT_SMP: random: 0x40, round: 7, i: 0, j: 7

D (49686) BT_SMP: smp_calculate_random_input ri=0x80

D (49686) BT_SMP: smp_calculate_f4
D (49696) BT_SMP: aes_cipher_msg_auth_code
D (49696) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (49706) BT_SMP:  cmac_generate_subkey
D (49706) BT_SMP: smp_encrypt_data

D (49716) BT_SMP: cmac_subkey_cont
D (49716) BT_SMP: leftshift_onebit
D (49716) BT_SMP: smp_xor_128

D (49726) BT_SMP: leftshift_onebit
D (49726) BT_SMP: cmac_prepare_last_block
D (49726) BT_SMP: flag = 0 round = 5
D (49736) BT_SMP: smp_xor_128

D (49736) BT_SMP: cmac_aes_k_calculate
D (49746) BT_SMP: smp_xor_128

D (49746) BT_SMP: smp_encrypt_data

D (49746) BT_SMP: smp_xor_128

D (49756) BT_SMP: smp_encrypt_data

D (49756) BT_SMP: smp_xor_128

D (49756) BT_SMP: smp_encrypt_data

D (49766) BT_SMP: smp_xor_128

D (49766) BT_SMP: smp_encrypt_data

D (49766) BT_SMP: smp_xor_128

D (49776) BT_SMP: smp_encrypt_data

D (49776) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (49776) BT_SMP: p_mac[0] = 0xc0 p_mac[1] = 0x04 p_mac[2] = 0xeb p_mac[3] = 0x3d
D (49786) BT_SMP: p_mac[4] = 0xe7 p_mac[5] = 0xb8 p_mac[6] = 0xe8 p_mac[7] = 0x75
D (49796) BT_SMP: peer commitment calculation is completed

D (49796) BT_SMP: Commitment check succeeds

D (49806) BT_SMP: smp_send_rand

D (49806) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (49816) BT_SMP: smp_build_rand_cmd

D (49816) BT_SMP: smp_send_msg_to_L2CAP
D (49826) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (49826) BT_SMP: smp_start_nonce_generation
D (49836) BT_SMP: smp_process_peer_nonce end

D (49836) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (49846) BT_SMP: smp_rand_back state=0xd
D (49846) BT_SMP: smp_finish_nonce_generation
D (49856) BT_SMP: smp_rand_back state=0xe
D (49856) BT_SMP: smp_process_new_nonce round 8
D (49866) BT_SMP: main smp_sm_event

D (49866) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (49876) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (49886) BT_SMP: smp_process_local_nonce

D (49886) BT_SMP: smp_calculate_local_commitment

D (49896) BT_SMP: random: 0xe2, round: 8, i: 1, j: 0

D (49896) BT_SMP: smp_calculate_random_input ri=0x80

D (49906) BT_SMP: smp_calculate_f4
D (49906) BT_SMP: aes_cipher_msg_auth_code
D (49916) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (49916) BT_SMP:  cmac_generate_subkey
D (49926) BT_SMP: smp_encrypt_data

D (49926) BT_SMP: cmac_subkey_cont
D (49926) BT_SMP: leftshift_onebit
D (49936) BT_SMP: leftshift_onebit
D (49936) BT_SMP: smp_xor_128

D (49936) BT_SMP: cmac_prepare_last_block
D (49946) BT_SMP: flag = 0 round = 5
D (49946) BT_SMP: smp_xor_128

D (49956) BT_SMP: cmac_aes_k_calculate
D (49956) BT_SMP: smp_xor_128

D (49956) BT_SMP: smp_encrypt_data

D (49966) BT_SMP: smp_xor_128

D (49966) BT_SMP: smp_encrypt_data

D (49966) BT_SMP: smp_xor_128

D (49976) BT_SMP: smp_encrypt_data

D (49976) BT_SMP: smp_xor_128

D (49976) BT_SMP: smp_encrypt_data

D (49986) BT_SMP: smp_xor_128

D (49986) BT_SMP: smp_encrypt_data

D (49986) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (49996) BT_SMP: p_mac[0] = 0xa5 p_mac[1] = 0xa7 p_mac[2] = 0xe8 p_mac[3] = 0x1a
D (50006) BT_SMP: p_mac[4] = 0x07 p_mac[5] = 0x5e p_mac[6] = 0xf1 p_mac[7] = 0x01
D (50006) BT_SMP: local commitment calculation is completed
D (50016) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (50026) BT_SMP:
SMDBG l2c smp_data_received

D (50026) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (50036) BT_SMP: main smp_sm_event

D (50036) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (50046) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (50056) BT_SMP: smp_process_pairing_commitment
D (50056) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (50066) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (50076) BT_SMP: smp_send_commitment
D (50076) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (50086) BT_SMP: smp_build_pairing_commitment_cmd

D (50086) BT_SMP: smp_send_msg_to_L2CAP
D (50096) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (50176) BT_SMP:
SMDBG l2c smp_data_received

D (50176) BT_SMP: main smp_sm_event

D (50176) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (50186) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (50186) BT_SMP: smp_proc_rand

D (50196) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (50196) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (50206) BT_SMP: smp_process_peer_nonce start

D (50216) BT_SMP: smp_check_commitment

D (50216) BT_SMP: smp_calculate_peer_commitment
D (50216) BT_SMP: random: 0xe2, round: 8, i: 1, j: 0

D (50226) BT_SMP: smp_calculate_random_input ri=0x80

D (50226) BT_SMP: smp_calculate_f4
D (50236) BT_SMP: aes_cipher_msg_auth_code
D (50236) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (50246) BT_SMP:  cmac_generate_subkey
D (50246) BT_SMP: smp_encrypt_data

D (50256) BT_SMP: cmac_subkey_cont
D (50256) BT_SMP: leftshift_onebit
D (50256) BT_SMP: smp_xor_128

D (50266) BT_SMP: leftshift_onebit
D (50266) BT_SMP: cmac_prepare_last_block
D (50266) BT_SMP: flag = 0 round = 5
D (50276) BT_SMP: smp_xor_128

D (50276) BT_SMP: cmac_aes_k_calculate
D (50286) BT_SMP: smp_xor_128

D (50286) BT_SMP: smp_encrypt_data

D (50286) BT_SMP: smp_xor_128

D (50296) BT_SMP: smp_encrypt_data

D (50296) BT_SMP: smp_xor_128

D (50296) BT_SMP: smp_encrypt_data

D (50306) BT_SMP: smp_xor_128

D (50306) BT_SMP: smp_encrypt_data

D (50306) BT_SMP: smp_xor_128

D (50316) BT_SMP: smp_encrypt_data

D (50316) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (50316) BT_SMP: p_mac[0] = 0x85 p_mac[1] = 0x1d p_mac[2] = 0xdc p_mac[3] = 0xcc
D (50326) BT_SMP: p_mac[4] = 0x50 p_mac[5] = 0x4f p_mac[6] = 0x0b p_mac[7] = 0x51
D (50336) BT_SMP: peer commitment calculation is completed

D (50336) BT_SMP: Commitment check succeeds

D (50346) BT_SMP: smp_send_rand

D (50346) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (50356) BT_SMP: smp_build_rand_cmd

D (50356) BT_SMP: smp_send_msg_to_L2CAP
D (50366) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (50366) BT_SMP: smp_start_nonce_generation
D (50376) BT_SMP: smp_process_peer_nonce end

D (50376) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (50386) BT_SMP: smp_rand_back state=0xd
D (50386) BT_SMP: smp_finish_nonce_generation
D (50396) BT_SMP: smp_rand_back state=0xe
D (50396) BT_SMP: smp_process_new_nonce round 9
D (50406) BT_SMP: main smp_sm_event

D (50406) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (50416) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (50426) BT_SMP: smp_process_local_nonce

D (50426) BT_SMP: smp_calculate_local_commitment

D (50436) BT_SMP: random: 0xe2, round: 9, i: 1, j: 1

D (50436) BT_SMP: smp_calculate_random_input ri=0x81

D (50446) BT_SMP: smp_calculate_f4
D (50446) BT_SMP: aes_cipher_msg_auth_code
D (50456) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (50456) BT_SMP:  cmac_generate_subkey
D (50466) BT_SMP: smp_encrypt_data

D (50466) BT_SMP: cmac_subkey_cont
D (50466) BT_SMP: leftshift_onebit
D (50476) BT_SMP: smp_xor_128

D (50476) BT_SMP: leftshift_onebit
D (50476) BT_SMP: cmac_prepare_last_block
D (50486) BT_SMP: flag = 0 round = 5
D (50486) BT_SMP: smp_xor_128

D (50496) BT_SMP: cmac_aes_k_calculate
D (50496) BT_SMP: smp_xor_128

D (50496) BT_SMP: smp_encrypt_data

D (50506) BT_SMP: smp_xor_128

D (50506) BT_SMP: smp_encrypt_data

D (50506) BT_SMP: smp_xor_128

D (50516) BT_SMP: smp_encrypt_data

D (50516) BT_SMP: smp_xor_128

D (50516) BT_SMP: smp_encrypt_data

D (50526) BT_SMP: smp_xor_128

D (50526) BT_SMP: smp_encrypt_data

D (50526) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (50536) BT_SMP: p_mac[0] = 0xb6 p_mac[1] = 0x08 p_mac[2] = 0xdb p_mac[3] = 0x45
D (50546) BT_SMP: p_mac[4] = 0xfb p_mac[5] = 0xd6 p_mac[6] = 0x0b p_mac[7] = 0xf6
D (50546) BT_SMP: local commitment calculation is completed
D (50556) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (50566) BT_SMP:
SMDBG l2c smp_data_received

D (50566) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (50576) BT_SMP: main smp_sm_event

D (50576) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (50586) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (50596) BT_SMP: smp_process_pairing_commitment
D (50596) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (50606) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (50616) BT_SMP: smp_send_commitment
D (50616) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (50626) BT_SMP: smp_build_pairing_commitment_cmd

D (50626) BT_SMP: smp_send_msg_to_L2CAP
D (50636) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (50756) BT_SMP:
SMDBG l2c smp_data_received

D (50766) BT_SMP: main smp_sm_event

D (50766) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (50766) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (50776) BT_SMP: smp_proc_rand

D (50776) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (50786) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (50796) BT_SMP: smp_process_peer_nonce start

D (50796) BT_SMP: smp_check_commitment

D (50796) BT_SMP: smp_calculate_peer_commitment
D (50806) BT_SMP: random: 0xe2, round: 9, i: 1, j: 1

D (50806) BT_SMP: smp_calculate_random_input ri=0x81

D (50816) BT_SMP: smp_calculate_f4
D (50816) BT_SMP: aes_cipher_msg_auth_code
D (50826) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (50826) BT_SMP:  cmac_generate_subkey
D (50836) BT_SMP: smp_encrypt_data

D (50836) BT_SMP: cmac_subkey_cont
D (50836) BT_SMP: leftshift_onebit
D (50846) BT_SMP: leftshift_onebit
D (50846) BT_SMP: cmac_prepare_last_block
D (50856) BT_SMP: flag = 0 round = 5
D (50856) BT_SMP: smp_xor_128

D (50856) BT_SMP: cmac_aes_k_calculate
D (50866) BT_SMP: smp_xor_128

D (50866) BT_SMP: smp_encrypt_data

D (50866) BT_SMP: smp_xor_128

D (50876) BT_SMP: smp_encrypt_data

D (50876) BT_SMP: smp_xor_128

D (50876) BT_SMP: smp_encrypt_data

D (50886) BT_SMP: smp_xor_128

D (50886) BT_SMP: smp_encrypt_data

D (50886) BT_SMP: smp_xor_128

D (50896) BT_SMP: smp_encrypt_data

D (50896) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (50906) BT_SMP: p_mac[0] = 0x10 p_mac[1] = 0x4a p_mac[2] = 0x51 p_mac[3] = 0xfa
D (50906) BT_SMP: p_mac[4] = 0x09 p_mac[5] = 0xdf p_mac[6] = 0x6b p_mac[7] = 0x3b
D (50916) BT_SMP: peer commitment calculation is completed

D (50926) BT_SMP: Commitment check succeeds

D (50926) BT_SMP: smp_send_rand

D (50926) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (50936) BT_SMP: smp_build_rand_cmd

D (50936) BT_SMP: smp_send_msg_to_L2CAP
D (50946) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (50956) BT_SMP: smp_start_nonce_generation
D (50956) BT_SMP: smp_process_peer_nonce end

D (50966) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (50966) BT_SMP: smp_rand_back state=0xd
D (50976) BT_SMP: smp_finish_nonce_generation
D (50976) BT_SMP: smp_rand_back state=0xe
D (50976) BT_SMP: smp_process_new_nonce round 10
D (50986) BT_SMP: main smp_sm_event

D (50986) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (50996) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (51006) BT_SMP: smp_process_local_nonce

D (51016) BT_SMP: smp_calculate_local_commitment

D (51016) BT_SMP: random: 0xe2, round: 10, i: 1, j: 2

D (51026) BT_SMP: smp_calculate_random_input ri=0x80

D (51026) BT_SMP: smp_calculate_f4
D (51026) BT_SMP: aes_cipher_msg_auth_code
D (51036) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (51046) BT_SMP:  cmac_generate_subkey
D (51046) BT_SMP: smp_encrypt_data

D (51046) BT_SMP: cmac_subkey_cont
D (51056) BT_SMP: leftshift_onebit
D (51056) BT_SMP: leftshift_onebit
D (51056) BT_SMP: smp_xor_128

D (51066) BT_SMP: cmac_prepare_last_block
D (51066) BT_SMP: flag = 0 round = 5
D (51066) BT_SMP: smp_xor_128

D (51076) BT_SMP: cmac_aes_k_calculate
D (51076) BT_SMP: smp_xor_128

D (51076) BT_SMP: smp_encrypt_data

D (51086) BT_SMP: smp_xor_128

D (51086) BT_SMP: smp_encrypt_data

D (51096) BT_SMP: smp_xor_128

D (51096) BT_SMP: smp_encrypt_data

D (51096) BT_SMP: smp_xor_128

D (51106) BT_SMP: smp_encrypt_data

D (51106) BT_SMP: smp_xor_128

D (51106) BT_SMP: smp_encrypt_data

D (51116) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (51116) BT_SMP: p_mac[0] = 0x72 p_mac[1] = 0xc1 p_mac[2] = 0x4f p_mac[3] = 0x4e
D (51126) BT_SMP: p_mac[4] = 0x53 p_mac[5] = 0x4c p_mac[6] = 0xa0 p_mac[7] = 0x84
D (51136) BT_SMP: local commitment calculation is completed
D (51136) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (51146) BT_SMP:
SMDBG l2c smp_data_received

D (51146) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (51156) BT_SMP: main smp_sm_event

D (51156) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (51166) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (51176) BT_SMP: smp_process_pairing_commitment
D (51186) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (51186) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (51196) BT_SMP: smp_send_commitment
D (51196) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (51206) BT_SMP: smp_build_pairing_commitment_cmd

D (51206) BT_SMP: smp_send_msg_to_L2CAP
D (51216) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (51296) BT_SMP:
SMDBG l2c smp_data_received

D (51306) BT_SMP: main smp_sm_event

D (51306) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (51306) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (51316) BT_SMP: smp_proc_rand

D (51316) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (51326) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (51336) BT_SMP: smp_process_peer_nonce start

D (51336) BT_SMP: smp_check_commitment

D (51336) BT_SMP: smp_calculate_peer_commitment
D (51346) BT_SMP: random: 0xe2, round: 10, i: 1, j: 2

D (51346) BT_SMP: smp_calculate_random_input ri=0x80

D (51356) BT_SMP: smp_calculate_f4
D (51356) BT_SMP: aes_cipher_msg_auth_code
D (51366) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (51366) BT_SMP:  cmac_generate_subkey
D (51376) BT_SMP: smp_encrypt_data

D (51376) BT_SMP: cmac_subkey_cont
D (51376) BT_SMP: leftshift_onebit
D (51386) BT_SMP: leftshift_onebit
D (51386) BT_SMP: cmac_prepare_last_block
D (51396) BT_SMP: flag = 0 round = 5
D (51396) BT_SMP: smp_xor_128

D (51396) BT_SMP: cmac_aes_k_calculate
D (51406) BT_SMP: smp_xor_128

D (51406) BT_SMP: smp_encrypt_data

D (51406) BT_SMP: smp_xor_128

D (51416) BT_SMP: smp_encrypt_data

D (51416) BT_SMP: smp_xor_128

D (51416) BT_SMP: smp_encrypt_data

D (51426) BT_SMP: smp_xor_128

D (51426) BT_SMP: smp_encrypt_data

D (51426) BT_SMP: smp_xor_128

D (51436) BT_SMP: smp_encrypt_data

D (51436) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (51446) BT_SMP: p_mac[0] = 0x4e p_mac[1] = 0xae p_mac[2] = 0xff p_mac[3] = 0xc0
D (51446) BT_SMP: p_mac[4] = 0xff p_mac[5] = 0xe2 p_mac[6] = 0x0b p_mac[7] = 0x81
D (51456) BT_SMP: peer commitment calculation is completed

D (51466) BT_SMP: Commitment check succeeds

D (51466) BT_SMP: smp_send_rand

D (51466) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (51476) BT_SMP: smp_build_rand_cmd

D (51476) BT_SMP: smp_send_msg_to_L2CAP
D (51486) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (51496) BT_SMP: smp_start_nonce_generation
D (51496) BT_SMP: smp_process_peer_nonce end

D (51506) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (51506) BT_SMP: smp_rand_back state=0xd
D (51516) BT_SMP: smp_finish_nonce_generation
D (51516) BT_SMP: smp_rand_back state=0xe
D (51516) BT_SMP: smp_process_new_nonce round 11
D (51526) BT_SMP: main smp_sm_event

D (51526) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (51536) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (51546) BT_SMP: smp_process_local_nonce

D (51556) BT_SMP: smp_calculate_local_commitment

D (51556) BT_SMP: random: 0xe2, round: 11, i: 1, j: 3

D (51566) BT_SMP: smp_calculate_random_input ri=0x80

D (51566) BT_SMP: smp_calculate_f4
D (51566) BT_SMP: aes_cipher_msg_auth_code
D (51576) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (51586) BT_SMP:  cmac_generate_subkey
D (51586) BT_SMP: smp_encrypt_data

D (51586) BT_SMP: cmac_subkey_cont
D (51596) BT_SMP: leftshift_onebit
D (51596) BT_SMP: leftshift_onebit
D (51596) BT_SMP: smp_xor_128

D (51606) BT_SMP: cmac_prepare_last_block
D (51606) BT_SMP: flag = 0 round = 5
D (51606) BT_SMP: smp_xor_128

D (51616) BT_SMP: cmac_aes_k_calculate
D (51616) BT_SMP: smp_xor_128

D (51616) BT_SMP: smp_encrypt_data

D (51626) BT_SMP: smp_xor_128

D (51626) BT_SMP: smp_encrypt_data

D (51636) BT_SMP: smp_xor_128

D (51636) BT_SMP: smp_encrypt_data

D (51636) BT_SMP: smp_xor_128

D (51646) BT_SMP: smp_encrypt_data

D (51646) BT_SMP: smp_xor_128

D (51646) BT_SMP: smp_encrypt_data

D (51656) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (51656) BT_SMP: p_mac[0] = 0xb1 p_mac[1] = 0x8a p_mac[2] = 0x74 p_mac[3] = 0x25
D (51666) BT_SMP: p_mac[4] = 0xe3 p_mac[5] = 0x77 p_mac[6] = 0x08 p_mac[7] = 0x10
D (51676) BT_SMP: local commitment calculation is completed
D (51676) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (51686) BT_SMP:
SMDBG l2c smp_data_received

D (51686) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (51696) BT_SMP: main smp_sm_event

D (51696) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (51706) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (51716) BT_SMP: smp_process_pairing_commitment
D (51726) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (51726) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (51736) BT_SMP: smp_send_commitment
D (51736) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (51746) BT_SMP: smp_build_pairing_commitment_cmd

D (51746) BT_SMP: smp_send_msg_to_L2CAP
D (51756) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (51886) BT_SMP:
SMDBG l2c smp_data_received

D (51886) BT_SMP: main smp_sm_event

D (51886) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (51896) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (51896) BT_SMP: smp_proc_rand

D (51906) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (51906) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (51916) BT_SMP: smp_process_peer_nonce start

D (51926) BT_SMP: smp_check_commitment

D (51926) BT_SMP: smp_calculate_peer_commitment
D (51926) BT_SMP: random: 0xe2, round: 11, i: 1, j: 3

D (51936) BT_SMP: smp_calculate_random_input ri=0x80

D (51946) BT_SMP: smp_calculate_f4
D (51946) BT_SMP: aes_cipher_msg_auth_code
D (51946) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (51956) BT_SMP:  cmac_generate_subkey
D (51956) BT_SMP: smp_encrypt_data

D (51966) BT_SMP: cmac_subkey_cont
D (51966) BT_SMP: leftshift_onebit
D (51966) BT_SMP: smp_xor_128

D (51976) BT_SMP: leftshift_onebit
D (51976) BT_SMP: cmac_prepare_last_block
D (51976) BT_SMP: flag = 0 round = 5
D (51986) BT_SMP: smp_xor_128

D (51986) BT_SMP: cmac_aes_k_calculate
D (51996) BT_SMP: smp_xor_128

D (51996) BT_SMP: smp_encrypt_data

D (51996) BT_SMP: smp_xor_128

D (52006) BT_SMP: smp_encrypt_data

D (52006) BT_SMP: smp_xor_128

D (52006) BT_SMP: smp_encrypt_data

D (52016) BT_SMP: smp_xor_128

D (52016) BT_SMP: smp_encrypt_data

D (52016) BT_SMP: smp_xor_128

D (52026) BT_SMP: smp_encrypt_data

D (52026) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (52026) BT_SMP: p_mac[0] = 0xcc p_mac[1] = 0x33 p_mac[2] = 0xb6 p_mac[3] = 0x29
D (52036) BT_SMP: p_mac[4] = 0x7d p_mac[5] = 0x82 p_mac[6] = 0x2d p_mac[7] = 0x36
D (52046) BT_SMP: peer commitment calculation is completed

D (52046) BT_SMP: Commitment check succeeds

D (52056) BT_SMP: smp_send_rand

D (52056) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (52066) BT_SMP: smp_build_rand_cmd

D (52066) BT_SMP: smp_send_msg_to_L2CAP
D (52076) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (52076) BT_SMP: smp_start_nonce_generation
D (52086) BT_SMP: smp_process_peer_nonce end

D (52086) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (52096) BT_SMP: smp_rand_back state=0xd
D (52096) BT_SMP: smp_finish_nonce_generation
D (52106) BT_SMP: smp_rand_back state=0xe
D (52106) BT_SMP: smp_process_new_nonce round 12
D (52116) BT_SMP: main smp_sm_event

D (52116) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (52126) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (52136) BT_SMP: smp_process_local_nonce

D (52136) BT_SMP: smp_calculate_local_commitment

D (52146) BT_SMP: random: 0xe2, round: 12, i: 1, j: 4

D (52146) BT_SMP: smp_calculate_random_input ri=0x80

D (52156) BT_SMP: smp_calculate_f4
D (52156) BT_SMP: aes_cipher_msg_auth_code
D (52166) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (52166) BT_SMP:  cmac_generate_subkey
D (52176) BT_SMP: smp_encrypt_data

D (52176) BT_SMP: cmac_subkey_cont
D (52176) BT_SMP: leftshift_onebit
D (52186) BT_SMP: smp_xor_128

D (52186) BT_SMP: leftshift_onebit
D (52186) BT_SMP: smp_xor_128

D (52196) BT_SMP: cmac_prepare_last_block
D (52196) BT_SMP: flag = 0 round = 5
D (52206) BT_SMP: smp_xor_128

D (52206) BT_SMP: cmac_aes_k_calculate
D (52206) BT_SMP: smp_xor_128

D (52216) BT_SMP: smp_encrypt_data

D (52216) BT_SMP: smp_xor_128

D (52216) BT_SMP: smp_encrypt_data

D (52226) BT_SMP: smp_xor_128

D (52226) BT_SMP: smp_encrypt_data

D (52226) BT_SMP: smp_xor_128

D (52236) BT_SMP: smp_encrypt_data

D (52236) BT_SMP: smp_xor_128

D (52236) BT_SMP: smp_encrypt_data

D (52246) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (52246) BT_SMP: p_mac[0] = 0xf0 p_mac[1] = 0x27 p_mac[2] = 0xe6 p_mac[3] = 0xc1
D (52256) BT_SMP: p_mac[4] = 0x72 p_mac[5] = 0x22 p_mac[6] = 0x0d p_mac[7] = 0x1b
D (52266) BT_SMP: local commitment calculation is completed
D (52266) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (52276) BT_SMP:
SMDBG l2c smp_data_received

D (52276) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (52286) BT_SMP: main smp_sm_event

D (52296) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (52306) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (52306) BT_SMP: smp_process_pairing_commitment
D (52316) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (52316) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (52326) BT_SMP: smp_send_commitment
D (52336) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (52336) BT_SMP: smp_build_pairing_commitment_cmd

D (52346) BT_SMP: smp_send_msg_to_L2CAP
D (52346) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (52426) BT_SMP:
SMDBG l2c smp_data_received

D (52426) BT_SMP: main smp_sm_event

D (52426) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (52436) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (52436) BT_SMP: smp_proc_rand

D (52446) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (52446) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (52456) BT_SMP: smp_process_peer_nonce start

D (52466) BT_SMP: smp_check_commitment

D (52466) BT_SMP: smp_calculate_peer_commitment
D (52466) BT_SMP: random: 0xe2, round: 12, i: 1, j: 4

D (52476) BT_SMP: smp_calculate_random_input ri=0x80

D (52486) BT_SMP: smp_calculate_f4
D (52486) BT_SMP: aes_cipher_msg_auth_code
D (52486) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (52496) BT_SMP:  cmac_generate_subkey
D (52496) BT_SMP: smp_encrypt_data

D (52506) BT_SMP: cmac_subkey_cont
D (52506) BT_SMP: leftshift_onebit
D (52506) BT_SMP: leftshift_onebit
D (52516) BT_SMP: cmac_prepare_last_block
D (52516) BT_SMP: flag = 0 round = 5
D (52516) BT_SMP: smp_xor_128

D (52526) BT_SMP: cmac_aes_k_calculate
D (52526) BT_SMP: smp_xor_128

D (52536) BT_SMP: smp_encrypt_data

D (52536) BT_SMP: smp_xor_128

D (52536) BT_SMP: smp_encrypt_data

D (52546) BT_SMP: smp_xor_128

D (52546) BT_SMP: smp_encrypt_data

D (52546) BT_SMP: smp_xor_128

D (52556) BT_SMP: smp_encrypt_data

D (52556) BT_SMP: smp_xor_128

D (52556) BT_SMP: smp_encrypt_data

D (52566) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (52566) BT_SMP: p_mac[0] = 0x25 p_mac[1] = 0x65 p_mac[2] = 0x87 p_mac[3] = 0x9e
D (52576) BT_SMP: p_mac[4] = 0xe2 p_mac[5] = 0x1f p_mac[6] = 0xa8 p_mac[7] = 0xda
D (52586) BT_SMP: peer commitment calculation is completed

D (52586) BT_SMP: Commitment check succeeds

D (52596) BT_SMP: smp_send_rand

D (52596) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (52596) BT_SMP: smp_build_rand_cmd

D (52606) BT_SMP: smp_send_msg_to_L2CAP
D (52606) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (52616) BT_SMP: smp_start_nonce_generation
D (52626) BT_SMP: smp_process_peer_nonce end

D (52626) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (52636) BT_SMP: smp_rand_back state=0xd
D (52636) BT_SMP: smp_finish_nonce_generation
D (52646) BT_SMP: smp_rand_back state=0xe
D (52646) BT_SMP: smp_process_new_nonce round 13
D (52646) BT_SMP: main smp_sm_event

D (52656) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (52666) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (52676) BT_SMP: smp_process_local_nonce

D (52676) BT_SMP: smp_calculate_local_commitment

D (52686) BT_SMP: random: 0xe2, round: 13, i: 1, j: 5

D (52686) BT_SMP: smp_calculate_random_input ri=0x81

D (52696) BT_SMP: smp_calculate_f4
D (52696) BT_SMP: aes_cipher_msg_auth_code
D (52696) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (52706) BT_SMP:  cmac_generate_subkey
D (52706) BT_SMP: smp_encrypt_data

D (52716) BT_SMP: cmac_subkey_cont
D (52716) BT_SMP: leftshift_onebit
D (52716) BT_SMP: leftshift_onebit
D (52726) BT_SMP: smp_xor_128

D (52726) BT_SMP: cmac_prepare_last_block
D (52736) BT_SMP: flag = 0 round = 5
D (52736) BT_SMP: smp_xor_128

D (52736) BT_SMP: cmac_aes_k_calculate
D (52746) BT_SMP: smp_xor_128

D (52746) BT_SMP: smp_encrypt_data

D (52746) BT_SMP: smp_xor_128

D (52756) BT_SMP: smp_encrypt_data

D (52756) BT_SMP: smp_xor_128

D (52756) BT_SMP: smp_encrypt_data

D (52766) BT_SMP: smp_xor_128

D (52766) BT_SMP: smp_encrypt_data

D (52766) BT_SMP: smp_xor_128

D (52776) BT_SMP: smp_encrypt_data

D (52776) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (52786) BT_SMP: p_mac[0] = 0x0a p_mac[1] = 0xa7 p_mac[2] = 0x6a p_mac[3] = 0xcb
D (52786) BT_SMP: p_mac[4] = 0x9b p_mac[5] = 0xeb p_mac[6] = 0x33 p_mac[7] = 0x52
D (52796) BT_SMP: local commitment calculation is completed
D (52806) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (52806) BT_SMP:
SMDBG l2c smp_data_received

D (52816) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (52826) BT_SMP: main smp_sm_event

D (52826) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (52836) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (52846) BT_SMP: smp_process_pairing_commitment
D (52846) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (52856) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (52866) BT_SMP: smp_send_commitment
D (52866) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (52866) BT_SMP: smp_build_pairing_commitment_cmd

D (52876) BT_SMP: smp_send_msg_to_L2CAP
D (52876) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (52966) BT_SMP:
SMDBG l2c smp_data_received

D (52966) BT_SMP: main smp_sm_event

D (52966) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (52976) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (52976) BT_SMP: smp_proc_rand

D (52986) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (52986) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (52996) BT_SMP: smp_process_peer_nonce start

D (53006) BT_SMP: smp_check_commitment

D (53006) BT_SMP: smp_calculate_peer_commitment
D (53006) BT_SMP: random: 0xe2, round: 13, i: 1, j: 5

D (53016) BT_SMP: smp_calculate_random_input ri=0x81

D (53026) BT_SMP: smp_calculate_f4
D (53026) BT_SMP: aes_cipher_msg_auth_code
D (53026) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (53036) BT_SMP:  cmac_generate_subkey
D (53036) BT_SMP: smp_encrypt_data

D (53046) BT_SMP: cmac_subkey_cont
D (53046) BT_SMP: leftshift_onebit
D (53046) BT_SMP: smp_xor_128

D (53056) BT_SMP: leftshift_onebit
D (53056) BT_SMP: smp_xor_128

D (53056) BT_SMP: cmac_prepare_last_block
D (53066) BT_SMP: flag = 0 round = 5
D (53066) BT_SMP: smp_xor_128

D (53066) BT_SMP: cmac_aes_k_calculate
D (53076) BT_SMP: smp_xor_128

D (53076) BT_SMP: smp_encrypt_data

D (53086) BT_SMP: smp_xor_128

D (53086) BT_SMP: smp_encrypt_data

D (53086) BT_SMP: smp_xor_128

D (53096) BT_SMP: smp_encrypt_data

D (53096) BT_SMP: smp_xor_128

D (53096) BT_SMP: smp_encrypt_data

D (53106) BT_SMP: smp_xor_128

D (53106) BT_SMP: smp_encrypt_data

D (53106) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (53116) BT_SMP: p_mac[0] = 0xfd p_mac[1] = 0x1e p_mac[2] = 0x19 p_mac[3] = 0xfb
D (53116) BT_SMP: p_mac[4] = 0x19 p_mac[5] = 0x02 p_mac[6] = 0x01 p_mac[7] = 0x5d
D (53126) BT_SMP: peer commitment calculation is completed

D (53136) BT_SMP: Commitment check succeeds

D (53136) BT_SMP: smp_send_rand

D (53146) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (53146) BT_SMP: smp_build_rand_cmd

D (53146) BT_SMP: smp_send_msg_to_L2CAP
D (53156) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (53166) BT_SMP: smp_start_nonce_generation
D (53166) BT_SMP: smp_process_peer_nonce end

D (53176) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (53176) BT_SMP: smp_rand_back state=0xd
D (53186) BT_SMP: smp_finish_nonce_generation
D (53196) BT_SMP: smp_rand_back state=0xe
D (53196) BT_SMP: smp_process_new_nonce round 14
D (53196) BT_SMP: main smp_sm_event

D (53196) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (53206) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (53216) BT_SMP: smp_process_local_nonce

D (53226) BT_SMP: smp_calculate_local_commitment

D (53226) BT_SMP: random: 0xe2, round: 14, i: 1, j: 6

D (53236) BT_SMP: smp_calculate_random_input ri=0x81

D (53236) BT_SMP: smp_calculate_f4
D (53246) BT_SMP: aes_cipher_msg_auth_code
D (53246) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (53256) BT_SMP:  cmac_generate_subkey
D (53256) BT_SMP: smp_encrypt_data

D (53256) BT_SMP: cmac_subkey_cont
D (53266) BT_SMP: leftshift_onebit
D (53266) BT_SMP: smp_xor_128

D (53266) BT_SMP: leftshift_onebit
D (53276) BT_SMP: cmac_prepare_last_block
D (53276) BT_SMP: flag = 0 round = 5
D (53286) BT_SMP: smp_xor_128

D (53286) BT_SMP: cmac_aes_k_calculate
D (53286) BT_SMP: smp_xor_128

D (53296) BT_SMP: smp_encrypt_data

D (53296) BT_SMP: smp_xor_128

D (53296) BT_SMP: smp_encrypt_data

D (53306) BT_SMP: smp_xor_128

D (53306) BT_SMP: smp_encrypt_data

D (53306) BT_SMP: smp_xor_128

D (53316) BT_SMP: smp_encrypt_data

D (53316) BT_SMP: smp_xor_128

D (53316) BT_SMP: smp_encrypt_data

D (53326) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (53326) BT_SMP: p_mac[0] = 0x4d p_mac[1] = 0xe9 p_mac[2] = 0x4b p_mac[3] = 0x25
D (53336) BT_SMP: p_mac[4] = 0xfc p_mac[5] = 0x58 p_mac[6] = 0xbf p_mac[7] = 0x1c
D (53346) BT_SMP: local commitment calculation is completed
D (53346) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (53356) BT_SMP:
SMDBG l2c smp_data_received

D (53356) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (53366) BT_SMP: main smp_sm_event

D (53376) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (53386) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (53386) BT_SMP: smp_process_pairing_commitment
D (53396) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (53396) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (53406) BT_SMP: smp_send_commitment
D (53416) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (53416) BT_SMP: smp_build_pairing_commitment_cmd

D (53426) BT_SMP: smp_send_msg_to_L2CAP
D (53426) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (53506) BT_SMP:
SMDBG l2c smp_data_received

D (53506) BT_SMP: main smp_sm_event

D (53506) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (53516) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (53516) BT_SMP: smp_proc_rand

D (53526) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (53526) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (53536) BT_SMP: smp_process_peer_nonce start

D (53546) BT_SMP: smp_check_commitment

D (53546) BT_SMP: smp_calculate_peer_commitment
D (53546) BT_SMP: random: 0xe2, round: 14, i: 1, j: 6

D (53556) BT_SMP: smp_calculate_random_input ri=0x81

D (53566) BT_SMP: smp_calculate_f4
D (53566) BT_SMP: aes_cipher_msg_auth_code
D (53566) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (53576) BT_SMP:  cmac_generate_subkey
D (53576) BT_SMP: smp_encrypt_data

D (53586) BT_SMP: cmac_subkey_cont
D (53586) BT_SMP: leftshift_onebit
D (53586) BT_SMP: leftshift_onebit
D (53596) BT_SMP: cmac_prepare_last_block
D (53596) BT_SMP: flag = 0 round = 5
D (53596) BT_SMP: smp_xor_128

D (53606) BT_SMP: cmac_aes_k_calculate
D (53606) BT_SMP: smp_xor_128

D (53616) BT_SMP: smp_encrypt_data

D (53616) BT_SMP: smp_xor_128

D (53616) BT_SMP: smp_encrypt_data

D (53626) BT_SMP: smp_xor_128

D (53626) BT_SMP: smp_encrypt_data

D (53626) BT_SMP: smp_xor_128

D (53636) BT_SMP: smp_encrypt_data

D (53636) BT_SMP: smp_xor_128

D (53636) BT_SMP: smp_encrypt_data

D (53646) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (53646) BT_SMP: p_mac[0] = 0x97 p_mac[1] = 0xa7 p_mac[2] = 0xea p_mac[3] = 0xc7
D (53656) BT_SMP: p_mac[4] = 0xa6 p_mac[5] = 0xb7 p_mac[6] = 0x3a p_mac[7] = 0xcd
D (53666) BT_SMP: peer commitment calculation is completed

D (53666) BT_SMP: Commitment check succeeds

D (53676) BT_SMP: smp_send_rand

D (53676) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (53676) BT_SMP: smp_build_rand_cmd

D (53686) BT_SMP: smp_send_msg_to_L2CAP
D (53686) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (53696) BT_SMP: smp_start_nonce_generation
D (53706) BT_SMP: smp_process_peer_nonce end

D (53706) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (53716) BT_SMP: smp_rand_back state=0xd
D (53716) BT_SMP: smp_finish_nonce_generation
D (53726) BT_SMP: smp_rand_back state=0xe
D (53726) BT_SMP: smp_process_new_nonce round 15
D (53726) BT_SMP: main smp_sm_event

D (53736) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (53746) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (53756) BT_SMP: smp_process_local_nonce

D (53756) BT_SMP: smp_calculate_local_commitment

D (53766) BT_SMP: random: 0xe2, round: 15, i: 1, j: 7

D (53766) BT_SMP: smp_calculate_random_input ri=0x81

D (53776) BT_SMP: smp_calculate_f4
D (53776) BT_SMP: aes_cipher_msg_auth_code
D (53776) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (53786) BT_SMP:  cmac_generate_subkey
D (53786) BT_SMP: smp_encrypt_data

D (53796) BT_SMP: cmac_subkey_cont
D (53796) BT_SMP: leftshift_onebit
D (53796) BT_SMP: smp_xor_128

D (53806) BT_SMP: leftshift_onebit
D (53806) BT_SMP: cmac_prepare_last_block
D (53816) BT_SMP: flag = 0 round = 5
D (53816) BT_SMP: smp_xor_128

D (53816) BT_SMP: cmac_aes_k_calculate
D (53826) BT_SMP: smp_xor_128

D (53826) BT_SMP: smp_encrypt_data

D (53826) BT_SMP: smp_xor_128

D (53836) BT_SMP: smp_encrypt_data

D (53836) BT_SMP: smp_xor_128

D (53836) BT_SMP: smp_encrypt_data

D (53846) BT_SMP: smp_xor_128

D (53846) BT_SMP: smp_encrypt_data

D (53846) BT_SMP: smp_xor_128

D (53856) BT_SMP: smp_encrypt_data

D (53856) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (53866) BT_SMP: p_mac[0] = 0xff p_mac[1] = 0xd5 p_mac[2] = 0xf8 p_mac[3] = 0xc8
D (53866) BT_SMP: p_mac[4] = 0x09 p_mac[5] = 0x18 p_mac[6] = 0x58 p_mac[7] = 0xc4
D (53876) BT_SMP: local commitment calculation is completed
D (53886) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (53886) BT_SMP:
SMDBG l2c smp_data_received

D (53896) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (53906) BT_SMP: main smp_sm_event

D (53906) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (53916) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (53926) BT_SMP: smp_process_pairing_commitment
D (53926) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (53936) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (53946) BT_SMP: smp_send_commitment
D (53946) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (53946) BT_SMP: smp_build_pairing_commitment_cmd

D (53956) BT_SMP: smp_send_msg_to_L2CAP
D (53956) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (54046) BT_SMP:
SMDBG l2c smp_data_received

D (54046) BT_SMP: main smp_sm_event

D (54046) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (54056) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (54056) BT_SMP: smp_proc_rand

D (54066) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (54066) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (54076) BT_SMP: smp_process_peer_nonce start

D (54086) BT_SMP: smp_check_commitment

D (54086) BT_SMP: smp_calculate_peer_commitment
D (54086) BT_SMP: random: 0xe2, round: 15, i: 1, j: 7

D (54096) BT_SMP: smp_calculate_random_input ri=0x81

D (54106) BT_SMP: smp_calculate_f4
D (54106) BT_SMP: aes_cipher_msg_auth_code
D (54106) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (54116) BT_SMP:  cmac_generate_subkey
D (54116) BT_SMP: smp_encrypt_data

D (54126) BT_SMP: cmac_subkey_cont
D (54126) BT_SMP: leftshift_onebit
D (54126) BT_SMP: smp_xor_128

D (54136) BT_SMP: leftshift_onebit
D (54136) BT_SMP: cmac_prepare_last_block
D (54136) BT_SMP: flag = 0 round = 5
D (54146) BT_SMP: smp_xor_128

D (54146) BT_SMP: cmac_aes_k_calculate
D (54156) BT_SMP: smp_xor_128

D (54156) BT_SMP: smp_encrypt_data

D (54156) BT_SMP: smp_xor_128

D (54166) BT_SMP: smp_encrypt_data

D (54166) BT_SMP: smp_xor_128

D (54166) BT_SMP: smp_encrypt_data

D (54176) BT_SMP: smp_xor_128

D (54176) BT_SMP: smp_encrypt_data

D (54176) BT_SMP: smp_xor_128

D (54186) BT_SMP: smp_encrypt_data

D (54186) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (54186) BT_SMP: p_mac[0] = 0x3b p_mac[1] = 0x26 p_mac[2] = 0x0f p_mac[3] = 0x29
D (54196) BT_SMP: p_mac[4] = 0xd5 p_mac[5] = 0xff p_mac[6] = 0x0f p_mac[7] = 0x61
D (54206) BT_SMP: peer commitment calculation is completed

D (54206) BT_SMP: Commitment check succeeds

D (54216) BT_SMP: smp_send_rand

D (54216) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (54226) BT_SMP: smp_build_rand_cmd

D (54226) BT_SMP: smp_send_msg_to_L2CAP
D (54236) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (54236) BT_SMP: smp_start_nonce_generation
D (54246) BT_SMP: smp_process_peer_nonce end

D (54246) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (54256) BT_SMP: smp_rand_back state=0xd
D (54256) BT_SMP: smp_finish_nonce_generation
D (54266) BT_SMP: smp_rand_back state=0xe
D (54266) BT_SMP: smp_process_new_nonce round 16
D (54276) BT_SMP: main smp_sm_event

D (54276) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (54286) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (54296) BT_SMP: smp_process_local_nonce

D (54296) BT_SMP: smp_calculate_local_commitment

D (54306) BT_SMP: random: 0x01, round: 16, i: 2, j: 0

D (54306) BT_SMP: smp_calculate_random_input ri=0x81

D (54316) BT_SMP: smp_calculate_f4
D (54316) BT_SMP: aes_cipher_msg_auth_code
D (54326) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (54326) BT_SMP:  cmac_generate_subkey
D (54336) BT_SMP: smp_encrypt_data

D (54336) BT_SMP: cmac_subkey_cont
D (54336) BT_SMP: leftshift_onebit
D (54346) BT_SMP: smp_xor_128

D (54346) BT_SMP: leftshift_onebit
D (54346) BT_SMP: cmac_prepare_last_block
D (54356) BT_SMP: flag = 0 round = 5
D (54356) BT_SMP: smp_xor_128

D (54366) BT_SMP: cmac_aes_k_calculate
D (54366) BT_SMP: smp_xor_128

D (54366) BT_SMP: smp_encrypt_data

D (54376) BT_SMP: smp_xor_128

D (54376) BT_SMP: smp_encrypt_data

D (54376) BT_SMP: smp_xor_128

D (54386) BT_SMP: smp_encrypt_data

D (54386) BT_SMP: smp_xor_128

D (54386) BT_SMP: smp_encrypt_data

D (54396) BT_SMP: smp_xor_128

D (54396) BT_SMP: smp_encrypt_data

D (54396) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (54406) BT_SMP: p_mac[0] = 0x60 p_mac[1] = 0x19 p_mac[2] = 0x19 p_mac[3] = 0xd8
D (54416) BT_SMP: p_mac[4] = 0x15 p_mac[5] = 0x9f p_mac[6] = 0xd4 p_mac[7] = 0x68
D (54416) BT_SMP: local commitment calculation is completed
D (54426) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (54436) BT_SMP:
SMDBG l2c smp_data_received

D (54436) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (54446) BT_SMP: main smp_sm_event

D (54446) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (54456) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (54466) BT_SMP: smp_process_pairing_commitment
D (54466) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (54476) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (54486) BT_SMP: smp_send_commitment
D (54486) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (54496) BT_SMP: smp_build_pairing_commitment_cmd

D (54496) BT_SMP: smp_send_msg_to_L2CAP
D (54506) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (54586) BT_SMP:
SMDBG l2c smp_data_received

D (54586) BT_SMP: main smp_sm_event

D (54586) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (54596) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (54596) BT_SMP: smp_proc_rand

D (54606) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (54606) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (54616) BT_SMP: smp_process_peer_nonce start

D (54626) BT_SMP: smp_check_commitment

D (54626) BT_SMP: smp_calculate_peer_commitment
D (54626) BT_SMP: random: 0x01, round: 16, i: 2, j: 0

D (54636) BT_SMP: smp_calculate_random_input ri=0x81

D (54646) BT_SMP: smp_calculate_f4
D (54646) BT_SMP: aes_cipher_msg_auth_code
D (54646) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (54656) BT_SMP:  cmac_generate_subkey
D (54656) BT_SMP: smp_encrypt_data

D (54666) BT_SMP: cmac_subkey_cont
D (54666) BT_SMP: leftshift_onebit
D (54666) BT_SMP: leftshift_onebit
D (54676) BT_SMP: cmac_prepare_last_block
D (54676) BT_SMP: flag = 0 round = 5
D (54676) BT_SMP: smp_xor_128

D (54686) BT_SMP: cmac_aes_k_calculate
D (54686) BT_SMP: smp_xor_128

D (54696) BT_SMP: smp_encrypt_data

D (54696) BT_SMP: smp_xor_128

D (54696) BT_SMP: smp_encrypt_data

D (54706) BT_SMP: smp_xor_128

D (54706) BT_SMP: smp_encrypt_data

D (54706) BT_SMP: smp_xor_128

D (54716) BT_SMP: smp_encrypt_data

D (54716) BT_SMP: smp_xor_128

D (54716) BT_SMP: smp_encrypt_data

D (54726) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (54726) BT_SMP: p_mac[0] = 0x75 p_mac[1] = 0xd5 p_mac[2] = 0x38 p_mac[3] = 0x44
D (54736) BT_SMP: p_mac[4] = 0x29 p_mac[5] = 0x0d p_mac[6] = 0x7f p_mac[7] = 0x29
D (54746) BT_SMP: peer commitment calculation is completed

D (54746) BT_SMP: Commitment check succeeds

D (54756) BT_SMP: smp_send_rand

D (54756) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (54756) BT_SMP: smp_build_rand_cmd

D (54766) BT_SMP: smp_send_msg_to_L2CAP
D (54766) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (54776) BT_SMP: smp_start_nonce_generation
D (54786) BT_SMP: smp_process_peer_nonce end

D (54786) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (54796) BT_SMP: smp_rand_back state=0xd
D (54796) BT_SMP: smp_finish_nonce_generation
D (54806) BT_SMP: smp_rand_back state=0xe
D (54806) BT_SMP: smp_process_new_nonce round 17
D (54806) BT_SMP: main smp_sm_event

D (54816) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (54826) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (54836) BT_SMP: smp_process_local_nonce

D (54836) BT_SMP: smp_calculate_local_commitment

D (54846) BT_SMP: random: 0x01, round: 17, i: 2, j: 1

D (54846) BT_SMP: smp_calculate_random_input ri=0x80

D (54856) BT_SMP: smp_calculate_f4
D (54856) BT_SMP: aes_cipher_msg_auth_code
D (54856) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (54866) BT_SMP:  cmac_generate_subkey
D (54866) BT_SMP: smp_encrypt_data

D (54876) BT_SMP: cmac_subkey_cont
D (54876) BT_SMP: leftshift_onebit
D (54876) BT_SMP: leftshift_onebit
D (54886) BT_SMP: smp_xor_128

D (54886) BT_SMP: cmac_prepare_last_block
D (54896) BT_SMP: flag = 0 round = 5
D (54896) BT_SMP: smp_xor_128

D (54896) BT_SMP: cmac_aes_k_calculate
D (54906) BT_SMP: smp_xor_128

D (54906) BT_SMP: smp_encrypt_data

D (54906) BT_SMP: smp_xor_128

D (54916) BT_SMP: smp_encrypt_data

D (54916) BT_SMP: smp_xor_128

D (54916) BT_SMP: smp_encrypt_data

D (54926) BT_SMP: smp_xor_128

D (54926) BT_SMP: smp_encrypt_data

D (54926) BT_SMP: smp_xor_128

D (54936) BT_SMP: smp_encrypt_data

D (54936) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (54946) BT_SMP: p_mac[0] = 0x10 p_mac[1] = 0x06 p_mac[2] = 0xd1 p_mac[3] = 0x19
D (54946) BT_SMP: p_mac[4] = 0x4f p_mac[5] = 0x46 p_mac[6] = 0xce p_mac[7] = 0x8d
D (54956) BT_SMP: local commitment calculation is completed
D (54966) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (54966) BT_SMP:
SMDBG l2c smp_data_received

D (54976) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (54986) BT_SMP: main smp_sm_event

D (54986) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (54996) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (55006) BT_SMP: smp_process_pairing_commitment
D (55006) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (55016) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (55026) BT_SMP: smp_send_commitment
D (55026) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (55026) BT_SMP: smp_build_pairing_commitment_cmd

D (55036) BT_SMP: smp_send_msg_to_L2CAP
D (55036) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (55126) BT_SMP:
SMDBG l2c smp_data_received

D (55126) BT_SMP: main smp_sm_event

D (55126) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (55136) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (55136) BT_SMP: smp_proc_rand

D (55146) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (55146) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (55156) BT_SMP: smp_process_peer_nonce start

D (55166) BT_SMP: smp_check_commitment

D (55166) BT_SMP: smp_calculate_peer_commitment
D (55166) BT_SMP: random: 0x01, round: 17, i: 2, j: 1

D (55176) BT_SMP: smp_calculate_random_input ri=0x80

D (55186) BT_SMP: smp_calculate_f4
D (55186) BT_SMP: aes_cipher_msg_auth_code
D (55186) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (55196) BT_SMP:  cmac_generate_subkey
D (55196) BT_SMP: smp_encrypt_data

D (55206) BT_SMP: cmac_subkey_cont
D (55206) BT_SMP: leftshift_onebit
D (55206) BT_SMP: leftshift_onebit
D (55216) BT_SMP: cmac_prepare_last_block
D (55216) BT_SMP: flag = 0 round = 5
D (55216) BT_SMP: smp_xor_128

D (55226) BT_SMP: cmac_aes_k_calculate
D (55226) BT_SMP: smp_xor_128

D (55236) BT_SMP: smp_encrypt_data

D (55236) BT_SMP: smp_xor_128

D (55236) BT_SMP: smp_encrypt_data

D (55246) BT_SMP: smp_xor_128

D (55246) BT_SMP: smp_encrypt_data

D (55246) BT_SMP: smp_xor_128

D (55256) BT_SMP: smp_encrypt_data

D (55256) BT_SMP: smp_xor_128

D (55256) BT_SMP: smp_encrypt_data

D (55266) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (55266) BT_SMP: p_mac[0] = 0x03 p_mac[1] = 0xb7 p_mac[2] = 0xd5 p_mac[3] = 0xc9
D (55276) BT_SMP: p_mac[4] = 0x34 p_mac[5] = 0xc2 p_mac[6] = 0x3d p_mac[7] = 0xa0
D (55286) BT_SMP: peer commitment calculation is completed

D (55286) BT_SMP: Commitment check succeeds

D (55296) BT_SMP: smp_send_rand

D (55296) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (55296) BT_SMP: smp_build_rand_cmd

D (55306) BT_SMP: smp_send_msg_to_L2CAP
D (55306) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (55316) BT_SMP: smp_start_nonce_generation
D (55326) BT_SMP: smp_process_peer_nonce end

D (55326) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (55336) BT_SMP: smp_rand_back state=0xd
D (55336) BT_SMP: smp_finish_nonce_generation
D (55346) BT_SMP: smp_rand_back state=0xe
D (55346) BT_SMP: smp_process_new_nonce round 18
D (55346) BT_SMP: main smp_sm_event

D (55356) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (55366) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (55376) BT_SMP: smp_process_local_nonce

D (55376) BT_SMP: smp_calculate_local_commitment

D (55386) BT_SMP: random: 0x01, round: 18, i: 2, j: 2

D (55386) BT_SMP: smp_calculate_random_input ri=0x80

D (55396) BT_SMP: smp_calculate_f4
D (55396) BT_SMP: aes_cipher_msg_auth_code
D (55396) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (55406) BT_SMP:  cmac_generate_subkey
D (55406) BT_SMP: smp_encrypt_data

D (55416) BT_SMP: cmac_subkey_cont
D (55416) BT_SMP: leftshift_onebit
D (55416) BT_SMP: smp_xor_128

D (55426) BT_SMP: leftshift_onebit
D (55426) BT_SMP: cmac_prepare_last_block
D (55436) BT_SMP: flag = 0 round = 5
D (55436) BT_SMP: smp_xor_128

D (55436) BT_SMP: cmac_aes_k_calculate
D (55446) BT_SMP: smp_xor_128

D (55446) BT_SMP: smp_encrypt_data

D (55446) BT_SMP: smp_xor_128

D (55456) BT_SMP: smp_encrypt_data

D (55456) BT_SMP: smp_xor_128

D (55456) BT_SMP: smp_encrypt_data

D (55466) BT_SMP: smp_xor_128

D (55466) BT_SMP: smp_encrypt_data

D (55466) BT_SMP: smp_xor_128

D (55476) BT_SMP: smp_encrypt_data

D (55476) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (55486) BT_SMP: p_mac[0] = 0x27 p_mac[1] = 0x92 p_mac[2] = 0x96 p_mac[3] = 0x87
D (55486) BT_SMP: p_mac[4] = 0x01 p_mac[5] = 0x72 p_mac[6] = 0x5e p_mac[7] = 0x42
D (55496) BT_SMP: local commitment calculation is completed
D (55506) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (55506) BT_SMP:
SMDBG l2c smp_data_received

D (55516) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (55526) BT_SMP: main smp_sm_event

D (55526) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (55536) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (55546) BT_SMP: smp_process_pairing_commitment
D (55546) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (55556) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (55566) BT_SMP: smp_send_commitment
D (55566) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (55566) BT_SMP: smp_build_pairing_commitment_cmd

D (55576) BT_SMP: smp_send_msg_to_L2CAP
D (55576) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (55756) BT_SMP:
SMDBG l2c smp_data_received

D (55756) BT_SMP: main smp_sm_event

D (55756) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (55766) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (55766) BT_SMP: smp_proc_rand

D (55776) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (55776) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (55786) BT_SMP: smp_process_peer_nonce start

D (55796) BT_SMP: smp_check_commitment

D (55796) BT_SMP: smp_calculate_peer_commitment
D (55796) BT_SMP: random: 0x01, round: 18, i: 2, j: 2

D (55806) BT_SMP: smp_calculate_random_input ri=0x80

D (55816) BT_SMP: smp_calculate_f4
D (55816) BT_SMP: aes_cipher_msg_auth_code
D (55816) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (55826) BT_SMP:  cmac_generate_subkey
D (55826) BT_SMP: smp_encrypt_data

D (55836) BT_SMP: cmac_subkey_cont
D (55836) BT_SMP: leftshift_onebit
D (55836) BT_SMP: smp_xor_128

D (55846) BT_SMP: leftshift_onebit
D (55846) BT_SMP: cmac_prepare_last_block
D (55846) BT_SMP: flag = 0 round = 5
D (55856) BT_SMP: smp_xor_128

D (55856) BT_SMP: cmac_aes_k_calculate
D (55866) BT_SMP: smp_xor_128

D (55866) BT_SMP: smp_encrypt_data

D (55866) BT_SMP: smp_xor_128

D (55876) BT_SMP: smp_encrypt_data

D (55876) BT_SMP: smp_xor_128

D (55876) BT_SMP: smp_encrypt_data

D (55886) BT_SMP: smp_xor_128

D (55886) BT_SMP: smp_encrypt_data

D (55886) BT_SMP: smp_xor_128

D (55896) BT_SMP: smp_encrypt_data

D (55896) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (55896) BT_SMP: p_mac[0] = 0x05 p_mac[1] = 0xf2 p_mac[2] = 0xb1 p_mac[3] = 0x8d
D (55906) BT_SMP: p_mac[4] = 0x6a p_mac[5] = 0x9e p_mac[6] = 0xf5 p_mac[7] = 0x7e
D (55916) BT_SMP: peer commitment calculation is completed

D (55916) BT_SMP: Commitment check succeeds

D (55926) BT_SMP: smp_send_rand

D (55926) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (55936) BT_SMP: smp_build_rand_cmd

D (55936) BT_SMP: smp_send_msg_to_L2CAP
D (55946) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_SEC_CONN_PHS1_START(8)
D (55946) BT_SMP: smp_start_nonce_generation
D (55956) BT_SMP: smp_process_peer_nonce end

D (55956) BT_SMP: result state = SMP_STATE_SEC_CONN_PHS1_START

D (55966) BT_SMP: smp_rand_back state=0xd
D (55966) BT_SMP: smp_finish_nonce_generation
D (55976) BT_SMP: smp_rand_back state=0xe
D (55976) BT_SMP: smp_process_new_nonce round 19
D (55986) BT_SMP: main smp_sm_event

D (55986) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS1_START (8)], Event: [HAVE_LOCAL_NONCE_EVT (31)]
D (55996) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS1_START(8) ==> SMP_STATE_WAIT_COMMITMENT(9)
D (56006) BT_SMP: smp_process_local_nonce

D (56006) BT_SMP: smp_calculate_local_commitment

D (56016) BT_SMP: random: 0x01, round: 19, i: 2, j: 3

D (56016) BT_SMP: smp_calculate_random_input ri=0x80

D (56026) BT_SMP: smp_calculate_f4
D (56026) BT_SMP: aes_cipher_msg_auth_code
D (56036) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (56036) BT_SMP:  cmac_generate_subkey
D (56046) BT_SMP: smp_encrypt_data

D (56046) BT_SMP: cmac_subkey_cont
D (56046) BT_SMP: leftshift_onebit
D (56056) BT_SMP: smp_xor_128

D (56056) BT_SMP: leftshift_onebit
D (56056) BT_SMP: smp_xor_128

D (56066) BT_SMP: cmac_prepare_last_block
D (56066) BT_SMP: flag = 0 round = 5
D (56076) BT_SMP: smp_xor_128

D (56076) BT_SMP: cmac_aes_k_calculate
D (56076) BT_SMP: smp_xor_128

D (56086) BT_SMP: smp_encrypt_data

D (56086) BT_SMP: smp_xor_128

D (56086) BT_SMP: smp_encrypt_data

D (56096) BT_SMP: smp_xor_128

D (56096) BT_SMP: smp_encrypt_data

D (56096) BT_SMP: smp_xor_128

D (56106) BT_SMP: smp_encrypt_data

D (56106) BT_SMP: smp_xor_128

D (56106) BT_SMP: smp_encrypt_data

D (56116) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (56116) BT_SMP: p_mac[0] = 0xcf p_mac[1] = 0x0c p_mac[2] = 0x52 p_mac[3] = 0x12
D (56126) BT_SMP: p_mac[4] = 0xbe p_mac[5] = 0xb3 p_mac[6] = 0x66 p_mac[7] = 0x6a
D (56136) BT_SMP: local commitment calculation is completed
D (56136) BT_SMP: result state = SMP_STATE_WAIT_COMMITMENT

D (56146) BT_SMP:
SMDBG l2c smp_data_received

D (56146) BT_SMP: in smp_data_received cmd = 0x03, peer_auth_req = 0x2d,loc_auth_req = 0x0d

D (56156) BT_SMP: main smp_sm_event

D (56166) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_COMMITMENT (9)], Event: [PAIR_COMMITMENT_EVT (15)]
D (56176) BT_SMP: State change: SMP_STATE_WAIT_COMMITMENT(9) ==> SMP_STATE_WAIT_NONCE(10)
D (56176) BT_SMP: smp_process_pairing_commitment
D (56186) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0f

D (56186) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0f

D (56196) BT_SMP: smp_send_commitment
D (56206) BT_SMP: smp_send_cmd on l2cap cmd_code=0xf

D (56206) BT_SMP: smp_build_pairing_commitment_cmd

D (56216) BT_SMP: smp_send_msg_to_L2CAP
D (56216) BT_SMP: result state = SMP_STATE_WAIT_NONCE

D (56336) BT_SMP:
SMDBG l2c smp_data_received

D (56346) BT_SMP: main smp_sm_event

D (56346) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_NONCE (10)], Event: [RAND_EVT (4)]
D (56346) BT_SMP: State change: SMP_STATE_WAIT_NONCE(10) ==> SMP_STATE_SEC_CONN_PHS2_START(11)
D (56356) BT_SMP: smp_proc_rand

D (56356) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x04

D (56366) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x04

D (56376) BT_SMP: smp_process_peer_nonce start

D (56376) BT_SMP: smp_check_commitment

D (56386) BT_SMP: smp_calculate_peer_commitment
D (56386) BT_SMP: random: 0x01, round: 19, i: 2, j: 3

D (56386) BT_SMP: smp_calculate_random_input ri=0x80

D (56396) BT_SMP: smp_calculate_f4
D (56396) BT_SMP: aes_cipher_msg_auth_code
D (56406) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (56406) BT_SMP:  cmac_generate_subkey
D (56416) BT_SMP: smp_encrypt_data

D (56416) BT_SMP: cmac_subkey_cont
D (56416) BT_SMP: leftshift_onebit
D (56426) BT_SMP: leftshift_onebit
D (56426) BT_SMP: cmac_prepare_last_block
D (56436) BT_SMP: flag = 0 round = 5
D (56436) BT_SMP: smp_xor_128

D (56436) BT_SMP: cmac_aes_k_calculate
D (56446) BT_SMP: smp_xor_128

D (56446) BT_SMP: smp_encrypt_data

D (56446) BT_SMP: smp_xor_128

D (56456) BT_SMP: smp_encrypt_data

D (56456) BT_SMP: smp_xor_128

D (56456) BT_SMP: smp_encrypt_data

D (56466) BT_SMP: smp_xor_128

D (56466) BT_SMP: smp_encrypt_data

D (56466) BT_SMP: smp_xor_128

D (56476) BT_SMP: smp_encrypt_data

D (56476) BT_SMP: tlen = 16 p_mac = 0x3ffcc624
D (56486) BT_SMP: p_mac[0] = 0x18 p_mac[1] = 0x50 p_mac[2] = 0x80 p_mac[3] = 0x19
D (56486) BT_SMP: p_mac[4] = 0x13 p_mac[5] = 0x17 p_mac[6] = 0xbb p_mac[7] = 0x2d
D (56496) BT_SMP: peer commitment calculation is completed

D (56506) BT_SMP: Commitment check succeeds

D (56506) BT_SMP: smp_send_rand

D (56506) BT_SMP: smp_send_cmd on l2cap cmd_code=0x4

D (56516) BT_SMP: smp_build_rand_cmd

D (56516) BT_SMP: smp_send_msg_to_L2CAP
D (56526) BT_SMP: main smp_sm_event

D (56526) BT_SMP: SMP Role: Slave State: [SMP_STATE_SEC_CONN_PHS2_START (11)], Event: [SEC_CONN_PHASE1_CMPLT_EVT (32)]
D (56536) BT_SMP: State change: SMP_STATE_SEC_CONN_PHS2_START(11) ==> SMP_STATE_WAIT_DHK_CHECK(12)
D (56546) BT_SMP: smp_calculate_local_dhkey_check
D (56556) BT_SMP: smp_calculate_f5_mackey_and_long_term_key

D (56556) BT_SMP: smp_collect_local_ble_address

D (56566) BT_SMP: smp_collect_peer_ble_address

D (56566) BT_SMP: smp_calculate_f5
D (56566) BT_SMP: smp_calculate_f5_key
D (56576) BT_SMP: aes_cipher_msg_auth_code
D (56576) BT_SMP: AES128_CMAC started, allocate buffer size = 32
D (56586) BT_SMP:  cmac_generate_subkey
D (56586) BT_SMP: smp_encrypt_data

D (56596) BT_SMP: cmac_subkey_cont
D (56596) BT_SMP: leftshift_onebit
D (56596) BT_SMP: smp_xor_128

D (56606) BT_SMP: leftshift_onebit
D (56606) BT_SMP: cmac_prepare_last_block
D (56606) BT_SMP: flag = 1 round = 2
D (56616) BT_SMP: smp_xor_128

D (56616) BT_SMP: cmac_aes_k_calculate
D (56616) BT_SMP: smp_xor_128

D (56626) BT_SMP: smp_encrypt_data

D (56626) BT_SMP: smp_xor_128

D (56626) BT_SMP: smp_encrypt_data

D (56636) BT_SMP: tlen = 16 p_mac = 0x3ffcc574
D (56636) BT_SMP: p_mac[0] = 0xff p_mac[1] = 0x19 p_mac[2] = 0xa0 p_mac[3] = 0xd0
D (56646) BT_SMP: p_mac[4] = 0xeb p_mac[5] = 0x6e p_mac[6] = 0x46 p_mac[7] = 0xe6
D (56656) BT_SMP: smp_calculate_f5_mackey_or_long_term_key
D (56656) BT_SMP: aes_cipher_msg_auth_code
D (56666) BT_SMP: AES128_CMAC started, allocate buffer size = 64
D (56666) BT_SMP:  cmac_generate_subkey
D (56676) BT_SMP: smp_encrypt_data

D (56676) BT_SMP: cmac_subkey_cont
D (56686) BT_SMP: leftshift_onebit
D (56686) BT_SMP: leftshift_onebit
D (56686) BT_SMP: cmac_prepare_last_block
D (56696) BT_SMP: flag = 0 round = 4
D (56696) BT_SMP: smp_xor_128

D (56696) BT_SMP: cmac_aes_k_calculate
D (56706) BT_SMP: smp_xor_128

D (56706) BT_SMP: smp_encrypt_data

D (56706) BT_SMP: smp_xor_128

D (56716) BT_SMP: smp_encrypt_data

D (56716) BT_SMP: smp_xor_128

D (56716) BT_SMP: smp_encrypt_data

D (56726) BT_SMP: smp_xor_128

D (56726) BT_SMP: smp_encrypt_data

D (56726) BT_SMP: tlen = 16 p_mac = 0x3ffcc554
D (56736) BT_SMP: p_mac[0] = 0xa9 p_mac[1] = 0x4a p_mac[2] = 0x77 p_mac[3] = 0xbc
D (56746) BT_SMP: p_mac[4] = 0xd5 p_mac[5] = 0xf4 p_mac[6] = 0x49 p_mac[7] = 0x2b
D (56746) BT_SMP: smp_calculate_f5_mackey_or_long_term_key
D (56756) BT_SMP: aes_cipher_msg_auth_code
D (56756) BT_SMP: AES128_CMAC started, allocate buffer size = 64
D (56766) BT_SMP:  cmac_generate_subkey
D (56766) BT_SMP: smp_encrypt_data

D (56776) BT_SMP: cmac_subkey_cont
D (56776) BT_SMP: leftshift_onebit
D (56776) BT_SMP: leftshift_onebit
D (56786) BT_SMP: cmac_prepare_last_block
D (56786) BT_SMP: flag = 0 round = 4
D (56796) BT_SMP: smp_xor_128

D (56796) BT_SMP: cmac_aes_k_calculate
D (56796) BT_SMP: smp_xor_128

D (56806) BT_SMP: smp_encrypt_data

D (56806) BT_SMP: smp_xor_128

D (56806) BT_SMP: smp_encrypt_data

D (56816) BT_SMP: smp_xor_128

D (56816) BT_SMP: smp_encrypt_data

D (56816) BT_SMP: smp_xor_128

D (56826) BT_SMP: smp_encrypt_data

D (56826) BT_SMP: tlen = 16 p_mac = 0x3ffcc554
D (56836) BT_SMP: p_mac[0] = 0x04 p_mac[1] = 0x97 p_mac[2] = 0x0c p_mac[3] = 0x08
D (56836) BT_SMP: p_mac[4] = 0x6a p_mac[5] = 0x61 p_mac[6] = 0x04 p_mac[7] = 0x83
D (56846) BT_SMP: smp_calculate_f5_mackey_and_long_term_key is completed

D (56856) BT_SMP: smp_collect_local_io_capabilities

D (56856) BT_SMP: smp_collect_local_ble_address

D (56866) BT_SMP: smp_collect_peer_ble_address

D (56866) BT_SMP: smp_calculate_f6
D (56876) BT_SMP: aes_cipher_msg_auth_code
D (56876) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (56886) BT_SMP:  cmac_generate_subkey
D (56886) BT_SMP: smp_encrypt_data

D (56886) BT_SMP: cmac_subkey_cont
D (56896) BT_SMP: leftshift_onebit
D (56896) BT_SMP: leftshift_onebit
D (56896) BT_SMP: cmac_prepare_last_block
D (56906) BT_SMP: flag = 0 round = 5
D (56906) BT_SMP: smp_xor_128

D (56906) BT_SMP: cmac_aes_k_calculate
D (56916) BT_SMP: smp_xor_128

D (56916) BT_SMP: smp_encrypt_data

D (56926) BT_SMP: smp_xor_128

D (56926) BT_SMP: smp_encrypt_data

D (56926) BT_SMP: smp_xor_128

D (56936) BT_SMP: smp_encrypt_data

D (56936) BT_SMP: smp_xor_128

D (56936) BT_SMP: smp_encrypt_data

D (56946) BT_SMP: smp_xor_128

D (56946) BT_SMP: smp_encrypt_data

D (56946) BT_SMP: tlen = 16 p_mac = 0x3ffcc5d4
D (56956) BT_SMP: p_mac[0] = 0xeb p_mac[1] = 0x3f p_mac[2] = 0x91 p_mac[3] = 0x8e
D (56956) BT_SMP: p_mac[4] = 0x55 p_mac[5] = 0x3d p_mac[6] = 0x16 p_mac[7] = 0x42
D (56966) BT_SMP: local DHKey check calculation is completed
D (56976) BT_SMP: smp_phase_2_dhkey_checks_are_present

D (56976) BT_SMP: result state = SMP_STATE_WAIT_DHK_CHECK

D (56986) BT_SMP: smp_process_peer_nonce end

D (56986) BT_SMP: result state = SMP_STATE_WAIT_DHK_CHECK

D (56996) BT_SMP:
SMDBG l2c smp_data_received

D (56996) BT_SMP: main smp_sm_event

D (57006) BT_SMP: SMP Role: Slave State: [SMP_STATE_WAIT_DHK_CHECK (12)], Event: [PAIR_DHKEY_CHECK_EVT (13)]
D (57016) BT_SMP: State change: SMP_STATE_WAIT_DHK_CHECK(12) ==> SMP_STATE_DHK_CHECK(13)
D (57026) BT_SMP: smp_process_dhkey_check
D (57026) BT_SMP: smp_command_has_invalid_parameters for cmd code 0x0d

D (57036) BT_SMP: smp_command_has_valid_fixed_length for cmd code 0x0d

D (57036) BT_SMP: smp_calculate_peer_dhkey_check
D (57046) BT_SMP: smp_collect_peer_io_capabilities

D (57046) BT_SMP: smp_collect_local_ble_address

D (57056) BT_SMP: smp_collect_peer_ble_address

D (57056) BT_SMP: smp_calculate_f6
D (57066) BT_SMP: aes_cipher_msg_auth_code
D (57066) BT_SMP: AES128_CMAC started, allocate buffer size = 80
D (57076) BT_SMP:  cmac_generate_subkey
D (57076) BT_SMP: smp_encrypt_data

D (57076) BT_SMP: cmac_subkey_cont
D (57086) BT_SMP: leftshift_onebit
D (57086) BT_SMP: leftshift_onebit
D (57086) BT_SMP: cmac_prepare_last_block
D (57096) BT_SMP: flag = 0 round = 5
D (57096) BT_SMP: smp_xor_128

D (57106) BT_SMP: cmac_aes_k_calculate
D (57106) BT_SMP: smp_xor_128

D (57106) BT_SMP: smp_encrypt_data

D (57116) BT_SMP: smp_xor_128

D (57116) BT_SMP: smp_encrypt_data

D (57116) BT_SMP: smp_xor_128

D (57126) BT_SMP: smp_encrypt_data

D (57126) BT_SMP: smp_xor_128

D (57126) BT_SMP: smp_encrypt_data

D (57136) BT_SMP: smp_xor_128

D (57136) BT_SMP: smp_encrypt_data

D (57136) BT_SMP: tlen = 16 p_mac = 0x3ffcc634
D (57146) BT_SMP: p_mac[0] = 0x8e p_mac[1] = 0x56 p_mac[2] = 0x64 p_mac[3] = 0xb1
D (57156) BT_SMP: p_mac[4] = 0xb3 p_mac[5] = 0xa6 p_mac[6] = 0x84 p_mac[7] = 0x23
D (57156) BT_SMP: peer DHKey check calculation is completed
D (57166) BT_SMP: main smp_sm_event

D (57166) BT_SMP: SMP Role: Slave State: [SMP_STATE_DHK_CHECK (13)], Event: [SEC_CONN_KEY_READY_EVT (37)]
D (57176) BT_SMP: State change: SMP_STATE_DHK_CHECK(13) ==> SMP_STATE_DHK_CHECK(13)
D (57186) BT_SMP: smp_match_dhkey_checks

D (57186) BT_SMP: dhkey checks match

D (57196) BT_SMP: main smp_sm_event

D (57196) BT_SMP: SMP Role: Slave State: [SMP_STATE_DHK_CHECK (13)], Event: [PAIR_DHKEY_CHECK_EVT (13)]
D (57206) BT_SMP: State change: SMP_STATE_DHK_CHECK(13) ==> SMP_STATE_ENCRYPTION_PENDING(14)
D (57216) BT_SMP: smp_send_dhkey_check
D (57216) BT_SMP: smp_send_cmd on l2cap cmd_code=0xd

D (57226) BT_SMP: smp_build_pair_dhkey_check_cmd

D (57226) BT_SMP: smp_send_msg_to_L2CAP
D (57236) BT_SMP: result state = SMP_STATE_ENCRYPTION_PENDING

D (57236) BT_SMP: result state = SMP_STATE_ENCRYPTION_PENDING

D (57246) BT_SMP: result state = SMP_STATE_ENCRYPTION_PENDING

D (57286) BT_SMP: smp_proc_ltk_request state = 14

D (57286) BT_SMP: main smp_sm_event

D (57286) BT_SMP: SMP Role: Slave State: [SMP_STATE_ENCRYPTION_PENDING (14)], Event: [ENC_REQ_EVT (24)]
D (57296) BT_SMP: State change: SMP_STATE_ENCRYPTION_PENDING(14) ==> SMP_STATE_ENCRYPTION_PENDING(14)
D (57306) BT_SMP: smp_generate_stk

W (57306) BT_SMP: FOR LE SC LTK IS USED INSTEAD OF STK
D (57316) BT_SMP: smp_process_stk
D (57316) BT_SMP: smp_mask_enc_key

D (57316) BT_SMP: main smp_sm_event

D (57326) BT_SMP: SMP Role: Slave State: [SMP_STATE_ENCRYPTION_PENDING (14)], Event: [KEY_READY_EVT (16)]
D (57336) BT_SMP: State change: SMP_STATE_ENCRYPTION_PENDING(14) ==> SMP_STATE_ENCRYPTION_PENDING(14)
D (57346) BT_SMP: smp_send_ltk_reply
D (57346) BT_SMP: result state = SMP_STATE_ENCRYPTION_PENDING

D (57346) BT_SMP: result state = SMP_STATE_ENCRYPTION_PENDING

D (57466) BT_SMP: smp_link_encrypted encr_enable=1

D (57466) BT_SMP: main smp_sm_event

D (57466) BT_SMP: SMP Role: Slave State: [SMP_STATE_ENCRYPTION_PENDING (14)], Event: [ENCRYPTED_EVT (17)]
D (57476) BT_SMP: State change: SMP_STATE_ENCRYPTION_PENDING(14) ==> SMP_STATE_ENCRYPTION_PENDING(14)
D (57486) BT_SMP: smp_check_auth_req rcvs enc_enable=1 i_keys=0x3 r_keys=0x3 (i-initiator r-responder)

D (57496) BT_SMP: smp_check_auth_req rcvs upgrades: i_keys=0x3 r_keys=0x3 (i-initiator r-responder)

D (57496) BT_SMP: main smp_sm_event

D (57506) BT_SMP: SMP Role: Slave State: [SMP_STATE_ENCRYPTION_PENDING (14)], Event: [BOND_REQ_EVT (25)]
D (57516) BT_SMP: State change: SMP_STATE_ENCRYPTION_PENDING(14) ==> SMP_STATE_BOND_PENDING(15)
D (57526) BT_SMP:
smp_key_distribution role=1 (0-master) r_keys=0x3 i_keys=0x3

D (57526) BT_SMP: smp_key_pick_key key_to_dist=0x3

D (57536) BT_SMP: key to send = 03, i = 0

D (57536) BT_SMP: smp_distribute_act[0]

D (57546) BT_SMP: smp_generate_ltk

D (57546) BT_SMP: smp_process_secure_connection_long_term_key

D (57556) BT_SMP: smp_save_secure_connections_long_term_key-Save LTK as local LTK key

D (57566) BT_SMP: smp_save_secure_connections_long_term_key-Save LTK as peer LTK key

D (57566) BT_SMP: smp_update_key_mask before update role=1 recv=0 local_i_key = 03, local_r_key = 03

D (57576) BT_SMP: updated local_i_key = 02, local_r_key = 02

D (57586) BT_SMP:
smp_key_distribution role=1 (0-master) r_keys=0x2 i_keys=0x2

D (57596) BT_SMP: smp_key_pick_key key_to_dist=0x2

D (57596) BT_SMP: key to send = 02, i = 0

D (57606) BT_SMP: key to send = 02, i = 1

D (57606) BT_SMP: smp_distribute_act[1]

D (57606) BT_SMP: smp_send_id_info

D (57616) BT_SMP: smp_update_key_mask before update role=1 recv=0 local_i_key = 02, local_r_key = 02

D (57626) BT_SMP: updated local_i_key = 02, local_r_key = 00

D (57626) BT_SMP: smp_send_cmd on l2cap cmd_code=0x8

D (57636) BT_SMP: smp_build_identity_info_cmd

D (57636) BT_SMP: smp_send_msg_to_L2CAP
D (57646) BT_SMP: smp_send_cmd on l2cap cmd_code=0x9

D (57646) BT_SMP: smp_build_id_addr_cmd

D (57656) BT_SMP: smp_send_msg_to_L2CAP
D (57656) BT_SMP: smp_key_distribution_by_transport

D (57656) BT_SMP:
smp_key_distribution role=1 (0-master) r_keys=0x0 i_keys=0x2

D (57666) BT_SMP: smp_key_pick_key key_to_dist=0x0

D (57676) BT_SMP: key to send = 00, i = 0

D (57676) BT_SMP: key to send = 00, i = 1

D (57686) BT_SMP: key to send = 00, i = 2

D (57686) BT_SMP: key to send = 00, i = 3

D (57686) BT_SMP: result state = SMP_STATE_BOND_PENDING

D (57696) BT_SMP: result state = SMP_STATE_BOND_PENDING

I (57706) SEC_GATTS_DEMO: key type = ESP_LE_KEY_LENC
I (57706) SEC_GATTS_DEMO: key type = ESP_LE_KEY_PENC
I (57716) SEC_GATTS_DEMO: key type = ESP_LE_KEY_LID
D (57736) BT_SMP:
SMDBG l2c smp_data_received

D (57736) BT_SMP: main smp_sm_event

D (57736) BT_SMP: SMP Role: Slave State: [SMP_STATE_BOND_PENDING (15)], Event: [ID_INFO_EVT (8)]
D (57746) BT_SMP: State change: SMP_STATE_BOND_PENDING(15) ==> SMP_STATE_BOND_PENDING(15)
D (57756) BT_SMP: smp_proc_id_info
D (57756) BT_SMP: smp_key_distribution_by_transport

D (57766) BT_SMP:
smp_key_distribution role=1 (0-master) r_keys=0x0 i_keys=0x2

D (57766) BT_SMP: smp_key_pick_key key_to_dist=0x0

D (57776) BT_SMP: key to send = 00, i = 0

D (57776) BT_SMP: key to send = 00, i = 1

D (57786) BT_SMP: key to send = 00, i = 2

D (57786) BT_SMP: key to send = 00, i = 3

D (57796) BT_SMP: result state = SMP_STATE_BOND_PENDING

D (57796) BT_SMP:
SMDBG l2c smp_data_received

D (57806) BT_SMP: main smp_sm_event

D (57806) BT_SMP: SMP Role: Slave State: [SMP_STATE_BOND_PENDING (15)], Event: [ID_ADDR_EVT (9)]
D (57816) BT_SMP: State change: SMP_STATE_BOND_PENDING(15) ==> SMP_STATE_BOND_PENDING(15)
D (57826) BT_SMP: smp_proc_id_addr
D (57826) BT_SMP: smp_update_key_mask before update role=1 recv=1 local_i_key = 02, local_r_key = 00

D (57836) BT_SMP: updated local_i_key = 00, local_r_key = 00

D (57846) BT_SMP: smp_key_distribution_by_transport

D (57846) BT_SMP:
smp_key_distribution role=1 (0-master) r_keys=0x0 i_keys=0x0

D (57856) BT_SMP: smp_key_pick_key key_to_dist=0x0

D (57856) BT_SMP: key to send = 00, i = 0

D (57866) BT_SMP: key to send = 00, i = 1

D (57866) BT_SMP: key to send = 00, i = 2

D (57876) BT_SMP: key to send = 00, i = 3

D (57876) BT_SMP: main smp_sm_event

D (57876) BT_SMP: SMP Role: Slave State: [SMP_STATE_BOND_PENDING (15)], Event: [AUTH_CMPL_EVT (23)]
D (57886) BT_SMP: State change: SMP_STATE_BOND_PENDING(15) ==> SMP_STATE_IDLE(0)
D (57896) BT_SMP: smp_send_pair_fail status=0 failure=0
D (57906) BT_SMP: smp_proc_pairing_cmpl

D (57906) BT_SMP: send SMP_COMPLT_EVT reason=0x0 sec_level=0x4

D (57916) BT_SMP: smp_reset_control_value

D (57916) BT_SMP: smp_remove_fixed_channel

D (57926) BT_SMP: smp_cb_cleanup

D (57926) BT_SMP: result state = SMP_STATE_IDLE

D (57926) BT_SMP: result state = SMP_STATE_IDLE

I (58036) SEC_GATTS_DEMO: key type = ESP_LE_KEY_PID
I (58036) SEC_GATTS_DEMO: remote BD_ADDR: 416d2dc5d8d1
I (58036) SEC_GATTS_DEMO: address type = 1
I (58036) SEC_GATTS_DEMO: pair status = success
I (58046) SEC_GATTS_DEMO: auth mode = ESP_LE_AUTH_REQ_SC_MITM_BOND
I (58056) SEC_GATTS_DEMO: Bonded devices number : 1

I (58056) SEC_GATTS_DEMO: Bonded devices list : 1

I (58066) SEC_GATTS_DEMO: 41 6d 2d c5 d8 d1

@xiewenxiang
Copy link
Collaborator

Hi @dragahassan

Does the actual application scenario is ESP32 display the passkey and the phone enters the passkey?
If so, it seems that the phone just used the previous 6 digits data.

Could you provide the model of the mobile phone? I want to test the phone if I can find it.

@hassandraga
Copy link
Contributor

@xiewenxiang I didn't find yet in SMP components where the peer device PIN, however I tested with LG G7 Android 10, Samsung A7, Asus tablet old Android maybe 7.

@ghost
Copy link
Author

ghost commented Aug 21, 2020

I just tested again with iPhone 11, Samsung S20+.. same results. with non modified gatt_security_server example, it's a bug and we need to figure out how to fix it in SMP components.

@ghost
Copy link
Author

ghost commented Aug 21, 2020

@xiewenxiang please make sure when testing you set the correct first digit, then add random numbers, like "123456111222".

@xiewenxiang
Copy link
Collaborator

@dragahassan

I am very very sorry that I cannot reproduce the question you mentioned. Maybe there are some differences between our operations

I use the gatt_security_server, A little bit of modification, esp_ble_io_cap_t iocap = ESP_IO_CAP_NONE => esp_ble_io_cap_t iocap = ESP_IO_CAP_OUT. I'm sure you made this change too, otherwise ESP32 won't display the key here.

I reproduce the scenario you mentioned with several phones(itouch & iphone 8). The pairing was not successful, but the connection was not be disconnected. The connection was still in the clear text transmission state.

Do you hope that the connection will break when the pairing fails?

@xiewenxiang
Copy link
Collaborator

图片

@xiewenxiang
Copy link
Collaborator

Screenshot from 2020-08-24 11-14-16

@xiewenxiang
Copy link
Collaborator

ESP32 display the key: 123456
I input: 123456112233 & 123456666666 & 123456123456
All of them pair fail.

@ghost
Copy link
Author

ghost commented Aug 24, 2020

Strange!, thank you for this check, maybe we have different kit or different SDK ?

I'm using:

  • Kit version: DevKitC: v4
  • Module or chip used: ESP32-WROOM-32D
  • IDF version: v4.2-dev-1905-g625bd5eb1
  • Build System: idf.py
  • Compiler version: xtensa-esp32-elf-gcc (crosstool-NG esp-2020r2) 8.2.0

@ghost
Copy link
Author

ghost commented Aug 24, 2020

I just test again with 2 other ESP32 but same kit version (ESP32-WROOM-32D) and Samsung S20+, pairing success.
probably this problem exit only on SDK v4.2-dev-XXXX.

@xiewenxiang
Copy link
Collaborator

I completely tested in accordance with the conditions you said, but still failed to reproduce, all of which were pair fail.

Could you provide the bin file you generated? I want to test your firmware directly.

The attachment is the bin I generated.

0x8000 partition_table/partition-table.bin 0x1000 bootloader/bootloader.bin 0x10000 sec_gatts_demo.bin

build.tar.gz

@ghost
Copy link
Author

ghost commented Aug 25, 2020

I test it with your bin file's, and it's success with 123456666666, I record a video (from virtualbox), I'm sure this security issue still exist, but I can't figure out yet the exact cause.

Windows_10_64-2020-08-25T12-44-25-927300900Z.zip

build.zip

If we use the same non modified example, and the same SDK version and compiler.. why we have different size ? my firmware bin file (sec_gatts_demo.bin) is 690K, while your's 704K ? I know enabling log and other stuff in menuconfig can increase the size, but we are okay that we use non modified example, except for enabling ESP_IO_CAP_OUT.

@Alvin1Zhang
Copy link
Collaborator

Thanks for reporting, feel free to reopen.

@Alvin1Zhang Alvin1Zhang added the Resolution: Cannot Reproduce Issue cannot be reproduced label Aug 23, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Resolution: Cannot Reproduce Issue cannot be reproduced
Projects
None yet
Development

No branches or pull requests

4 participants