search

zephyrproject-rtos / zephyr

Primary Git Repository for the Zephyr Project. Zephyr is a new generation, scalable, optimized, secure RTOS for multiple hardware architectures.
https://docs.zephyrproject.org
Apache License 2.0
10.51k stars 6.44k forks source link

[PTS] GAP/TC_BOND_BON_BV_01_C fails #3141

Closed zephyrbot closed 7 years ago

zephyrbot commented 7 years ago

Reported by Dawei Wu:

Test Env: Zephyr revision: master/033b5e9a7de8fa17abcd1f2fc4bd09f421383a34 PTS: 7.0 Host: Win10 64bit Enterprise , Dell Optiplex with Intel® Core i7-4770 @3.4GHZ, 8GB Memory BT USB dongle: CSR Please see attachment log for more info

(Imported from Jira ZEP-1688)

zephyrbot commented 7 years ago

by Dawei Wu:

zephyrbot commented 7 years ago

by Mariusz Skamra:

zephyrbot commented 7 years ago

by Dawei Wu:

zephyrbot commented 7 years ago

by Mariusz Skamra:

zephyrbot commented 7 years ago

by Dawei Wu:

zephyrbot commented 7 years ago

by Mariusz Skamra:

zephyrbot commented 7 years ago

by Mariusz Skamra:

Dawei Wu Please gather HCI traces (btmon), debug logs (iut-zephyr.log) and logs from PTS ProtocolViewer. I enclose my files as a reference [^GAP_TC_BOND_BON_BV_01_C.zip]

zephyrbot commented 7 years ago

by Mariusz Skamra:

Dawei Wu Please show me your PIXIT and ICS configuration as well.

zephyrbot commented 7 years ago

by Dawei Wu:

This case is not 100% failed, tried 3 times, 1 time passed. Here is the failed log attached.

zephyrbot commented 7 years ago

by Mariusz Skamra:

Dawei Wu Please attach your PIXIT and ICS values

zephyrbot commented 7 years ago

by Mariusz Skamra:

and traces from btmon.

On host machine (linux) run: sudo btmon -w filename.btsnoop and start the test

try to use a bluetooth Dongle to see if it's reproducible

zephyrbot commented 7 years ago

by Dawei Wu:

