This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

CPS/SEN/SPE/BI-04-C [Procedure Already In Progress] inconc

Hello ,

The test of CPS/SEN/SPE/BI-04-C [Procedure Already In Progress]  failed. 

While this test, the tester sometimes received the unexpected ATT Disconnect which our product might send.

Could you tell me how to stop the ATT Disconnect?

The test-log

  +0 ms
  Initialize Test Case: Build date: Jul 18 2018, 09:31:58

  +0 ms
  Start Test Case: CPS/SEN/SPE/BI-04-C

  +0 ms
  Message: PTS Log started on Tuesday, October 02, 2018, 16:34:18

  +0 ms
  Message: PTS: v7.3.0 Build 40

  +0 ms
  Message: OS: Microsoft Windows NT 6.1.7601 Service Pack 1

  +0 ms
  Message: OS Name: Microsoft Windows 7 Home Premium

  +4009 ms
  Preliminary Verdict: PASS

  +4056 ms
  Send Event: HCI!HCI_RESET

  +4180 ms
  Receive Event: HCI?HCI_RESET_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4180 ms
  Preliminary Verdict: PASS

  +4180 ms
  Send Event: HCI!HCI_SET_EVENT_MASK{
  eventMask=0x3FFFFFFFFFFFFFFF
  }

  +4180 ms
  Receive Event: HCI?HCI_SET_EVENT_MASK_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4180 ms
  Preliminary Verdict: PASS

  +4180 ms
  Send Event: HCI!HCI_READ_LOCAL_VERSION_INFORMATION

  +4180 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
  } 

  +4180 ms
  Preliminary Verdict: PASS

  +4180 ms
  Send Event: HCI!HCI_READ_BD_ADDR

  +4196 ms
  Receive Event: HCI?HCI_READ_BD_ADDR_COMPLETE_EVENT{
  status=HCI_OK,
  bdAddress=0x001BDC0808A3
  }

  +4196 ms
  Preliminary Verdict: PASS

  +4196 ms
  Send Event: HCI!HCI_LE_SET_EVENT_MASK{
  leEventMask=0x000000000000001F
  }

  +4196 ms
  Receive Event: HCI?HCI_LE_SET_EVENT_MASK_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4196 ms
  Preliminary Verdict: PASS

  +4196 ms
  Send Event: HCI!HCI_WRITE_LE_HOST_SUPPORTED{
  leSupportedHost=HCI_LE_SUPPORTED_HOST_ENABLED,
  simultaneousLeHost=HCI_SIMULTANEOUS_LE_HOST_ENABLED
  }

  +4196 ms
  Receive Event: HCI?HCI_WRITE_LE_HOST_SUPPORTED_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4196 ms
  Preliminary Verdict: PASS

  +4196 ms
  Send Event: HCI!HCI_LE_CLEAR_WHITE_LIST

  +4196 ms
  Receive Event: HCI?HCI_LE_CLEAR_WHITE_LIST_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4196 ms
  Preliminary Verdict: PASS

  +4196 ms
  Send Event: HCI!HCI_WRITE_SIMPLE_PAIRING_MODE{
  simplePairingMode=HCI_SIMPLE_PAIRING_ENABLED
  }

  +4212 ms
  Receive Event: HCI?HCI_WRITE_SIMPLE_PAIRING_MODE_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4212 ms
  Preliminary Verdict: PASS

 +4212 ms
  Preliminary Verdict: PASS

  +4212 ms
  Send Event: HCI!HCI_LE_ADD_DEVICE_TO_WHITE_LIST{
  addressType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
  address=0xC58DCE70012F
  }

  +4212 ms
  Receive Event: HCI?HCI_LE_ADD_DEVICE_TO_WHITE_LIST_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4212 ms
  Preliminary Verdict: PASS

  +4212 ms
  Send Event: HCI!HCI_LE_ADD_DEVICE_TO_WHITE_LIST{
  addressType=HCI_LE_RANDOM_DEVICE_ADDRESS,
  address=0xC58DCE70012F
  }

  +4212 ms
  Receive Event: HCI?HCI_LE_ADD_DEVICE_TO_WHITE_LIST_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4212 ms
  Preliminary Verdict: PASS

  +4212 ms
  Preliminary Verdict: PASS

  +4212 ms
  Preliminary Verdict: PASS

  +4212 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
  }

  +4212 ms
  Receive Event: HCI?HCI_LE_SET_SCAN_PARAMETERS_COMPLETE_EVENT{
  status=HCI_OK
  }

  +4212 ms
  Preliminary Verdict: PASS

  +4227 ms
  Send Event: HCI!HCI_LE_SET_SCAN_ENABLE{
  leScanEnable=HCI_LE_SCAN_ENABLE,
  filterDuplicates=HCI_LE_DUPLICATE_FILTERING_DISABLE
  }

  +5506 ms
  Preliminary Verdict: PASS

  +5506 ms
  Preliminary Verdict: PASS

  +7519 ms
  Preliminary Verdict: PASS

  +7519 ms
  Preliminary Verdict: PASS

  +9516 ms
  Preliminary Verdict: PASS

  +9516 ms
  Send Event: HCI!HCI_LE_SET_SCAN_ENABLE{
  leScanEnable=HCI_LE_SCAN_DISABLE,
  filterDuplicates=HCI_LE_DUPLICATE_FILTERING_DISABLE
  }

  +9531 ms
  Preliminary Verdict: PASS

  +9562 ms
  Send Event: ATT!ATT_CONNECT_REQ{
  peerAddr=0xC58DCE70012F,
  peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
  ownAddrType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
  minInterval=0x0032,
  maxInterval=0x0046,
  latency=0x0000
  }

  +13556 ms
  Receive Event: SEC?SEC_LE_REMOTE_CSRK_REQUEST_REQ{
  peerAddr=0xC58DCE70012F,
  peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS
  }

  +13556 ms
  Receive Event: ATT?ATT_CONNECT_RSP{
  bdAddr=0xC58DCE70012F,
  peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
  lcid=0x0040,
  status=HCI_OK
  }

  +13556 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=C58DCE70012F,
  connInterval=0x0046,
  connLatency=0x0000,
  supervisionTimeout=0x07D0,
  clockAccuracy=HCI_LE_CLOCK_ACCURACY_500PPM
  }

  +13556 ms
  Send Event: SEC!SEC_LE_REMOTE_CSRK_REQUEST_RSP{
  peerAddr=0xC58DCE70012F,
  peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
  accept=FALSE,
  keyType=HCI_UNAUTHENTICATED_COMBINATION_KEY,
  csrk=0x00000000000000000000000000000000,
  signCounter=0x00000000
  }

  +13556 ms
  Preliminary Verdict: PASS

  +13556 ms
  Verdict Description: Connection setup successfully.

  +13556 ms
  Pass: Tester successfully initiated connection.

  +13556 ms
  Verdict Description: Tester successfully initiated connection.

  +13556 ms
  Verdict Description: LE Security not initiated due to TSPX_security_enabled value.

  +13556 ms
  Send Event: ATT!ATT_FIND_BY_TYPE_VALUE_REQ{
  lcid=0x0040,
  startingHandle=0x0001,
  endingHandle=0xFFFF,
  attributeType=0x2800,
  length=0x0002,
  PrimaryService=0x1818
  }

  +13681 ms
  Receive Event: ATT?ATT_FIND_BY_TYPE_VALUE_RSP{
  lcid=0x0040,
  HandleRange={
  {
  foundAttributeHandle=0x000F,
  endFoundHandle=0x0019
  }
  }
  } 

  +13852 ms
  Receive Event: ATT?ATT_FIND_BY_TYPE_VALUE_CFM{
  lcid=0040,
  result=0x0100,
  errorHandle=0x0000,
  HandleRanges={
  {
  foundAttributeHandle=0x000F,
  endFoundHandle=0x0019,
  }
  }
  }

  +13852 ms
  Preliminary Verdict: PASS

  +13852 ms
  Verdict Description: Discover Primary Service by Service UUID Request completed successfully.

  +13852 ms
  Pass: The IUT successfully returned the UUID for Cycling Power

  +13852 ms
  Verdict Description: The IUT successfully returned the UUID for Cycling Power

  +13852 ms
  Send Event: ATT!ATT_READ_BY_TYPE_REQ{
  lcid=0x0040,
  startingHandle=0x000F,
  endingHandle=0x0019,
  attributeTypeSize=0x02,
  attributeType=0x2803
  }

  +14024 ms
  Receive Event: ATT?ATT_READ_BY_TYPE_RSP{
  {
  handle=0x0010
  value{
  Properties=0x10,
  Handle=0x0011,
  UUID=0x2A63
  }
  }
  {
  handle=0x0013
  value{
  Properties=0x02,
  Handle=0x0014,
  UUID=0x2A65
  }
  }
  {
  handle=0x0015
  value{
  Properties=0x02,
  Handle=0x0016,
  UUID=0x2A5D
  }
  }
  }

  +14196 ms
  Receive Event: ATT?ATT_READ_BY_TYPE_RSP{
  {
  handle=0x0017
  value{
  Properties=0x28,
  Handle=0x0018,
  UUID=0x2A66
  }
  }
  }

  +14383 ms
  Receive Event: ATT?ATT_READ_BY_TYPE_CFM{
  lcid=0x0040,
  attributeType=0x2803,
  attributeTypeSize=0x02,
  result=0x0100,
  errorHandle=0x0000
  }

  +14383 ms
  Receive Event: ATT?ATT_READ_BY_TYPE_CFM{
  {
  handle=0x0010
  value{
  Properties=0x10,
  Handle=0x0011,
  UUID=0x2A63
  }
  }
  {
  handle=0x0013
  value{
  Properties=0x02,
  Handle=0x0014,
  UUID=0x2A65
  }
  }
  {
  handle=0x0015
  value{
  Properties=0x02,
  Handle=0x0016,
  UUID=0x2A5D
  }
  }
  {
  handle=0x0017
  value{
  Properties=0x28,
  Handle=0x0018,
  UUID=0x2A66
  }
  }
  }

  +14383 ms
  Preliminary Verdict: PASS

  +14383 ms
  Verdict Description: Discover All Characteristics of Service Request completed successfully.

  +14383 ms
  Send Event: ATT!ATT_FIND_INFO_REQ{
  lcid=0x0040,
  startingHandle=0x0012,
  endingHandle=0x0012
  }

  +14554 ms
  Receive Event: ATT?ATT_FIND_INFO_CFM{
  lcid=0x0040,
  result=0x0100,
  errorHandle=0x0000
  }

  +14554 ms
  Receive Event: ATT?ATT_FIND_INFO_RSP{
  {
  handle=0x0012,
  uuid=0x2902
  }
  }

  +14554 ms
  Receive Event: ATT?ATT_FIND_INFO_CFM{
  {
  handle=0x0012,
  uuid=0x2902,
  }
  }

  +14554 ms
  Preliminary Verdict: PASS

  +14554 ms
  Verdict Description: Discover All Characteristic Descriptors Request completed successfully.

  +14554 ms
  Send Event: ATT!ATT_FIND_INFO_REQ{
  lcid=0x0040,
  startingHandle=0x0019,
  endingHandle=0x0019
  }

  +14726 ms
  Receive Event: ATT?ATT_FIND_INFO_CFM{
  lcid=0x0040,
  result=0x0100,
  errorHandle=0x0000
  }

  +14726 ms
  Receive Event: ATT?ATT_FIND_INFO_RSP{
  {
  handle=0x0019,
  uuid=0x2902
  }
  }

  +14726 ms
  Receive Event: ATT?ATT_FIND_INFO_CFM{
  {
  handle=0x0019,
  uuid=0x2902,
  }
  }

  +14726 ms
  Preliminary Verdict: PASS

  +14726 ms
  Verdict Description: Discover All Characteristic Descriptors Request completed successfully.

  +14726 ms
  Send Event: ATT!ATT_WRITE_REQ{
  lcid=0x0040,
  attributeHandle=0x0019,
  length=0x0002,
  value{
  Properties=0x0000
  }
  } 

  +14991 ms
  Receive Event: ATT?ATT_WRITE_CFM{
  lcid=0x0040,
  result=0x0100,
  errorHandle=0x0000
  }

  +14991 ms
  Preliminary Verdict: PASS

  +17987 ms
  Send Event: ATT!ATT_WRITE_REQ{
  lcid=0x0040,
  attributeHandle=0x0019,
  length=0x0002,
  value{
  Properties=0x0002
  }
  }

  +18143 ms
  Receive Event: ATT?ATT_WRITE_CFM{
  lcid=0x0040,
  result=0x0100,
  errorHandle=0x0000
  }

  +18143 ms
  Preliminary Verdict: PASS

  +18143 ms
  Send Event: ATT!ATT_WRITE_REQ{
  lcid=0x0040,
  attributeHandle=0x0012,
  length=0x0002,
  value{
  Properties=0x0000
  }
  }

  +18314 ms
  Receive Event: ATT?ATT_WRITE_CFM{
  lcid=0x0040,
  result=0x0100,
  errorHandle=0x0000
  }

  +18314 ms
  Preliminary Verdict: PASS

  +21309 ms
  Send Event: ATT!ATT_WRITE_REQ{
  lcid=0x0040,
  attributeHandle=0x0012,
  length=0x0002,
  value{
  Properties=0x0001
  }
  }

  +21543 ms
  Receive Event: ATT?ATT_WRITE_CFM{
  lcid=0x0040,
  result=0x0100,
  errorHandle=0x0000
  }

  +21543 ms
  Preliminary Verdict: PASS

  +21559 ms
  Send Event: ATT!ATT_READ_REQ{
  lcid=0x0040,
  attributeHandle=0x0014
  }

  +21731 ms
  Receive Event: ATT?ATT_READ_CFM{
  lcid=0x0040,
  length=0x0004,
  result=0x0100,
  errorHandle=0x0000,
  value{
  CyclingPowerFeature=0x0019020A
  }
  }

  +21731 ms
  Preliminary Verdict: PASS

  +21731 ms
  Verdict Description: Read Request completed successfully. 

  +21731 ms
  Preliminary Verdict: PASS

  +21731 ms
  Pass: The data received for 'Cycling Power Feature' conforms to the schema

  +21731 ms
  Verdict Description: The data received for 'Cycling Power Feature' conforms to the schema

  +21777 ms
  Send Event: ATT!ATT_WRITE_REQ{
  lcid=0x0040,
  attributeHandle=0x0018,
  length=0x0001,
  value{  OpCode=0x0C,  CyclingPowerVectorControlValue=0x0063  }  }   +21902 ms  Receive Event: ATT?ATT_WRITE_CFM{  lcid=0x0040,  result=0x0100,  errorHandle=0x0000  }   +21902 ms  Preliminary Verdict: PASS   +22511 ms  Receive Event: ATT?ATT_HANDLE_VALUE_NOTIFICATION_REQ{  lcid=0x0040,  attributeHandle=0x0011,  length=0x000A,  attributeValue=0x00000000005B0000002C  }   +22511 ms  Receive Event: ATT?ATT_HANDLE_VALUE_IND{  lcid=0x0040,  attributeHandle=0x0018,  length=0x0005,  attributeValue=0x00FFFF010C20  }   +22511 ms  Preliminary Verdict: PASS   +22511 ms  Pass: The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.   +22511 ms  Verdict Description: The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.   +22511 ms  Send Event: ATT!ATT_WRITE_REQ{  lcid=0x0040,  attributeHandle=0x0018,  length=0x0001,  value{  OpCode=0x0C,  CyclingPowerVectorControlValue=0x006E  }  }   +22682 ms  Receive Event: ATT?ATT_WRITE_CFM{  lcid=0x0040,  result=0x0100,  errorHandle=0x0000
  }

  +22682 ms
  Preliminary Verdict: PASS

  +22682 ms
  Verdict Description: Write Request completed successfully.

  +43383 ms
  Receive Event: ATT?ATT_DISCONNECT_REQ{
  lcid=0x0040
  }

  +43383 ms
  Verdict Description: Unexpected ATT Disconnect received.

  +43383 ms
  Receive Event: HCI?HCI_LE_DISCONNECTION_COMPLETE_EVENT{
  status=HCI_OK,
  connectionHandle=0x004D,
  reason=HCI_CONNECTION_TIMEOUT
  }

  +43383 ms
  Verdict Description: Unexpected ATT Disconnect received.

  +43383 ms
  Inconclusive: Non-passing verdict returned from APICOM, see log for more details.

  +43383 ms
  Verdict Description: Non-passing verdict returned from APICOM, see log for more details.

  +45021 ms
  Final Verdict: INCONC

  +45021 ms
  Encrypted Verdict:
 A1#ZWY4MzQ5MDg3MmQwNTIxOGQzMzQ5YjY2ODA5M2MzNjQ5ZDY4NmY0Yjc2MzIzM2VkNTUyNTFhNGU4Mjg1MjI0NA==#S7tk81R4UBM+y2jy+jTqSwIFbmqou/dBe0rGBnSk5Rd1NLMNsmJ6x0apjF5t71xW 

  +45021 ms
  Test Case Ended: CPS/SEN/SPE/BI-04-C 

