distance is always 0 in nrf_dm sample

[AndyM]

Hello

I built the nrf dm sample for the  nrf52840dk_nrf52840 target and loaded it on 2  nrf52840 dev kits

Tried both MCPD and RTT methods

No matter what the distance between the kits the distance reported by the software is always zero

There are also multiple -EAGAIN and -EBUSY errors 

They come from timeslot_queue_append() function that is called by dm_request_add()

dm_request_add() is called  the data_cb and  adv_scanned_cb callbacks in main.c

While -EAGAIN is harmless - it is returned when the dm request is already in the timeslot queue,

-EBUSY is questionable. It is returned when the start time of the last request in the list  is < than (TIMESLOT_LENGTH_US + MIN_TIME_BETWEEN_TIMESLOTS_US)

Not sure what the significance of that is - please clarify

What am I missing? All I did is build and loaded on 2 dev kits

I'm using SDK  1.9.1

Thanks

Here are the logs

--MCPD--

00> [00:00:26.463,165] <inf> peer_c: Measurement result:
00> [00:00:26.463,165] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:26.463,165] <inf> peer_c: Quality: ok
00> [00:00:26.463,165] <inf> peer_c: Distance estimates:
00> [00:00:26.463,195] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:26.509,765] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -16)
00> [00:00:26.575,653] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -16)
00> [00:00:26.638,336] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -16)
00> [00:00:26.770,568] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:26.828,521] <inf> peer_c: Measurement result:
00> [00:00:26.828,521] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:26.828,552] <inf> peer_c: Quality: ok
00> [00:00:26.828,552] <inf> peer_c: Distance estimates:
00> [00:00:26.828,552] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:26.828,704] <inf> peer_c: Measurement result:
00> [00:00:26.828,704] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:26.828,704] <inf> peer_c: Quality: ok
00> [00:00:26.828,735] <inf> peer_c: Distance estimates:
00> [00:00:26.828,735] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:26.896,850] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:26.938,415] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:26.966,918] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:27.030,609] <inf> peer_c: Measurement result:
00> [00:00:27.030,609] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.030,609] <inf> peer_c: Quality: ok
00> [00:00:27.030,639] <inf> peer_c: Distance estimates:
00> [00:00:27.030,700] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.030,853] <inf> peer_c: Measurement result:
00> [00:00:27.030,883] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.030,883] <inf> peer_c: Quality: ok
00> [00:00:27.030,883] <inf> peer_c: Distance estimates:
00> [00:00:27.030,914] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.153,320] <inf> peer_c: Measurement result:
00> [00:00:27.153,350] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.153,350] <inf> peer_c: Quality: ok
00> [00:00:27.153,350] <inf> peer_c: Distance estimates:
00> [00:00:27.153,350] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.153,503] <inf> peer_c: Measurement result:
00> [00:00:27.153,533] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.153,533] <inf> peer_c: Quality: ok
00> [00:00:27.153,533] <inf> peer_c: Distance estimates:
00> [00:00:27.153,533] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.296,173] <inf> peer_c: Measurement result:
00> [00:00:27.296,173] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.296,203] <inf> peer_c: Quality: ok
00> [00:00:27.296,203] <inf> peer_c: Distance estimates:
00> [00:00:27.296,203] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.296,356] <inf> peer_c: Measurement result:
00> [00:00:27.296,356] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.296,356] <inf> peer_c: Quality: ok
00> [00:00:27.296,386] <inf> peer_c: Distance estimates:
00> [00:00:27.296,386] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.353,485] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -16)
00> [00:00:27.475,921] <inf> peer_c: Measurement result:
00> [00:00:27.475,952] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.475,952] <inf> peer_c: Quality: ok
00> [00:00:27.475,982] <inf> peer_c: Distance estimates:
00> [00:00:27.475,982] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.476,135] <inf> peer_c: Measurement result:
00> [00:00:27.476,135] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.476,135] <inf> peer_c: Quality: ok
00> [00:00:27.476,165] <inf> peer_c: Distance estimates:
00> [00:00:27.476,165] <inf> peer_c: mcpd: ifft=0.00 phase_slope=0.00 rssi_openspace=0.00 best=0.00
00> [00:00:27.559,600] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:27.621,978] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:27.651,489] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -11)
00> [00:00:27.779,266] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -16)
00> [00:00:27.840,118] <inf> peer_c: Measurement result:
00> [00:00:27.840,118] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:27.840,118] <inf> peer_c: Quality: ok
00> [00:00:27.840,118] <inf> peer_c: Distance estimates:

---RTT----

00> [00:00:03.809,906] <inf> dm_main_c: Starting Distance Measurement example
00> [00:00:03.809,967] <dbg> nrf_dm.dm_init: Initialized NRF_DM version nrf_dm_0.6.1+
00> [00:00:03.810,150] <inf> sdc_hci_driver: SoftDevice Controller build revision:
00> 0e e7 c5 66 67 18 3c ac b3 d2 cc 81 a3 dc f1 c0 |...fg.<. ........
00> c0 36 02 22 |.6."
00> [00:00:03.814,483] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
00> [00:00:03.814,483] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
00> [00:00:03.814,483] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 14.50663 Build 1008232294
00> [00:00:03.815,795] <inf> bt_hci_core: Identity: E4:38:27:84:A8:F3 (random)
00> [00:00:03.815,795] <inf> bt_hci_core: HCI: version 5.2 (0x0b) revision 0x12fe, manufacturer 0x0059
00> [00:00:03.815,826] <inf> bt_hci_core: LMP: version 5.2 (0x0b) subver 0x12fe
00> [00:00:03.815,826] <inf> dm_main_c: DM Bluetooth LE Synchronization initialization
00> [00:00:05.855,255] <inf> peer_c: Measurement result:
00> [00:00:05.855,285] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:05.855,285] <inf> peer_c: Quality: ok
00> [00:00:05.855,285] <inf> peer_c: Distance estimates:
00> [00:00:05.855,285] <inf> peer_c: rtt: rtt=0.00
00> [00:00:05.855,438] <inf> peer_c: Measurement result:
00> [00:00:05.855,438] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:05.855,438] <inf> peer_c: Quality: ok
00> [00:00:05.855,468] <inf> peer_c: Distance estimates:
00> [00:00:05.855,468] <inf> peer_c: rtt: rtt=0.00
00> [00:00:07.507,446] <inf> peer_c: Measurement result:
00> [00:00:07.507,476] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:07.507,476] <inf> peer_c: Quality: ok
00> [00:00:07.507,476] <inf> peer_c: Distance estimates:
00> [00:00:07.507,476] <inf> peer_c: rtt: rtt=0.00
00> [00:00:07.507,629] <inf> peer_c: Measurement result:
00> [00:00:07.507,629] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:07.507,629] <inf> peer_c: Quality: ok
00> [00:00:07.507,629] <inf> peer_c: Distance estimates:
00> [00:00:07.507,659] <inf> peer_c: rtt: rtt=0.00
00> [00:00:08.049,499] <inf> peer_c: Measurement result:
00> [00:00:08.049,530] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:08.049,530] <inf> peer_c: Quality: ok
00> [00:00:08.049,560] <inf> peer_c: Distance estimates:
00> [00:00:08.049,560] <inf> peer_c: rtt: rtt=0.00
00> [00:00:08.049,682] <inf> peer_c: Measurement result:
00> [00:00:08.049,713] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:08.049,713] <inf> peer_c: Quality: ok
00> [00:00:08.049,713] <inf> peer_c: Distance estimates:
00> [00:00:08.049,713] <inf> peer_c: rtt: rtt=0.00
00> [00:00:09.309,631] <inf> peer_c: Measurement result:
00> [00:00:09.309,661] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:09.309,661] <inf> peer_c: Quality: ok
00> [00:00:09.309,661] <inf> peer_c: Distance estimates:
00> [00:00:09.309,661] <inf> peer_c: rtt: rtt=0.00
00> [00:00:09.309,814] <inf> peer_c: Measurement result:
00> [00:00:09.309,814] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:09.309,844] <inf> peer_c: Quality: ok
00> [00:00:09.309,844] <inf> peer_c: Distance estimates:
00> [00:00:09.309,844] <inf> peer_c: rtt: rtt=0.00
00> [00:00:09.670,623] <inf> peer_c: Measurement result:
00> [00:00:09.670,654] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:09.670,654] <inf> peer_c: Quality: ok
00> [00:00:09.670,654] <inf> peer_c: Distance estimates:
00> [00:00:09.670,654] <inf> peer_c: rtt: rtt=0.00
00> [00:00:09.670,806] <inf> peer_c: Measurement result:
00> [00:00:09.670,806] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:09.670,806] <inf> peer_c: Quality: ok
00> [00:00:09.670,806] <inf> peer_c: Distance estimates:
00> [00:00:09.670,837] <inf> peer_c: rtt: rtt=0.00
00> [00:00:12.667,114] <inf> peer_c: Measurement result:
00> [00:00:12.667,144] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:12.667,144] <inf> peer_c: Quality: ok
00> [00:00:12.667,144] <inf> peer_c: Distance estimates:
00> [00:00:12.667,144] <inf> peer_c: rtt: rtt=0.00
00> [00:00:12.667,297] <inf> peer_c: Measurement result:
00> [00:00:12.667,297] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:12.667,327] <inf> peer_c: Quality: ok
00> [00:00:12.667,327] <inf> peer_c: Distance estimates:
00> [00:00:12.667,327] <inf> peer_c: rtt: rtt=0.00
00> [00:00:13.540,069] <dbg> nrf_dm.dm_request_add: Timeslot allocation failed (err -16)
00> [00:00:14.227,966] <inf> peer_c: Measurement result:
00> [00:00:14.227,966] <inf> peer_c: Addr: F1:EC:D4:BA:70:C4 (random)
00> [00:00:14.227,996] <inf> peer_c: Quality: ok
00> [00:00:14.227,996] <inf> peer_c: Distance estimates:
00> [00:00:14.227,996] <inf> peer_c: rtt: rtt=0.00