Mariusz Skamra , I tested all the PTS cases with real device Arduino101 ,so I need to upgrade Bluez to 5.40 or later(default is 5.37 on my Ubuntu 16.04) to use 'btmon --tty' for my understanding, but now I have some dependency issue to resolve on my host :( . See https://www.zephyrproject.org/doc/boards/x86/arduino_101/doc/board.html for more info to check how to build and run on Arduino 101.

zephyrbot commented 7 years ago

by Dawei Wu:

BTW, how can I check the PIXIT and ICS values ?

zephyrbot commented 7 years ago

by Mariusz Skamra:

I see in your logs that Test fails because LE Encryption fails to start. The status was "Connection Timeout".

I ran this test case 10 times on Arduino. 1/10 failed for me due to the same LE Encryption reason, but with different status "Unknown Connection Identifier"

Running this test case on n51 dongle 10/10 PASS

For me that is some problem in Controller on Arduino. There is no bug in Host neither in Test Automation.

I'll put this on hold now, because I want to test this with use of Sniffer, which I don't have now.

zephyrbot commented 7 years ago

by Mariusz Skamra:

Dawei Wu You can simply copy-paste the Logs from PTS console on windows

zephyrbot commented 7 years ago

by Mariusz Skamra:

Dawei Wu Please build with the current bluetooth branch. Updating both firmware and tester application helped for me. 10/10 PASS on Arduino 101

zephyrbot commented 7 years ago

by Dawei Wu:

Tried 6 times with bluetooth branch code, 1 time got PASS. Here is my PIXIT and ICS values.

PIXIT VALUES:
TSPX_bd_addr_iut 562F22928A95
TSPX_bd_addr_PTS C000DEADBEEF
TSPX_broadcaster_class_of_device 100104
TSPX_observer_class_of_device 100104
TSPX_peripheral_class_of_device 100104
TSPX_central_class_of_device 100104
TSPX_security_enabled FALSE
TSPX_delete_link_key TRUE
TSPX_pin_code 0000
TSPX_time_guard 300000
TSPX_use_implicit_send TRUE
TSPX_use_dynamic_pin FALSE
TSPX_secure_simple_pairing_pass_key_confirmation FALSE
TSPX_using_public_device_address FALSE
TSPX_using_random_device_address TRUE
TSPX_lim_adv_timeout 30720
TSPX_gen_disc_adv_min 30720
TSPX_lim_disc_scan_min 10240
TSPX_gen_disc_scan_min 10240
TSPX_database_file Database-GAP.sig
TSPX_iut_rx_mtu 23
TSPX_iut_private_address_interval 60000
TSPX_iut_privacy_enabled TRUE
TSPX_psm 1001
TSPX_iut_valid_connection_interval_min 00C8
TSPX_iut_valid_conneciton_interval_max 03C0
TSPX_iut_valid_connection_latency 0006
TSPX_iut_valid_timeout_multiplier 0962
TSPX_iut_connection_parameter_timeout 30000
TSPX_iut_invalid_connection_interval_min 0000
TSPX_iut_invalid_conneciton_interval_max 0000
TSPX_iut_invalid_connection_latency 0000
TSPX_iut_invalid_timeout_multiplier 0000
TSPX_LE_scan_interval 0010
TSPX_LE_scan_window 0010
TSPX_con_interval_min 0032
TSPX_con_interval_max 0046
TSPX_con_latency 0000
TSPX_supervision_timeout 07D0
TSPX_minimum_ce_length 0000
TSPX_maximum_ce_length 0000
TSPX_pairing_before_service_request FALSE
TSPX_iut_mandates_mitm FALSE
TSPX_encryption_before_service_request FALSE
TSPX_tester_appearance 0000
TSPX_iut_adverting_data_in_broadcasting_mode 0201060503180018010D095054532D4741502D3036423803190000
TSPX_iut_device_IRK_for_resolvable_privacy_address_generation_procedure 00000000000000000000000000000000
TSPX_tester_device_IRK_for_resolvable_privacy_address_generation_procedure 0123456789ABCDEF0123456789ABCDEF
TSPX_iut_device_name_in_adv_packet_for_random_address Tester
zephyrbot commented 7 years ago

by Mariusz Skamra:

Than you for PiXIT values. I see that those are the same as mine (except TSPX_bd_addr_iut of course). I tested this today and I cannot reproduce this locally. I ran this test in loop 96 times and always PASS...

OS: Client: Fedora 24 (4.8.16-200.fc24.x86_64) Server: Windows 7 Zephyr: bluetooth/b8b681ddf9548a2f24c627e9efbcff67503821a8 AutoPTS: master/be41e3fb57e14ea1038fef55d48701ffeb1e0c85 Workspace: zephyr-hci

Ruslan Mstoi Could you please check is this reproducible for you?

zephyrbot commented 7 years ago

by Ruslan Mstoi:

I was able to reproduce the failure. This test case failed once in ten times. Failure log:

PTS_LOGTYPE_EVENT_SUMMARY Event: MTC-FAIL: SEC_LE_ACCESS_CFM returned an error.

DUT: Arduino101 auto-pts: e462983 zephyr: v1.5.0-4623-gac70bdd1b (Bluetooth branch) workspace: zephyr-hci

zephyrbot commented 7 years ago

by Mariusz Skamra:

OK, I left this for the weekend running and finally I was able to reproduce this bug. I enclose HCI logs (btmon), debug logs from controller (RTT), debug logs from host, logs form auto-pts and Traces from PTS here: [^TC_BOND_BON_BV_03.zip]

My conclusion is that PTS failed to establish a connection with IUT after disconnection. PTS requests for Enabling advertising and IUT enables it (what is clearly seen in logs). Then PTS tries to connect (LE Create Connection), it gets Command Success from controller. Next, PTS initiates (important!) Pairing. It then gets Disconnection Complete event which means that the connection failed to established. And that is why this "MTC-FAIL: SEC_LE_ACCESS_CFM returned an error." is seen on PTS. On the HCI logs on IUT side, there is no even LE Connection Complete event.

Johan Hedberg Could you please look into logs to confirm?

For me it fails very rarely. Maybe you test in some noisy environment or the distance between IUT and PTS plays the role.

zephyrbot commented 7 years ago

by Mariusz Skamra:

Finally I managed to get sniffer. I enclose logs [^sniffer logs.zip] as you requested Johan Hedberg . Test iterated 28 times until first FAIL. In the frame "35100" (27 iter) we can see last CONNECT_IND from PTS. In the next iteration (28) IUT enables advertising (address 62:81:4b:6c:aa:e6). In frame 36444 there is first Scan Rsp from IUT. And it's keep on advertising. From the PTS logs we can see "MTC: Receive Advertising report successfully." so PTS received IUT advertising. And established connection "MTC: ATT connection established successfully" - LE Create Connection with Command Success. But the CONNECT_IND from PTS is not visible in sniffer traces. So my conclusion is that PTS controller could fail.

Unfortunately I ProtocolViewer failed to store the logs for me when BPA600 Sniffer was running. So I don't have logs from the same session.

zephyrbot commented 7 years ago

by vikram Shekhawat:

Closing this as cannot reproduce in current master/fef5ef74fa4abe2a7065b67663992630ed580455.