BTLE Fundamentals - Lesson 6, Exercise 2 - LL_PHY_REQ response is 2 LL_REJECT_EXT_IND and then nothing, however COM logging on the app indicates success

[robbsadler]

I am working through BTLE Fundamentals, Lesson 6, Exercise 2, and running the code from blefund_less3_exer2 per the instructions and it all looks good on the app COM log:

*** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
[00:00:00.000,274] <inf> Lesson3_Exercise2: Starting Lesson 3 - Exercise 2

[00:00:00.000,671] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision:
36 f0 e5 0e 87 68 48 fb 02 fd 9f 82 cc 32 e5 7b |6....hH. .....2.{
91 b1 5c ed |..\.
[00:00:00.002,593] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.002,624] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:00.002,655] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 54.58864 Build 1214809870
[00:00:00.003,540] <inf> bt_hci_core: Identity: EA:F7:95:23:3C:04 (random)
[00:00:00.003,570] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x118f, manufacturer 0x0059
[00:00:00.003,601] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x118f
[00:00:00.003,601] <inf> Lesson3_Exercise2: Bluetooth initialized
[00:00:00.004,486] <inf> Lesson3_Exercise2: Advertising successfully started
[00:00:15.846,984] <inf> Lesson3_Exercise2: Connected
[00:00:15.847,015] <inf> Lesson3_Exercise2: Connection parameters: interval 45.00 ms, latency 0 intervals, timeout 5000 ms
[00:00:15.915,740] <inf> Lesson3_Exercise2: MTU exchange successful
[00:00:15.915,771] <inf> Lesson3_Exercise2: New MTU: 244 bytes
[00:00:16.050,872] <inf> Lesson3_Exercise2: Data length updated. Length 251/27 bytes, time 2120/328 us
[00:00:16.275,756] <inf> Lesson3_Exercise2: PHY updated. New PHY: 1M
[00:00:16.501,007] <inf> Lesson3_Exercise2: Connection parameters updated: interval 7.50 ms, latency 0 intervals, timeout 5000 ms
[00:00:16.755,737] <inf> Lesson3_Exercise2: Connection parameters updated: interval 45.00 ms, latency 0 intervals, timeout 5000 ms
[00:00:21.270,660] <inf> Lesson3_Exercise2: Connection parameters updated: interval 1000.00 ms, latency 0 intervals, timeout 4000 ms

But in the sniffer output, I'm getting an error in response to the LL_PHY_REQ, and I have retried it many times:

Time	Source	Protocol	Length	Flags	Channel Index	Delta time (start to start)	RSSI	Info
1472.562202	Slave_0xd2f6322c	LE LL	29	0x01	31	326µs	-26 dBm	Control Opcode: LL_PHY_REQ
1472.607106	Slave_0xd2f6322c	ATT	52	0x01	26	230µs	-23 dBm	Rcvd Read By Group Type Response, Attribute List Length: 1, Unknown
1472.607544	Master_0xd2f6322c	LE LL	29	0x03	26	438µs	-45 dBm	Control Opcode: LL_REJECT_EXT_IND
1472.651875	Master_0xd2f6322c	LE LL	29	0x03	30	44331µs	-42 dBm	Control Opcode: LL_REJECT_EXT_IND

I was trying to see if there was something I was missing, and ran into the definition of the 0x2a Different Transaction Collision error. It looks like you should wait for a response before sending out another request, and the exercise code doesn't do that. One comment I found mentioned that starting another request while one is in process is a spec violation. So I'm wondering if this is generally true for all requests, and for guidance on how best to accomplish this.

I modified the code as follows add a 1 sec sleep before the next request, and it eliminated the collision:

	/* STEP 7.2 - Update the PHY mode */
	update_phy(my_conn);

	// wait for a second - RLS
	k_sleep(K_MSEC(1000));

	/* STEP 13.5 - Update the data length and MTU */
	update_data_length(my_conn);
	update_mtu(my_conn);

So it looks like that may be something missing in the exercise, and I might want to send these async requests out awaiting the previous one to complete. 

Can anyone comment on best practices for doing this?

I am not new to async programming or to C, but this is my first time around BTLE programming.

[Einar Thorsrud]

Hi,

Thank you for reporting. I have forwarded this to the cours maintainer.

Regarding a better approach for this that could be to wait for the callback from the PHY update before continuing with the data length update. In this erxercise code, the callback function is on_le_phy_updated() (this is registered along with other callbacks in a call to bt_conn_cb_register().

[Edvin]

Hello,

Is it possible to upload the sniffer trace that you pasted some snippets from? 

Best regards,

Edvin

[robbsadler]

I can probably repro - it was a very consistent situation for my setup. I'll get you the trace when I get set up (on the road currently).

[Edvin]

That would be great. You see, I am not able to reproduce it, but I also see that my phone also requests some of these updates before the nRF has had the chance to do so, and therefore, the request is not physically sent, and hence no collission.

I could of course write a central sample that doesn't actively request any of these updates, but if you already have a setup that can replicate the issue, that would be great. To be honest, I am surprised that the BT stack didn't throw an error if it is doing an illegal operation. Since this is the case, it would be nice to have a sniffer trace to point to.

Can you please also specify what version of NCS you are using? And you didn't specifically choose the Zephyr Bluetooth controller? (if you don't know what I am talking about, then you probably didn't. The default controller is the SoftDevice Controller from Nordic).

Best regards,

Edvin

[robbsadler]

Okay, that took me a bit cause of some non-related interruptions. Here you go...BTLE_L6E2_Getting_LL_REJECT_EXT_IND_CollisionError.pcapng

Hopefully that is the format you need.