Best regards,

Kiyoshi Iwai

Parents
  • Could you provide a sniffer log of what happens between line 613 and 616 (Verdict Description and Receive Event)? The time span between these two event was quite long. Also, the HCI_CONNECTION_TIMEOUT might be due to a too low accuracy for the low frequency clock, check the value of NRF_SDH_CLOCK_LF_ACCURACY or what accuracy you have provided to sd_softdevice_enable(..).

  • Hello Simon,

    Thank you for reply.

    Unfortunately I don't have the log of 613-616. 

    As you said, it took long time between two event, because this test may be abnormal check.

    So could you tell me how to change the HCI_CONNECTION_TIMEOUT longer, or how to stop the ATT Disconnect Request?

    Best regards,

    Kiyoshi Iwai

  • Hi Kiyoshi,

    I have taken a look at this case and log, but difficult to understand what is failing here.

    The HCI_CONNECTION_TIMEOUT typically occurs if the link is lost (supervisor timeout should occurs after 20 seconds if there is no successful communication, from log: supervisionTimeout=0x07D0). However I am unsure why that is, it may be that there is an assert on the peripheral, then the peripheral will reset, and thereby the tester will wait for supervisor timeout before HCI_CONNECTION_TIMEOUT occurs.

    To find the cause here I believe you need the source code for the peripheral, compile the project and enable debugging, so you can find what is happening (assert, timeout, or disconnect). Another option to find cause would be to get an on-air sniffer log, for instance using ellisys, frontline or the nrf sniffer tool. 

    It might be useful to receive the sdk_config.h from your project, so we can take a look at the lfclk parameters.

    Looking at CPS/SEN/SPE/BI-04-C I can't seem to find step 3 either, which is "The Lower Tester sets to 0x0002 the Client Characteristic Configuration descriptor of the Cycling Power Control Point characteristic.". So a sniffer log would be very helpful here.

    I assume that the peripheral device doesn't support bonding here, since you have not enabled bonding (from log: LE Security not initiated due to TSPX_security_enabled value).

    Best regards,
    Kenneth

  • Hello Kenneth,

    Thank you for your polite reply.

    The Test-log does not describe all transaction, I think. 

    But I have to pass this test because of getting the certificate of bluetooth SIG.

    I will check whether receive the confirmation from the tester or not, and if I receive any requests

    without the confirmation, I will send the Error Code which described the step 7 a) in the test specification.

    Best regards,

    Kiyoshi Iwai

  • Hi Kiyoshi ,

    If you are able to provide an on-air sniffer log I think I will be able to find why link timeout and disconnect 20 seconds after:

      +21777 ms
      Send Event: ATT!ATT_WRITE_REQ{
      lcid=0x0040,
      attributeHandle=0x0018,
      length=0x0001,
      value{  OpCode=0x0C,  CyclingPowerVectorControlValue=0x0063  }  }   +21902 ms  Receive Event: ATT?ATT_WRITE_CFM{  lcid=0x0040,  result=0x0100,  errorHandle=0x0000  }   +21902 ms  Preliminary Verdict: PASS   +22511 ms  Receive Event: ATT?ATT_HANDLE_VALUE_NOTIFICATION_REQ{  lcid=0x0040,  attributeHandle=0x0011,  length=0x000A,  attributeValue=0x00000000005B0000002C  }   +22511 ms  Receive Event: ATT?ATT_HANDLE_VALUE_IND{  lcid=0x0040,  attributeHandle=0x0018,  length=0x0005,  attributeValue=0x00FFFF010C20  }   +22511 ms  Preliminary Verdict: PASS   +22511 ms  Pass: The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.   +22511 ms  Verdict Description: The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.   +22511 ms  Send Event: ATT!ATT_WRITE_REQ{  lcid=0x0040,  attributeHandle=0x0018,  length=0x0001,  value{  OpCode=0x0C,  CyclingPowerVectorControlValue=0x006E  }  }   +22682 ms  Receive Event: ATT?ATT_WRITE_CFM{  lcid=0x0040,  result=0x0100,  errorHandle=0x0000
      }

    Maybe you can send us your hardware and we can try to make a sniffer log here and I can ship it back afterwards.

    Best regards,
    Kenneth

  • Hello Kenneth,

    Thank you so much for your help.

    But the certification laboratory has the tester, we don't. So we could not take a sniffer log.

    I'm sorry.

    BTW, we got the PASS result of all BLE test at last night, we finished this problem.

    Thanks,

    Kiyoshi Iwai

  • Hello Kioshi,

    Can I ask you how did you solve this problem?

    Thanks,

    Marcin Kawalec