[Kenneth]

Hello,

If you have any problems with the examples I suggest to try the latest nRF Connect SDK:
https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/samples/bluetooth/nrf_dm/README.html#bluetooth-nrf-distance-measurement-with-bluetooth-le-discovery

For instance download v2.1.0 from toolchain manager and try again.

Best regards,
Kenneth

[AndyM]

It's working! Thank you!

[AndyM]

UPDATE

1. Using MCPD method works for 10 seconds then stops, i.e nothing is printed to the rtt log.Tried to move one of the boards - still nothing. No errors in the log either. Log level set to 4.Any ideas?
Thanks

[AndyM]

UPDATE2

Turns out one of the devkits was on battery and losing power.so false alarm

One other thing I'm noticing
I enabled error reporting for dm_request_add() function - still get errors -EAGAIN and -EBUSY

-EAGAIN is self explanatory - but what about -BUSY?

00> [00:03:07.776,123] <inf> peer_c: mcpd: ifft=10.25 phase_slope=12.18 rssi_openspace=17.78 best=10.25
00> [00:03:07.846,313] <err> dm_main_c: dm_request_add for DM_ROLE_REFLECTOR failed:-11
00> [00:03:07.880,310] <err> dm_main_c: dm_request_add for DM_ROLE_INITIATOR failed:-11
00> [00:03:07.947,601] <err> dm_main_c: dm_request_add for DM_ROLE_INITIATOR failed:-11

00> [00:00:52.922,363] <inf> peer_c: mcpd: ifft=10.84 phase_slope=22.52 rssi_openspace=17.78 best=10.84
00> [00:00:54.077,819] <err> dm_main_c: dm_request_add for DM_ROLE_INITIATOR failed:-16
00> [00:00:55.092,620] <err> dm_main_c: dm_request_add for DM_ROLE_INITIATOR failed:-16
00> [00:00:56.564,178] <err> dm_main_c: dm_request_add for DM_ROLE_REFLECTOR failed:-16
00> [00:00:56.672,027] <err> dm_main_c: dm_request_add for DM_ROLE_INITIATOR failed:-11
00> [00:00:57.197,937] <err> dm_main_c: dm_request_add for DM_ROLE_INITIATOR failed:-16
00> [00:00:57.519,256] <inf> peer_c: Measurement result:
00> [00:00:57.519,287] <inf> peer_c: Addr: E4:38:27:84:A8:F3 (random)
00> [00:00:57.519,317] <inf> peer_c: Quality: poor
00> [00:00:57.519,317] <inf> peer_c: Distance estimates:
00> [00:00:57.519,348] <inf> peer_c: mcpd: ifft=0.29 phase_slope=0.00 rssi_openspace=25.12 best=0.29

[Kenneth]

Hi,

Looking at the implementation of dm_request_add() I can find it's a wrapper around timeslot_queue_append(), this function can provide the following error codes:

* @retval -ENOMEM when the tiemslot queue is full or a memory allocation error.
* @retval -EAGAIN when a single peer has a maximum number of timeslots scheduled.
* @retval -EBUSY when the timeslot cannot be scheduled due to time restrictions.

So it looks like both -EBUSY and -EAGAIN simply means wait and try again later.

Best regards,
Kenneth