Unable to pass 2 seconds for the PAwR sync ad

[TheLittleFish]

Hi Nordic Community

I have a problem with the PAwR examples were I'm unable to place a sync interval bigger than 2 secs.

The example starts with an interval of 0xFF * 1.25 = 318.75 ms. I altered it to 1 sec and everything works. But if I increase it further it stops working.

I tried this with the periodic_adv_conn and periodic_sync_connect (PAST) as well as with the periodic_adv_rsp and periodic_sync_rsp.

This is are the errors given for the periodic_sync_conn:

*** Booting nRF Connect SDK v2.5.2 ***
[00:00:00.000,701] <inf> Log_Main: main: Starting Beacon Demo

[00:00:00.000,732] <inf> Log_Main: main: It is an ID: ID!!
[00:00:00.000,854] <inf> bt_sdc_hci_driver: hci_driver_open: SoftDevice Controller build revision: 
                                            8d dc 02 cb 49 26 c6 47  1a 6a 3d 4e 2f d1 a4 f2 |....I&.G .j=N/...
                                            2e 38 1b 75                                      |.8.u             
[00:00:00.003,814] <inf> bt_hci_core: hci_vs_init: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.003,845] <inf> bt_hci_core: hci_vs_init: HW Variant: nRF52x (0x0002)
[00:00:00.003,875] <inf> bt_hci_core: hci_vs_init: Firmware: Standard Bluetooth controller (0x00) Version 141.732 Build 3324398027
[00:00:00.004,974] <inf> bt_hci_core: bt_dev_show_info: Identity: C3:13:1C:91:79:C5 (random)
[00:00:00.005,004] <inf> bt_hci_core: bt_dev_show_info: HCI: version 5.4 (0x0d) revision 0x1168, manufacturer 0x0059
[00:00:00.005,035] <inf> bt_hci_core: bt_dev_show_info: LMP: version 5.4 (0x0d) subver 0x1168
[00:00:00.005,065] <inf> Log_bleFasePAwR: bleFasePAwR_ready: Bluetooth initialized
[00:00:00.005,065] <dbg> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Starting Scan
[00:00:00.005,767] <dbg> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Scanning 
[00:00:00.080,932] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Found periodic advertising.
[00:00:00.080,993] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Creating Periodic Advertising Sync
[00:00:00.081,268] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Waiting for periodic sync

[00:00:02.560,028] <inf> Log_bleFasePAwR: sync_cb: Synced to 40:84:D1:A0:B5:23 (random) with 5 subevents
[00:00:02.560,211] <wrn> bt_hci_core: bt_hci_cmd_send_sync: opcode 0x2084 status 0x42
[00:00:02.560,241] <err> Log_bleFasePAwR: sync_cb: Failed to set subevents to sync to (err -5)
[00:00:02.560,302] <dbg> Log_bleFasePAwR: recv_cb: info->subevent: 0
[00:00:02.560,302] <dbg> Log_bleFasePAwR: recv_cb: buf.len: 30, buf.data: 30, , , 0, 0
[00:00:02.561,035] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Periodic sync established.
[00:00:02.561,309] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Stopped scanning
[00:00:02.561,340] <wrn> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Expected: The sem_per_term has been reseted to 0 (err -16)
[00:00:02.562,713] <inf> Log_bleFasePAwR: recv_cb: Responding with transmitedData: flags: 0, ID: A1, len: 30
[00:00:02.562,927] <wrn> bt_hci_core: bt_hci_cmd_send_sync: opcode 0x2083 status 0x42
[00:00:02.562,957] <err> Log_bleFasePAwR: recv_cb: Failed to send response (err -5)
[00:00:02.563,049] <inf> Log_bleFasePAwR: term_cb: Sync terminated (reason 31)
[00:00:02.563,110] <dbg> Log_Main: main: Terminated Main
[00:00:02.563,110] <dbg> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Starting Scan
[00:00:02.563,537] <dbg> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Scanning 
[00:00:02.585,021] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Found periodic advertising.
[00:00:02.585,052] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Creating Periodic Advertising Sync
[00:00:02.585,296] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Waiting for periodic sync

