CC2564C: CC2564C: A3DP source demo, Cancel a connection request

Hi Elisa,

Taking, air sniffer and FW logs would help.. Without the logs, it is difficult to say, what is going wrong..

Thanks

Hi Hari,

I did provide the air trace and fw logs, i uploaded them to the shared folder that Lauren provided.

Could you please confirm you have access to them?

Otherwise I can upload them again.

Thank you,

Hi Elisa,

The link may have expired.. Can, you please resend.. 

Thanks

Hello Hari,

Just to confirm that I emailed the logs to Lauren, since I could not upload them to the shared folder.

Could you please confirm that you received them?

Thank you!

Hi Elisa,

Yes, i received them.. Will get back in a day..

Thanks

Hi Elisa,

The FW logs does not show any excessive delays.. Did, you capture the air sniffer logs too? If, so can you please send them across? I wonder, if the ACL transactions between the peer stacks are sluggish..

Thanks

Hello Hari,

I will try to either upload the sniffer logs or to email them to Lauren. In the mean time one I noticed in the TI-logger's file : TI_U8I_NewPairFails_2.lgr

is that the connection request from TI seem to happen at time stamp 14:42:07.238

2366 14:42:07.238 receive LMP_SET_AFH (60), trans_id: master (0)   <--- Does this mean the connection request is being sent by TI?

If the above line does indicate that the connection request has been sent, then later, at time stamp 14:43:58.622 we see:

22936 14:43:58.622 0x00020C77 0x00017D9A <---- HCI_Link_Key_Request_Event

The time between those two events is almost 2min, Is this the reason for the delay?

Your advice is appreciated.

Hello Hari,

I just email Lauren an air trace file: TI_U8I_filtered_3.btt

What I noticed from those logs is that the headset (U8I) which is in pairing mode, still tries to connect to its last paired device, which is TI.

BUT, as mentioned earlier, TI has its PDL empty, and TI is scanning for devices, so from TI's list, we select U8I to connect to.

But the U8I keeps sending re-connection requests to TI, TI responds with authentication pending.

the U8I takes a while to send 'LMP Authentication Random Number' which TI rejects and finally U8I detaches.

After the headset sends LMP Detach, TI sends:

1921872: etAUD_Stream_Open_Confirmation 
1921877: Status: 3 
1921879: BD_ADDR: 0x501901302879 
1921884: LINK KEY: 0x00000000000000000000000000000000 

So it looks to me that it is the headset the one taking too long to send 'LMP Detach', probably because it is struggling trying to re-connect to TI and to handle the connection request that is coming from TI.

If this is true, the question is:   Can TI cancel/terminate the connection request that TI initiated, so TI does not have to wait 2min to send a response?

Thank you

Hello again,

I was able to upload two traces to the shared folder, the names of the files are:

TI_U8I_filtered_3.btt

and

TI_U8I_connect_takes_tooLong_toFail.btt

Thank you!

Hello again,

Looking at the air traces again, I am realizing that I do not see when TI starts to page the headset (right when I select U8I from TI's list of found devices). Maybe TI ends up not sending the connection request to the headset because TI has already received one from the headset. 

So it looks to me that it is the headset that takes too long to figure out what to do, but your insight is appreciated.

And the original question remains:  How can TI cancel/terminate the connection request that TI initiated, so TI does not have to wait 2min to send a response?

Your advice is greatly appreciated.

Can, you please provide the timestamp of the events in the sniff log file for your observations.

Thanks

the first time stamp, in the sniffer logs (TI_U8I_NewPairFails_2.lgr)  is  14:42:07.238

2366 14:42:07.238 receive LMP_SET_AFH (60), trans_id: master (0)   <---- it was at this moment when TI sent the connection request to the U8I

the second time stamp in the same sniffer log file is  14:43:58.622

22936 14:43:58.622 0x00020C77 0x00017D9A <---- HCI_Link_Key_Request_Event

the delta between 14:42:07.238 and 14:43:58.622 is almost 2min

Humm.. I am not sure, how you are determining that the connection request went at 2366.. It is not an LMP connection.. Viewing through my logger, i see below events ..

22935 - authentication request from remote 

22936 - Link key request from controller

22937 - host nack..

Timing wise, it seems fine..

20248 05/15/19 16:43:44.607 0x0001E0B6 0x000151DA LMP_channel_classification ----> AFH channel classification = 55 55 55 ff ff 7f fd ff 7f 55
20480 05/15/19 16:43:46.268 0x0001E5E5 0x00015709 <---- LMP_set_AFH AFH instant = 175870, AFH mode = 1, AFH channel map = 1f 00 c0 00 00 c0 03 00 c0 7f
21651 05/15/19 16:43:51.838 0x0001F758 0x0001687C LMP_channel_classification ----> AFH channel classification = ff ff 57 fd ff 7f fd ff 7f 55
21694 05/15/19 16:43:52.276 0x0001F8A7 0x000169CB <---- LMP_set_AFH AFH instant = 185472, AFH mode = 1, AFH channel map = 00 00 dc 03 00 c0 03 00 c0 7f
22935 05/15/19 16:43:58.622 0x00020C77 0x00017D9A <---- LMP_au_rand Random Number = 69 2c 5f db 99 ac b3 22 c9 ea 94 a5 c3 68 50 51
22936 05/15/19 16:43:58.622 0x00020C77 0x00017D9A <---- HCI_Link_Key_Request_Event
22937 05/15/19 16:43:58.637 0x00020C7C 0x00017D9F HCI_Link_Key_Request_Negative_Reply ---->

Thanks

Hi Hari,

I know that   2366 14:42:07.238 receive LMP_SET_AFH (60), trans_id: master (0)   

is the reference because at that moment I know I sent the connection request from TI, using: AUD_Open_Remote_Stream() 

but as you mentioned, I do not see an LMP message indicating the connection request, so that is why I asked if that line

2366 14:42:07.238 receive LMP_SET_AFH (60), trans_id: master (0)   <--- Does this mean the connection request is being sent by TI?

maybe TI's library never actually sent an LMP connection message.

then, from that moment, until the remote sends the authentication request to TI, there is an almost 2min time gap. This gap is the problem.

Once TI receives the authentication request at 22936, then everything is fine. But the problem is that it takes almost 2min to receive the authentication request.

from 

2366 14:42:07.238 receive LMP_SET_AFH (60), trans_id: master (0)  

to              

22936 14:43:58.622 0x00020C77 0x00017D9A <---- HCI_Link_Key_Request_Event

During those 2min, TI fails to start a new connection to any other device. That is why we are asking for a method to have TI cancel any pending transactions, so TI can re-start fresh.

Hi Elisa,

BT controller is transparent to ACL connections. they are handled from the host BT stack to peer device stack. So, you may not see any controller log messages for these connections. 

Snooping UART/HCI tx/rx lines may reveal when the ACL connection requests are sent. It is a rather complex procedure, but please take a look at below application note, if you can snoop these lines:

http://www.ti.com/lit/an/swpa234/swpa234.pdf

Thanks

Ok, I'll try.

Thanks

Hi Elisa,

Did, you get a chance to take the HCI sniffer logs? I understand it is little complex and may take a while.. If so, let us close this thread and create a new one, when ready..

Thanks