We are trying to complete Bluetooth qualification on our Cycling Power Service (CPS) against the Bluetooth
Test Specification (Document Number CPS.TS.1.1.1).
We fail the test case:
CPS/SEN/SPE/BI-04-C [Procedure Already In Progress]
Verify that the IUT responds appropriately when a Client attempts to perform a Cycling Power Control Point procedure when a procedure is already in progress.
According to the test specification the IUT should return Application Error Code set to Procedure Already in Progress (0x80).
Although ble_gatt.h has the following definition
#define BLE_GATT_STATUS_ATTERR_CPS_PROC_ALR_IN_PROG 0x01FE /< ATT Common Profile and Service Error: Procedure Already in Progress. /*
The test harness accepts 0x01FE as the correct response but we still fail the test.
I have posted the test log below.
Test Case Started: CPS v. 6.6.0.47, TC_SPE_BI_04_C started on Thursday, September 15, 2016, 10:25:09
PICS VALUES:
TSPC_ALL FALSE
TSPC_CPS_0_1 TRUE
TSPC_CPS_0_2 FALSE
TSPC_CPS_0a_1 TRUE
TSPC_CPS_1_1 FALSE
TSPC_CPS_1_2 TRUE
TSPC_CPS_2_1 FALSE
TSPC_CPS_2_2 FALSE
TSPC_CPS_2_3 FALSE
TSPC_CPS_2_4 TRUE
TSPC_CPS_2_5 FALSE
TSPC_CPS_2_6 FALSE
TSPC_CPS_2_7 FALSE
TSPC_CPS_2_8 FALSE
TSPC_CPS_2_9 FALSE
TSPC_CPS_2_10 TRUE
TSPC_CPS_2_11 FALSE
TSPC_CPS_2_12 FALSE
TSPC_CPS_2_13 TRUE
TSPC_CPS_2_14 FALSE
TSPC_CPS_2_15 FALSE
TSPC_CPS_2_16 FALSE
TSPC_CPS_2_17 FALSE
TSPC_CPS_2_18 FALSE
TSPC_CPS_2_19 FALSE
TSPC_CPS_2_20 FALSE
TSPC_CPS_2_21 FALSE
TSPC_CPS_2_22 TRUE
TSPC_CPS_2_23 FALSE
TSPC_CPS_2_24 TRUE
TSPC_CPS_3_1 TRUE
TSPC_CPS_3_2 TRUE
TSPC_CPS_3_3 TRUE
TSPC_CPS_3_4 TRUE
TSPC_CPS_3_5 FALSE
TSPC_CPS_3_6 FALSE
TSPC_CPS_3_7 FALSE
TSPC_CPS_3_8 TRUE
TSPC_CPS_3_9 FALSE
TSPC_CPS_3_10 FALSE
TSPC_CPS_3_11 FALSE
TSPC_CPS_3_12 FALSE
TSPC_CPS_3_13 FALSE
TSPC_CPS_3_14 FALSE
TSPC_CPS_3_15 FALSE
TSPC_CPS_3_16 TRUE
TSPC_CPS_3_17 TRUE
TSPC_CPS_3_18 FALSE
TSPC_CPS_3_19 FALSE
TSPC_CPS_3_20 FALSE
TSPC_CPS_3_21 FALSE
TSPC_CPS_3_22 TRUE
TSPC_CPS_3_23 TRUE
TSPC_CPS_3_24 FALSE
TSPC_CPS_3_25 FALSE
TSPC_CPS_3_26 FALSE
TSPC_CPS_3_27 FALSE
TSPC_CPS_3_28 FALSE
TSPC_CPS_3_29 FALSE
TSPC_CPS_3_30 TRUE
TSPC_CPS_3_31 FALSE
TSPC_CPS_3_32 FALSE
TSPC_CPS_3_33 FALSE
TSPC_CPS_3_34 FALSE
TSPC_CPS_3_35 FALSE
TSPC_CPS_3_36 FALSE
TSPC_CPS_3_37 FALSE
TSPC_CPS_3_38 FALSE
TSPC_CPS_3_39 FALSE
TSPC_CPS_4_1 FALSE
TSPC_CPS_4_2 FALSE
TSPC_CPS_4_3 FALSE
TSPC_CPS_4_4 FALSE
TSPC_CPS_4_5 FALSE
TSPC_CPS_4_6 FALSE
TSPC_CPS_5_1 FALSE
TSPC_CPS_5_2 FALSE
TSPC_CPS_5_3 FALSE
PIXIT VALUES:
TSPX_bd_addr_iut D5B20C574BE5
TSPX_time_guard 180000
TSPX_use_implicit_send TRUE
TSPX_tester_database_file C:\Program Files\Bluetooth SIG\Bluetooth PTS\Data\SIGDatabase\PTS_CPP_db.xml
TSPX_mtu_size 23
TSPX_secure_simple_pairing_pass_key_confirmation FALSE
TSPX_delete_link_key FALSE
TSPX_pin_code 0000
TSPX_use_dynamic_pin FALSE
TSPX_delete_ltk FALSE
TSPX_security_enabled FALSE
TSPX_iut_setup_att_over_br_edr FALSE
TSPX_run_as_tester2 FALSE
TSPX_iut_slowest_connection_interval_vector_notification 50
TSPX_tester_appearance 0000
TSPX_iut_use_resolvable_random_address FALSE
+577 ms
Initialize Test Case: Build date: Jul 8 2016, 16:23:12
+577 ms
Start Test Case: TC_SPE_BI_04_C
+577 ms
Message: PTS Log started on Thursday, September 15, 2016, 10:25:10
+577 ms
Message: PTS: v6.6.0 Build 47
+577 ms
Message: OS: Microsoft Windows NT 6.1.7601 Service Pack 1
+577 ms
Message: OS Name: Microsoft Windows 7 Professional
+4587 ms
Preliminary Verdict: PASS
+4649 ms
Send Event: HCI!HCI_RESET
+4774 ms
Receive Event: HCI?HCI_RESET_COMPLETE_EVENT{
status=HCI_OK
}
+4774 ms
Preliminary Verdict: PASS
+4774 ms
Send Event: HCI!HCI_SET_EVENT_MASK{
eventMask=0x3FFFFFFFFFFFFFFF
}
+4774 ms
Receive Event: HCI?HCI_SET_EVENT_MASK_COMPLETE_EVENT{
status=HCI_OK
}
+4774 ms
Preliminary Verdict: PASS
+4774 ms
Send Event: HCI!HCI_READ_LOCAL_VERSION_INFORMATION
+4774 ms
Receive Event: HCI?HCI_READ_LOCAL_VERSION_INFORMATION_COMPLETE_EVENT{
status=HCI_OK,
hciVersion=HCI_VERSION_4_0,
hciRevision=0x2031,
lmpVersion=0x06,
manufacturerName=0x000A,
lmpSubversion=0x2031
}
+4774 ms
Preliminary Verdict: PASS
+4774 ms
Send Event: HCI!HCI_READ_BD_ADDR
+4774 ms
Receive Event: HCI?HCI_READ_BD_ADDR_COMPLETE_EVENT{
status=HCI_OK,
bdAddress=0x001BDC080F92
}
+4774 ms
Preliminary Verdict: PASS
+4774 ms
Send Event: HCI!HCI_LE_SET_EVENT_MASK{
leEventMask=0x000000000000001F
}
+4774 ms
Receive Event: HCI?HCI_LE_SET_EVENT_MASK_COMPLETE_EVENT{
status=HCI_OK
}
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Send Event: HCI!HCI_WRITE_LE_HOST_SUPPORTED{
leSupportedHost=HCI_LE_SUPPORTED_HOST_ENABLED,
simultaneousLeHost=HCI_SIMULTANEOUS_LE_HOST_ENABLED
}
+4789 ms
Receive Event: HCI?HCI_WRITE_LE_HOST_SUPPORTED_COMPLETE_EVENT{
status=HCI_OK
}
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Send Event: HCI!HCI_LE_CLEAR_WHITE_LIST
+4789 ms
Receive Event: HCI?HCI_LE_CLEAR_WHITE_LIST_COMPLETE_EVENT{
status=HCI_OK
}
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Send Event: HCI!HCI_WRITE_SIMPLE_PAIRING_MODE{
simplePairingMode=HCI_SIMPLE_PAIRING_ENABLED
}
+4789 ms
Receive Event: HCI?HCI_WRITE_SIMPLE_PAIRING_MODE_COMPLETE_EVENT{
status=HCI_OK
}
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Send Event: HCI!HCI_LE_ADD_DEVICE_TO_WHITE_LIST{
addressType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
address=0xD5B20C574BE5
}
+4789 ms
Receive Event: HCI?HCI_LE_ADD_DEVICE_TO_WHITE_LIST_COMPLETE_EVENT{
status=HCI_OK
}
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Send Event: HCI!HCI_LE_ADD_DEVICE_TO_WHITE_LIST{
addressType=HCI_LE_RANDOM_DEVICE_ADDRESS,
address=0xD5B20C574BE5
}
+4789 ms
Receive Event: HCI?HCI_LE_ADD_DEVICE_TO_WHITE_LIST_COMPLETE_EVENT{
status=HCI_OK
}
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Preliminary Verdict: PASS
+4789 ms
Send Event: HCI!HCI_LE_SET_SCAN_PARAMETERS{
leScanType=HCI_LE_ACTIVE_SCANNING,
leScanInterval=0x001E,
leScanWindow=0x001E,
ownAddressType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
scanningFilterPolicy=HCI_LE_ACCEPT_WHITE_LIST_ADVERTISING_PACKETS
}
+4805 ms
Receive Event: HCI?HCI_LE_SET_SCAN_PARAMETERS_COMPLETE_EVENT{
status=HCI_OK
}
+4805 ms
Preliminary Verdict: PASS
+4805 ms
Send Event: HCI!HCI_LE_SET_SCAN_ENABLE{
leScanEnable=HCI_LE_SCAN_ENABLE,
filterDuplicates=HCI_LE_DUPLICATE_FILTERING_DISABLE
}
+4805 ms
Preliminary Verdict: PASS
+4852 ms
Preliminary Verdict: PASS
+4852 ms
Send Event: HCI!HCI_LE_SET_SCAN_ENABLE{
leScanEnable=HCI_LE_SCAN_DISABLE,
filterDuplicates=HCI_LE_DUPLICATE_FILTERING_DISABLE
}
+4867 ms
Preliminary Verdict: PASS
+4867 ms
Preliminary Verdict: PASS
+4867 ms
Send Event: ATT!ATT_CONNECT_REQ{
peerAddr=0xD5B20C574BE5,
peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
ownAddrType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
minInterval=0x0032,
maxInterval=0x0046,
latency=0x0000
}
+5242 ms
Receive Event: SEC?SEC_LE_REMOTE_CSRK_REQUEST_REQ{
peerAddr=0xD5B20C574BE5,
peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS
}
+5257 ms
Receive Event: ATT?ATT_CONNECT_RSP{
bdAddr=0xD5B20C574BE5,
peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
lcid=0x0040,
status=HCI_OK
}
+5257 ms
Receive Event: HCI?HCI_LE_CONNECTION_COMPLETE_EVENT{
status=HCI_OK,
connectionHandle=0x004D,
role=HCI_ROLE_MASTER,
peerAddressType=HCI_LE_RANDOM_DEVICE_ADDRESS,
peerAddress=D5B20C574BE5,
connInterval=0x0046,
connLatency=0x0000,
supervisionTimeout=0x07D0,
clockAccuracy=HCI_LE_CLOCK_ACCURACY_500PPM
}
+5257 ms
Send Event: SEC!SEC_LE_REMOTE_CSRK_REQUEST_RSP{
peerAddr=0xD5B20C574BE5,
peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
accept=FALSE,
keyType=HCI_UNAUTHENTICATED_COMBINATION_KEY,
csrk=0x00000000000000000000000000000000,
signCounter=0x00000000
}
+5257 ms
Preliminary Verdict: PASS
+5257 ms
Verdict Description: Connection setup successfully.
+5257 ms
Inconclusive: Tester successfully initiated connection.
+5257 ms
Verdict Description: Tester successfully initiated connection.
+5257 ms
Verdict Description: LE Security not initiated due to TSPX_security_enabled value.
+5257 ms
Send Event: ATT!ATT_FIND_BY_TYPE_VALUE_REQ{
lcid=0x0040,
startingHandle=0x0001,
endingHandle=0xFFFF,
attributeType=0x2800,
length=0x0002,
PrimaryService=0x1818
}
+5413 ms
Receive Event: ATT?ATT_FIND_BY_TYPE_VALUE_RSP{
lcid=0x0040,
HandleRange={
{
foundAttributeHandle=0x000C,
endFoundHandle=0x0016
}
}
}
+5585 ms
Receive Event: ATT?ATT_FIND_BY_TYPE_VALUE_CFM{
lcid=0040,
result=0x0100,
errorHandle=0x0000,
HandleRanges={
{
foundAttributeHandle=0x000C,
endFoundHandle=0x0016,
}
}
}
+5585 ms
Preliminary Verdict: PASS
+5585 ms
Verdict Description: Discover Primary Service by Service UUID Request completed successfully.
+5585 ms
Inconclusive: The IUT successfullly returned the UUID for Cycling Power
+5585 ms
Verdict Description: The IUT successfullly returned the UUID for Cycling Power
+5585 ms
Send Event: ATT!ATT_READ_BY_TYPE_REQ{
lcid=0x0040,
startingHandle=0x000C,
endingHandle=0x0016,
attributeTypeSize=0x02,
attributeType=0x2803
}
+5757 ms
Receive Event: ATT?ATT_READ_BY_TYPE_RSP{
{
handle=0x000D
value{
Properties=0x10,
Handle=0x000E,
UUID=0x2A63
}
}
{
handle=0x0010
value{
Properties=0x02,
Handle=0x0011,
UUID=0x2A65
}
}
{
handle=0x0012
value{
Properties=0x02,
Handle=0x0013,
UUID=0x2A5D
}
}
}
+5928 ms
Receive Event: ATT?ATT_READ_BY_TYPE_RSP{
{
handle=0x0014
value{
Properties=0x28,
Handle=0x0015,
UUID=0x2A66
}
}
}
+6100 ms
Receive Event: ATT?ATT_READ_BY_TYPE_CFM{
lcid=0x0040,
attributeType=0x2803,
attributeTypeSize=0x02,
result=0x0100,
errorHandle=0x0000
}
+6115 ms
Receive Event: ATT?ATT_READ_BY_TYPE_CFM{
{
handle=0x000D
value{
Properties=0x10,
Handle=0x000E,
UUID=0x2A63
}
}
{
handle=0x0010
value{
Properties=0x02,
Handle=0x0011,
UUID=0x2A65
}
}
{
handle=0x0012
value{
Properties=0x02,
Handle=0x0013,
UUID=0x2A5D
}
}
{
handle=0x0014
value{
Properties=0x28,
Handle=0x0015,
UUID=0x2A66
}
}
}
+6115 ms
Preliminary Verdict: PASS
+6115 ms
Verdict Description: Discover All Characteristics of Service Request completed successfully.
+6115 ms
Send Event: ATT!ATT_FIND_INFO_REQ{
lcid=0x0040,
startingHandle=0x000F,
endingHandle=0x000F
}
+6287 ms
Receive Event: ATT?ATT_FIND_INFO_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+6287 ms
Receive Event: ATT?ATT_FIND_INFO_RSP{
{
handle=0x000F,
uuid=0x2902
}
}
+6287 ms
Receive Event: ATT?ATT_FIND_INFO_CFM{
{
handle=0x000F,
uuid=0x2902,
}
}
+6287 ms
Preliminary Verdict: PASS
+6287 ms
Verdict Description: Discover All Characteristic Descriptors Request completed successfully.
+6287 ms
Send Event: ATT!ATT_FIND_INFO_REQ{
lcid=0x0040,
startingHandle=0x0016,
endingHandle=0x0016
}
+6459 ms
Receive Event: ATT?ATT_FIND_INFO_RSP{
{
handle=0x0016,
uuid=0x2902
}
}
+6459 ms
Receive Event: ATT?ATT_FIND_INFO_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+6459 ms
Receive Event: ATT?ATT_FIND_INFO_CFM{
{
handle=0x0016,
uuid=0x2902,
}
}
+6459 ms
Preliminary Verdict: PASS
+6459 ms
Verdict Description: Discover All Characteristic Descriptors Request completed successfully.
+6490 ms
Send Event: ATT!ATT_WRITE_REQ{
lcid=0x0040,
attributeHandle=0x0016,
length=0x0002,
value{
Properties=0x0000
}
}
+6630 ms
Receive Event: ATT?ATT_WRITE_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+6630 ms
Preliminary Verdict: PASS
+6630 ms
Verdict Description: Write Request completed successfully.
+6630 ms
Send Event: ATT!ATT_WRITE_REQ{
lcid=0x0040,
attributeHandle=0x0016,
length=0x0002,
value{
Properties=0x0002
}
}
+6802 ms
Receive Event: ATT?ATT_WRITE_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+6802 ms
Preliminary Verdict: PASS
+6802 ms
Verdict Description: Write Request completed successfully.
+6817 ms
Send Event: ATT!ATT_WRITE_REQ{
lcid=0x0040,
attributeHandle=0x000F,
length=0x0002,
value{
Properties=0x0000
}
}
+6973 ms
Receive Event: ATT?ATT_WRITE_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+6973 ms
Preliminary Verdict: PASS
+6973 ms
Verdict Description: Write Request completed successfully.
+6989 ms
Send Event: ATT!ATT_WRITE_REQ{
lcid=0x0040,
attributeHandle=0x000F,
length=0x0002,
value{
Properties=0x0001
}
}
+7161 ms
Receive Event: ATT?ATT_WRITE_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+7161 ms
Preliminary Verdict: PASS
+7161 ms
Verdict Description: Write Request completed successfully.
+7161 ms
Send Event: ATT!ATT_READ_REQ{
lcid=0x0040,
attributeHandle=0x0011
}
+7332 ms
Receive Event: ATT?ATT_READ_CFM{
lcid=0x0040,
length=0x0004,
result=0x0100,
errorHandle=0x0000,
value{
CyclingPowerFeature=0x00001208
}
}
+7332 ms
Preliminary Verdict: PASS
+7332 ms
Verdict Description: Read Request completed successfully.
+7332 ms
Preliminary Verdict: PASS
+7332 ms
Inconclusive: The data received for 'Cycling Power Feature' conform to the schema
+7332 ms
Verdict Description: The data received for 'Cycling Power Feature' conform to the schema
+7348 ms
Send Event: ATT!ATT_WRITE_REQ{
lcid=0x0040,
attributeHandle=0x0015,
length=0x0001,
value{
OpCode=0x05
}
}
+7504 ms
Receive Event: ATT?ATT_WRITE_CFM{
lcid=0x0040,
result=0x0100,
errorHandle=0x0000
}
+7504 ms
Preliminary Verdict: PASS
+7504 ms
Verdict Description: Write Request completed successfully.
+7504 ms
Receive Event: ATT?ATT_HANDLE_VALUE_REQ{
lcid=0x0040,
attributeHandle=0x0015,
length=0x0005,
attributeValue=0x2A00AD010520
}
+7504 ms
Preliminary Verdict: PASS
+7504 ms
Inconclusive: The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.
+7504 ms
Verdict Description: The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.
+7504 ms
Send Event: ATT!ATT_WRITE_REQ{
lcid=0x0040,
attributeHandle=0x0015,
length=0x0001,
value{
OpCode=0x05
}
}
+7675 ms
Receive Event: ATT?ATT_WRITE_CFM{
lcid=0x0040,
result=0x00FE,
errorHandle=0x0015
}
+7675 ms
Preliminary Verdict: PASS
+7675 ms
Verdict Description: Write Request completed successfully.
+10998 ms
Receive Event: HCI?HCI_LE_CONNECTION_UPDATE_COMPLETE_EVENT{
status=HCI_OK,
connectionHandle=0x004D,
connInterval=0x00A0,
connLatency=0x0000,
supervisionTimeout=0x0190
}
+37518 ms
Receive Event: ATT?ATT_TRANSACTION_TIMEOUT_IND{
lcid=0x0040,
primitiveTimeout=0xA81C
}
+37518 ms
Preliminary Verdict: INCONC
+37518 ms
Pass: Non-passing verdict returned from APICOM, see log for more details.
+37518 ms
Verdict Description: Non-passing verdict returned from APICOM, see log for more details.
+38517 ms
Send Event: ATT!ATT_DISCONNECT_REQ{
lcid=0x0040
}
+38610 ms
Receive Event: ATT?ATT_DISCONNECT_RSP{
lcid=0x0040,
result=0x0000
}
+38610 ms
Receive Event: HCI?HCI_LE_DISCONNECTION_COMPLETE_EVENT{
status=HCI_OK,
connectionHandle=0x004D,
reason=HCI_CONNECTION_TERMINATED_BY_LOCAL_HOST
}
+38610 ms
Preliminary Verdict: PASS
+38610 ms
Verdict Description: Connection terminated successfully.
+40170 ms
Final Verdict: INCONC
+40170 ms
Encrypted Verdict: A1#Zjc3ZmVlOTAyMTMyNDc5NWUyZTZkZWVlYWVlN2FlNDIyZWFmNWVjMmU4Y2FhOTIyNDVhYjY0Mjg1MzlmYzhlMA==#zUSxWWkOSUQkGbqH49gaMdyRoY4kEXJRpFR34Vkm3w1FiUo+0y4o4DMTBJNt0MUr
+40170 ms
Test Case Ended: TC_SPE_BI_04_C