[00:00:05.060,089] <inf> Log_bleFasePAwR: sync_cb: Synced to 40:84:D1:A0:B5:23 (random) with 5 subevents
[00:00:05.060,302] <wrn> bt_hci_core: bt_hci_cmd_send_sync: opcode 0x2084 status 0x42
[00:00:05.060,302] <err> Log_bleFasePAwR: sync_cb: Failed to set subevents to sync to (err -5)
[00:00:05.060,363] <dbg> Log_bleFasePAwR: recv_cb: info->subevent: 0
[00:00:05.060,394] <dbg> Log_bleFasePAwR: recv_cb: buf.len: 30, buf.data: 30, , , 0, 0
[00:00:05.061,126] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Periodic sync established.
[00:00:05.062,805] <inf> Log_bleFasePAwR: recv_cb: Responding with transmitedData: flags: 0, ID: A1, len: 30
[00:00:05.063,018] <wrn> bt_hci_core: bt_hci_cmd_send_sync: opcode 0x2083 status 0x42
[00:00:05.063,049] <err> Log_bleFasePAwR: recv_cb: Failed to send response (err -5)
[00:00:05.063,140] <inf> Log_bleFasePAwR: term_cb: Sync terminated (reason 31)
[00:00:05.063,201] <inf> Log_bleFasePAwR: bleFasePAwR_adquirePeriodicSync: Stopped scanning

I saw that a interval of 10 s is possible as is presented in:

 Periodic Advertising with Responses (PAwR): A practical guide 

I'm using NCS 2.5.2.

I would appreciate any guidance. Thank you for your help,

Fish

[TheLittleFish]

Update:

Found the problem with the periodic_adv_rsp and periodic_sync_rsp (PAST) versions.
In the same website give for the 10 s a version of these codes developed for low power is available for download. After analyzing the differences between it and the original, I discovered that if the 10 s delay, before the periodic_adv_rsp gives an order to disconnect, is removed the program fails.

		err = k_sem_take(&sem_written, K_SECONDS(10));
		if (err) {
			printk("Timed out during GATT write\n");
			num_synced--;

			goto disconnect;
		}

		printk("PAwR config written to sync %d, disconnecting\n", num_synced - 1);

disconnect:
		//added a delay so that the peer has enough time to sync before disconnection
		//k_msleep(10000); //  <---- This one
		if (default_conn)
		{
			err = bt_conn_disconnect(default_conn, BT_HCI_ERR_REMOTE_USER_TERM_CONN);
			if (err) {
					printk("Failed to disconnect, can be that the connection is already terminated, continue \n");		
			}
		}
		printk("Waiting for disconnected\n");
		k_sem_take(&sem_disconnected, K_FOREVER);
	}

When reducing the delay to 5 s, it give the following error:

Waiting for periodic sync...
Connected (err 0x00)
New timing: subevent 1, response slot 3
Not synced yet
Disconnected (reason 0x13)
Timed out while synchronizing
[00:01:10.012,603] <err> bt_adv: No valid legacy adv

Lowering the delay below 10 s makes the error appear, its chance of triggering seams to increase the lower the delay.

This means that for the periodic_sync_rsp needs for some reason to be in a connection with the periodic_adv_rsp to synchronize.

Any ideas why this is necessary?
I read a bit of the Bluetooth core but could not find this necessity.

[dejans]

Hi,

Is it that you tried to change interval_min and interval_max to the value 0x1F40 to get 10 s interval and this worked well when you added 10 seconds delay using k_msleep(10000) in periodic_adv_rsp sample (and used both periodic_adv_rsp and periodic_sync_rsp samples)?

There are 2 pairs of PAwR samples which should be used for testing. First pair consists of periodic_adv_rsp and periodic_sync_rsp samples and the second pair consists of periodic_adv_conn and periodic_sync_conn samples. What are you trying to achieve by combining periodic_sync_conn and periodic_adv_rsp?