Reply Children
  • I have also problem with pass this test CPS/SEN/SPE/BI-04-C

    At the step 5 of this precedure, you can find that "the Lower Tester does not send any Confirmation to acknowledge this indication".

    After that IUT sent:

    +18236 ms
    Receive Event:           L2CAP?L2CAP_LE_CONNECTION_UPDATE_IND{
                               peerAddr=0xCC52D3B4B51F,
                               peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
                               minInterval=0x0014,
                               maxInterval=0x0028,
                               slaveLatency=0x0000,
                               supervision_timeout=0x01F4
                             }
    
    
    +18236 ms
    Send Event:              L2CAP!L2CA_LE_CONNECTION_UPDATE_RSP{
                               peerAddr=0xCC52D3B4B51F,
                               peerAddrType=0x01,
                               paramAccepted=1
                             }

    and next:

    +40544 ms
    Receive Event:           ATT?ATT_DISCONNECT_IND{
                               lcid=0x1205
                             }
    
    
    +40544 ms
    Receive Event:           HCI?HCI_LE_DISCONNECTION_COMPLETE_EVENT{
                               status=HCI_OK,
                               connectionHandle=0x0063,
                               reason=HCI_CONNECTION_TIMEOUT
                             }
    
    
    +40544 ms
    Verdict Description:     Unexpected ATT Disconnect received.

    What sould I do in situation when Lower Tester does not send any Confirmation to acknowledge this indication? As Kiyoshi said it is abnormal situation.

    I will be grateful for help.

    Full log here:

    <?xml version="1.0" encoding="utf-8"?>
    <ARCHIVE>
      <VERSION>2.0</VERSION>
      <PicsPixit>Test Case Started: CPS v. 7.6.0.15, CPS/SEN/SPE/BI-04-C started on Friday, April 24, 2020, 10:37:18
    
    ICS VALUES:
    
    TSPC_ALL FALSE
    TSPC_CPS_0_1 FALSE
    TSPC_CPS_0_2 TRUE
    TSPC_CPS_0a_1 TRUE
    TSPC_CPS_1_1 FALSE
    TSPC_CPS_1_2 TRUE
    TSPC_CPS_2_1 FALSE
    TSPC_CPS_2_2 TRUE
    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 FALSE
    TSPC_CPS_2_14 FALSE
    TSPC_CPS_2_15 FALSE
    TSPC_CPS_2_16 FALSE
    TSPC_CPS_2_17 FALSE
    TSPC_CPS_2_18 TRUE
    TSPC_CPS_2_19 FALSE
    TSPC_CPS_2_20 FALSE
    TSPC_CPS_2_21 FALSE
    TSPC_CPS_2_22 FALSE
    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 TRUE
    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 FALSE
    TSPC_CPS_3_23 FALSE
    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_3a_1 FALSE
    TSPC_CPS_4_1 TRUE
    TSPC_CPS_4_2 TRUE
    TSPC_CPS_4_3 TRUE
    TSPC_CPS_4_4 TRUE
    TSPC_CPS_4_5 TRUE
    TSPC_CPS_4_6 TRUE
    TSPC_CPS_5_1 FALSE
    TSPC_CPS_5_2 FALSE
    TSPC_CPS_5_3 FALSE
    
    IXIT VALUES:
    
    TSPX_bd_addr_iut CC52D3B4B51F
    TSPX_iut_device_name_in_adv_packet_for_random_address 
    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
    </PicsPixit>
      <LOG>
    
    +140 ms
    Message:                 MindTree Stack Version - 016.004.000
    
    
    
    +140 ms
    Initialize Test Case:    Build date: Jan  7 2020, 19:20:07
    
    
    
    +140 ms
    Start Test Case:         CPS/SEN/SPE/BI-04-C
    
    
    
    +140 ms
    Message:                   PTS Log started on Friday, April 24, 2020, 10:37:18
    
    
    
    +140 ms
    Message:                   PTS: v7.6.0 Build 15
    
    
    
    +140 ms
    Message:                   OS: Microsoft Windows NT 6.1.7601 Service Pack 1
    
    
    
    +140 ms
    Message:                   OS Name: Microsoft Windows 7 专业版 
    
    
    
    +4165 ms
    Preliminary Verdict:     PASS
    
    
    
    +4196 ms
    Send Event:              HCI!HCI_RESET
    
    
    +4321 ms
    Receive Event:           HCI?HCI_RESET_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4321 ms
    Preliminary Verdict:     PASS
    
    
    
    +4321 ms
    Send Event:              HCI!HCI_SET_EVENT_MASK{
                               eventMask=0x3FFFFFFFFFFFFFFF
                             }
    
    
    +4321 ms
    Receive Event:           HCI?HCI_SET_EVENT_MASK_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4321 ms
    Preliminary Verdict:     PASS
    
    
    
    +4321 ms
    Send Event:              HCI!HCI_READ_LOCAL_VERSION_INFORMATION
    
    
    +4321 ms
    Receive Event:           HCI?HCI_READ_LOCAL_VERSION_INFORMATION_COMPLETE_EVENT{
                               status=HCI_OK,
                               hciVersion=0x08,
                               hciRevision=0x30E8,
                               lmpVersion=0x08,
                               manufacturerName=0x000A,
                               lmpSubversion=0x30E8
                             }
    
    
    +4321 ms
    Preliminary Verdict:     PASS
    
    
    
    +4321 ms
    Send Event:              HCI!HCI_READ_BD_ADDR
    
    
    +4321 ms
    Receive Event:           HCI?HCI_READ_BD_ADDR_COMPLETE_EVENT{
                               status=HCI_OK,
                               bdAddress=0x001BDCF21BF2
                             }
    
    
    +4321 ms
    Preliminary Verdict:     PASS
    
    
    
    +4321 ms
    Preliminary Verdict:     PASS
    
    
    
    +4336 ms
    Send Event:              HCI!HCI_LE_LOCAL_SUPPORTED_FEATURES
    
    
    +4336 ms
    Receive Event:           HCI?HCI_LE_READ_LOCAL_SUPPORTED_FEATURES_COMPLETE_EVENT{
                               status=HCI_OK,
                               leFeatures=0x000000000000001F
                             }
    
    
    +4336 ms
    Send Event:              HCI!HCI_LE_SET_EVENT_MASK{
                               leEventMask=0x000000000000003F
                             }
    
    
    +4336 ms
    Receive Event:           HCI?HCI_LE_SET_EVENT_MASK_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4336 ms
    Send Event:              HCI!HCI_WRITE_LE_HOST_SUPPORTED{
                               leSupportedHost=HCI_LE_SUPPORTED_HOST_ENABLED,
                               simultaneousLeHost=HCI_SIMULTANEOUS_LE_HOST_ENABLED
                             }
    
    
    +4336 ms
    Receive Event:           HCI?HCI_WRITE_LE_HOST_SUPPORTED_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4336 ms
    Send Event:              HCI!HCI_LE_ADD_DEVICE_TO_WHITE_LIST{
                               addressType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
                               address=0xCC52D3B4B51F
                             }
    
    
    +4336 ms
    Receive Event:           HCI?HCI_LE_ADD_DEVICE_TO_WHITE_LIST_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4336 ms
    Preliminary Verdict:     PASS
    
    
    
    +4336 ms
    Send Event:              HCI!HCI_LE_ADD_DEVICE_TO_WHITE_LIST{
                               addressType=HCI_LE_RANDOM_DEVICE_ADDRESS,
                               address=0xCC52D3B4B51F
                             }
    
    
    +4336 ms
    Receive Event:           HCI?HCI_LE_ADD_DEVICE_TO_WHITE_LIST_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4336 ms
    Preliminary Verdict:     PASS
    
    
    
    +4336 ms
    Preliminary Verdict:     PASS
    
    
    
    +4336 ms
    Preliminary Verdict:     PASS
    
    
    
    +4336 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
                             }
    
    
    +4352 ms
    Receive Event:           HCI?HCI_LE_SET_SCAN_PARAMETERS_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +4352 ms
    Preliminary Verdict:     PASS
    
    
    
    +4352 ms
    Send Event:              HCI!HCI_LE_SET_SCAN_ENABLE{
                               leScanEnable=HCI_LE_SCAN_ENABLE,
                               filterDuplicates=HCI_LE_DUPLICATE_FILTERING_DISABLE
                             }
    
    
    +4352 ms
    Receive Event:           HCI?HCI_LE_SET_SCAN_ENABLE_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +5569 ms
    Send Event:              HCI!HCI_LE_SET_SCAN_ENABLE{
                               leScanEnable=HCI_LE_SCAN_DISABLE,
                               filterDuplicates=HCI_LE_DUPLICATE_FILTERING_DISABLE
                             }
    
    
    +5584 ms
    Receive Event:           HCI?HCI_LE_SET_SCAN_ENABLE_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +5584 ms
    Preliminary Verdict:     PASS
    
    
    
    +5600 ms
    Send Event:              HCI!HCI_LE_CREATE_CONNECTION{
                               peerAddr=0xCC52D3B4B51F,
                               peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
                               ownAddrType=HCI_LE_PUBLIC_DEVICE_ADDRESS,
                               scanInterval=0x0020,
                               scanWindow=0x0012,
                               filterPolicy=0x00,
                               minConnInterval=0x0032,
                               maxConnInterval=0x0046,
                               latency=0x0000,
                               supervisionTimeout=0x07D0,
                               minCELength=0x0000,
                               maxCELength=0x0000
                             }
    
    
    +5616 ms
    Receive Event:           HCI?HCI_LE_CREATE_CONNECTION_STATUS_EVENT{
                               status=HCI_OK
                             }
    
    
    +6411 ms
    Receive Event:           ATT?ATT_CONNECT_IND{
                               bdAddr=0xCC52D3B4B51F,
                               peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
                               lcid=0x1205,
                               status=0x0000
                             }
    
    
    +6411 ms
    Preliminary Verdict:     PASS
    
    
    
    +6411 ms
    Receive Event:           HCI?HCI_LE_CONNECTION_COMPLETE_EVENT{
                               status=HCI_OK,
                               connectionHandle=0x0063,
                               role=HCI_ROLE_MASTER,
                               peerAddressType=HCI_LE_RANDOM_DEVICE_ADDRESS,
                               peerAddress=CC52D3B4B51F,
                               connInterval=0x003C,
                               connLatency=0x0000,
                               supervisionTimeout=0x07D0,
                               clockAccuracy=HCI_LE_CLOCK_ACCURACY_500PPM
                             }
    
    
    +6411 ms
    Verdict Description:     Connection setup successfully.
    
    
    
    +6411 ms
    Pass:                    Tester successfully initiated connection.
    
    
    
    +6411 ms
    Verdict Description:     Tester successfully initiated connection.
    
    
    
    +8424 ms
    Verdict Description:     LE Security not initiated due to TSPX_security_enabled value.
    
    
    
    +8424 ms
    Send Event:              HCI!GET_CONNECTION_HANDLE{
                               addr=0xCC52D3B4B51F,
                               addr_type=0x01,
                               conn_handle=0x0063
                             }
    
    
    +8424 ms
    Send Event:              ATT!ATT_FIND_BY_TYPE_VALUE_REQ{
                               lcid=0x1205,
                               startingHandle=0x0001,
                               endingHandle=0xFFFF,
                               attributeType=0x2800,
                               length=0x0002,
                               1818
                             }
    
    
    +8642 ms
    Receive Event:           ATT?ATT_FIND_BY_TYPE_VALUE_RSP{
                               lcid=0x1205,
                               HandleRange={
                                 				{
                                   foundAttributeHandle=0x000E,
                                   endFoundHandle=0x0018
    					
                                 }
                               }
                             }
    
    
    +8782 ms
    Receive Event:           ATT?ATT_FIND_BY_TYPE_VALUE_CFM{
                               lcid=1205,
                               result=0x0000,
                               errorHandle=0x0000,
                               HandleRanges={
                                 				{
                                   foundAttributeHandle=0x000E,
                                   endFoundHandle=0x0018,
                                   
    					
                                 }
                               }
                             }
    
    
    +8782 ms
    Preliminary Verdict:     PASS
    
    
    
    +8782 ms
    Verdict Description:     Discover Primary Service by Service UUID Request completed successfully.
    
    
    
    +8782 ms
    Pass:                    The IUT successfully returned the UUID for Cycling Power
    
    
    
    +8782 ms
    Verdict Description:     The IUT successfully returned the UUID for Cycling Power
    
    
    
    +8782 ms
    Send Event:              ATT!ATT_READ_BY_TYPE_REQ{
                               lcid=0x1205,
                               startingHandle=0x000E,
                               endingHandle=0x0018,
                               attributeTypeSize=0x02,
                               attributeType=0x2803
                             }
    
    
    +8923 ms
    Receive Event:           ATT?ATT_READ_BY_TYPE_IND{
                               lcid=0x1205,
                               length=0x0017,
                               attributeTypeSize=0x02,
                               attributeType=0x2803,
                               ElementCount=03,
                               AttributeSize=07,
                               Handle=000F,
                               AttrValue=2A63001010,
                               Handle=0012,
                               AttrValue=2A65001302,
                               Handle=0014,
                               AttrValue=2A5D001502
                             }
    
    
    +8938 ms
    Receive Event:           ATT?ATT_READ_BY_TYPE_RSP{
                               				{
                                 handle=0x000F
    					value{
                                   Properties=0x10,
                                   Handle=0x0010,
                                   UUID=0x2A63
                                 }
    
                               }
    				{
                                 handle=0x0012
    					value{
                                   Properties=0x02,
                                   Handle=0x0013,
                                   UUID=0x2A65
                                 }
    
                               }
    				{
                                 handle=0x0014
    					value{
                                   Properties=0x02,
                                   Handle=0x0015,
                                   UUID=0x2A5D
                                 }
    
                               }
    
                             }
    
    
    +9079 ms
    Receive Event:           ATT?ATT_READ_BY_TYPE_IND{
                               lcid=0x1205,
                               length=0x0009,
                               attributeTypeSize=0x02,
                               attributeType=0x2803,
                               ElementCount=01,
                               AttributeSize=07,
                               Handle=0016,
                               AttrValue=2A66001728
                             }
    
    
    +9079 ms
    Receive Event:           ATT?ATT_READ_BY_TYPE_RSP{
                               				{
                                 handle=0x0016
    					value{
                                   Properties=0x28,
                                   Handle=0x0017,
                                   UUID=0x2A66
                                 }
    
                               }
    
                             }
    
    
    +9235 ms
    Receive Event:           ATT?ATT_READ_BY_TYPE_CFM{
                               lcid=0x1205,
                               attributeType=0x2803,
                               attributeTypeSize=0x02,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +9235 ms
    Receive Event:           ATT?ATT_READ_BY_TYPE_CFM{
                               				{
                                 handle=0x000F
    					value{
                                   Properties=0x10,
                                   Handle=0x0010,
                                   UUID=0x2A63
                                 }
    
                               }
    				{
                                 handle=0x0012
    					value{
                                   Properties=0x02,
                                   Handle=0x0013,
                                   UUID=0x2A65
                                 }
    
                               }
    				{
                                 handle=0x0014
    					value{
                                   Properties=0x02,
                                   Handle=0x0015,
                                   UUID=0x2A5D
                                 }
    
                               }
    				{
                                 handle=0x0016
    					value{
                                   Properties=0x28,
                                   Handle=0x0017,
                                   UUID=0x2A66
                                 }
    
                               }
    
                             }
    
    
    +9235 ms
    Preliminary Verdict:     PASS
    
    
    
    +9235 ms
    Verdict Description:     Discover All Characteristics of Service Request completed successfully.
    
    
    
    +9235 ms
    Send Event:              ATT!ATT_FIND_INFO_REQ{
                               lcid=0x1205,
                               startingHandle=0x0011,
                               endingHandle=0x0011
                             }
    
    
    +9453 ms
    Receive Event:           ATT?ATT_FIND_INFO_RSP{
                               				{
                                 handle=0x0011,
                                 uuid=0x2902
    					
                               }
                             }
    
    
    +9453 ms
    Receive Event:           ATT?ATT_FIND_INFO_CFM{
                               				{
                                 handle=0x0011,
                                 uuid=0x2902,
                                 
    					
                               }
                             }
    
    
    +9453 ms
    Preliminary Verdict:     PASS
    
    
    
    +9453 ms
    Verdict Description:     Discover All Characteristic Descriptors Request completed successfully.
    
    
    
    +9453 ms
    Send Event:              ATT!ATT_FIND_INFO_REQ{
                               lcid=0x1205,
                               startingHandle=0x0018,
                               endingHandle=0x0018
                             }
    
    
    +9609 ms
    Receive Event:           ATT?ATT_FIND_INFO_RSP{
                               				{
                                 handle=0x0018,
                                 uuid=0x2902
    					
                               }
                             }
    
    
    +9609 ms
    Receive Event:           ATT?ATT_FIND_INFO_CFM{
                               				{
                                 handle=0x0018,
                                 uuid=0x2902,
                                 
    					
                               }
                             }
    
    
    +9609 ms
    Preliminary Verdict:     PASS
    
    
    
    +9609 ms
    Verdict Description:     Discover All Characteristic Descriptors Request completed successfully.
    
    
    
    +9609 ms
    Send Event:              ATT!ATT_WRITE_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0018,
                               length=0x0002,
                               0000
                             }
    
    
    +9750 ms
    Receive Event:           ATT?ATT_WRITE_CFM{
                               lcid=0x1205,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +9750 ms
    Preliminary Verdict:     PASS
    
    
    
    +11263 ms
    Send Event:              ATT!ATT_WRITE_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0018,
                               length=0x0002,
                               0002
                             }
    
    
    +11403 ms
    Receive Event:           ATT?ATT_WRITE_CFM{
                               lcid=0x1205,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +11403 ms
    Preliminary Verdict:     PASS
    
    
    
    +11403 ms
    Send Event:              ATT!ATT_WRITE_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0011,
                               length=0x0002,
                               0000
                             }
    
    
    +11622 ms
    Receive Event:           ATT?ATT_WRITE_CFM{
                               lcid=0x1205,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +11622 ms
    Preliminary Verdict:     PASS
    
    
    
    +13150 ms
    Send Event:              ATT!ATT_WRITE_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0011,
                               length=0x0002,
                               0001
                             }
    
    
    +13275 ms
    Receive Event:           ATT?ATT_WRITE_CFM{
                               lcid=0x1205,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +13275 ms
    Preliminary Verdict:     PASS
    
    
    
    +13275 ms
    Send Event:              ATT!ATT_READ_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0013
                             }
    
    
    +13431 ms
    Receive Event:           ATT?ATT_READ_CFM{
                               lcid=0x1205,
                               length=0x0004,
                               result=0x0100,
                               errorHandle=0x0000,
                               value{
                                 CyclingPowerFeature=0x0011020A
                               }
    
                             }
    
    
    +13431 ms
    Preliminary Verdict:     PASS
    
    
    
    +13431 ms
    Verdict Description:     Read Request completed successfully. Handle=0x0013
    
    
    
    +13431 ms
    Preliminary Verdict:     PASS
    
    
    
    +13431 ms
    Pass:                    The data received for 'Cycling Power Feature' conforms to the schema
    
    
    
    +13431 ms
    Verdict Description:     The data received for 'Cycling Power Feature' conforms to the schema
    
    
    
    +13431 ms
    Send Event:              ATT!ATT_WRITE_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0017,
                               length=0x0001,
                               0C
                             }
    
    
    +13572 ms
    Receive Event:           ATT?ATT_WRITE_CFM{
                               lcid=0x1205,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +13572 ms
    Preliminary Verdict:     PASS
    
    
    
    +13572 ms
    Verdict Description:     Waiting for indication on handle = 0x0017 for Characteristic 'Cycling Power Control Point' (UUID = 0x2A66)
    
    
    
    +13587 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +14632 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +15600 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +16582 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +16582 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_IND{
                               lcid=0x1205,
                               attributeHandle=0x0017,
                               length=0x0005,
                               attributeValue=0x0001010C20
                             }
    
    
    +16582 ms
    Preliminary Verdict:     PASS
    
    
    
    +16598 ms
    Pass:                    The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.
    
    
    
    +16598 ms
    Verdict Description:     The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.
    
    
    
    +16598 ms
    Send Event:              ATT!ATT_WRITE_REQ{
                               lcid=0x1205,
                               attributeHandle=0x0017,
                               length=0x0001,
                               0C
                             }
    
    
    +16723 ms
    Receive Event:           ATT?ATT_WRITE_CFM{
                               lcid=0x1205,
                               result=0x0000,
                               errorHandle=0x0000
                             }
    
    
    +16723 ms
    Preliminary Verdict:     PASS
    
    
    
    +16723 ms
    Verdict Description:     Write Request completed successfully.
    
    
    
    +16723 ms
    Verdict Description:     Waiting for indication on handle = 0x0017 for Characteristic 'Cycling Power Control Point' (UUID = 0x2A66)
    
    
    
    +17628 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +18236 ms
    Receive Event:           L2CAP?L2CAP_LE_CONNECTION_UPDATE_IND{
                               peerAddr=0xCC52D3B4B51F,
                               peerAddrType=HCI_LE_RANDOM_DEVICE_ADDRESS,
                               minInterval=0x0014,
                               maxInterval=0x0028,
                               slaveLatency=0x0000,
                               supervision_timeout=0x01F4
                             }
    
    
    +18236 ms
    Send Event:              L2CAP!L2CA_LE_CONNECTION_UPDATE_RSP{
                               peerAddr=0xCC52D3B4B51F,
                               peerAddrType=0x01,
                               paramAccepted=1
                             }
    
    
    +18610 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +19578 ms
    Receive Event:           ATT?ATT_HANDLE_VALUE_NOTIFICATION_IND{
                               lcid=0x1205,
                               attributeHandle=0x0010,
                               length=0x000A,
                               attributeValue=0x0000000000000000002C
                             }
    
    
    +40544 ms
    Receive Event:           ATT?ATT_DISCONNECT_IND{
                               lcid=0x1205
                             }
    
    
    +40544 ms
    Receive Event:           HCI?HCI_LE_DISCONNECTION_COMPLETE_EVENT{
                               status=HCI_OK,
                               connectionHandle=0x0063,
                               reason=HCI_CONNECTION_TIMEOUT
                             }
    
    
    +40544 ms
    Verdict Description:     Unexpected ATT Disconnect received.
    
    
    
    +40544 ms
    Inconclusive:            Non-passing verdict returned from APICOM, see log for more details.
    
    
    
    +40544 ms
    Verdict Description:     Non-passing verdict returned from APICOM, see log for more details.
    
    
    
    +42697 ms
    Receive Event:           HCI?HCI_RESET_COMPLETE_EVENT{
                               status=HCI_OK
                             }
    
    
    +43633 ms
    Final Verdict:           INCONC
    
    
    
    +43633 ms
    Encrypted Verdict:       A1#ZWY4MzQ5MDg3MmQwNTIxOGQzMzQ5YjY2ODA5M2MzNjQ5ZDY4NmY0Yjc2MzIzM2VkNTUyNTFhNGU4Mjg1MjI0NA==#mpduB7T8LvovABj6T4Gu+NaqZZp5djc+JHVvJvU+j6aMa6oiCklRuq5sE+AhiaFT
    
    
    +43633 ms
    Test Case Ended:         CPS/SEN/SPE/BI-04-C
    
    </LOG>
      <SUMMARY>Test case : CPS/SEN/SPE/BI-04-C started
    	- Connection setup successfully.
    	- Tester successfully initiated connection.
    	- LE Security not initiated due to TSPX_security_enabled value.
    	- Discover Primary Service by Service UUID Request completed successfully.
    	- The IUT successfully returned the UUID for Cycling Power
    	- Discover All Characteristics of Service Request completed successfully.
    	- Discover All Characteristic Descriptors Request completed successfully.
    	- Discover All Characteristic Descriptors Request completed successfully.
    	- Read Request completed successfully. Handle=0x0013
    	- The data received for 'Cycling Power Feature' conforms to the schema
    	- Waiting for indication on handle = 0x0017 for Characteristic 'Cycling Power Control Point' (UUID = 0x2A66)
    	- The value for 'Cycling Power Control Point' sent by the IUT was correctly formatted.
    	- Write Request completed successfully.
    	- Waiting for indication on handle = 0x0017 for Characteristic 'Cycling Power Control Point' (UUID = 0x2A66)
    	- Unexpected ATT Disconnect received.
    	- Non-passing verdict returned from APICOM, see log for more details.
    Final Verdict:INCONC
    CPS/SEN/SPE/BI-04-C finished
    </SUMMARY>
    </ARCHIVE>

  • It's been a while since I looked at this.

    Do you have an on-air sniffer log? Is there any difference if you are using TSPX_security_enabled (presuming bonding is supported)?

    Is it the same if you are using the default SDK example? For example: 
    https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.sdk5.v15.2.0/ble_sdk_app_csc.html

    I notice the disconnect reason is HCI_CONNECTION_TIMEOUT, this may be caused by an assert (fault_handler()), have you checked that?

Related