Best regards,
Dejan

[TheLittleFish]

dejans said:

Is it that you tried to change interval_min and interval_max to the value 0x1F40 to get 10 s interval and this worked well when you added 10 seconds delay using k_msleep(10000) in periodic_adv_rsp sample (and used both periodic_adv_rsp and periodic_sync_rsp samples)?

Yes i followed the low-power examples available in this link

 Periodic Advertising with Responses (PAwR): A practical guide 

dejans said:

There are 2 pairs of PAwR samples which should be used for testing. First pair consists of periodic_adv_rsp and periodic_sync_rsp samples and the second pair consists of periodic_adv_conn and periodic_sync_conn samples. What are you trying to achieve by combining periodic_sync_conn and periodic_adv_rsp?

That is my fault it was suppose to be as you have written periodic_adv_rsp with periodic_sync_rsp and  periodic_adv_conn with periodic_sync_conn. Altered in update.

[TheLittleFish]

So I went digging in the Bluetooth 5.4 core for more information and found this:

---

5.1.13 Periodic Advertising Sync Transfer procedure
A Controller may use the Periodic Advertising Sync Transfer procedure to transfer, to a connected peer device, the synchronization information necessary to synchronize to a periodic advertising train (see Section 4.4.3.4). Either the Central or the Peripheral Link Layer initiates this procedure by sending an LL_PERIODIC_SYNC_IND PDU or an LL_PERIODIC_SYNC_WR_IND PDU. The PDU used is determined by the type of the periodic advertising used. For PAwR, the LL_PERIODIC_SYNC_WR_IND PDU shall be used, otherwise the LL_PERIODIC_SYNC_IND PDU shall be used. If the LL_PERIODIC_SYNC_WR_IND PDU is used, then the RspAA shall be set to an Access Address value as specified in Section 2.1.2.
If the Host has enabled receipt of transfers and the Link Layer receives an LL_PERIODIC_SYNC_IND PDU or an LL_PERIODIC_SYNC_WR_IND PDU that describes a periodic advertising train that the Link Layer is neither already synchronized with nor in the process of synchronizing with, the Link Layer shall synchronize with the described periodic advertising train and then notify the Host; it shall also notify the Host if synchronization fails. However, if the PHY field of the LL_PERIODIC_SYNC_IND PDU or the LL_PERIODIC_SYNC_WR_IND PDU has no bits or more than one bit set, or the bit set corresponds to a PHY that the recipient does not support or is reserved for future use, the recipient shall ignore the PDU.
The procedure has completed when an LL_PERIODIC_SYNC_IND PDU or an LL_PERIODIC_SYNC_WR_IND PDU has been sent or received.

page 2886

---

Correct me if I'm wrong but, in the second paragraph where it says "and then notify the Host; it shall also notify the Host if synchronization fails", it means that the Host (the one giving the Per. Adv. information trough PAST) must be informed of the success of the synchronization.

Applying this to the example it means that the connection established with the Host must be maintained until the synchronization is resolved, has to inform it of the result.

If this is correct it explains why the example does not work without the delay, but it does explained the example that does not utilize PAST failing. I still have to test it with version 2.7.0 of the sdk, will update when done.

[TheLittleFish]

UPDATE:

After updating to sdk 2.7.0 the periodic_adv_conn and periodic_sync_conn samples no longer give a sync error. Initially there was also the message received was also garbage, but that was my fault, and now it works as expected. I'm presuming the softdevices controller had a bug in version 2.5.2 that was corrected in future updates.

Tomorrow will do more test and confirm if everything is really working as should.

[dejans]

Hi,

Thank you for the update.

Best regards,
Dejan

[TheLittleFish]

After some testing everything seems to be working ok.

Solutions:

1 - PAST does not permit disconnect without a response from the peripheral to the Host about how the synchronization went.

2 - Updating from sdk 2.5.2 to 2.7.0 fixed the connectivity problem that occurred when trying to synchronize to a Per. Adv. bigger than 2 sec.