DTM test not returning any packets

[Alex Crombie]

We have the following setup:
 - Both nRF52832 and nRF52840 chips in our product

 - The nRF52832 is a module while the nRF52840 is the chip integrated directly onto our PCB

 - SDK 15.0.0 (and integrating ble_dtm.c into our test firmware)

 -  Our devices communicate quite happily over BLE with each other in all configurations (832-832, 832-840, and 840-840) (relevant a bit later)

We are looking to do certification for our devices and we need to get the packet error rate in a blocking test. I have already looked at nAN34_v1.01 and was planning to retrieve the packet error rate as in the python scripts. As the nRF52 chips are already integrated into our product we have implemented the DTM interface over I2C rather than serial.

The issue we are seeing is that we start the test by setting out of the devices to transmit with the following options followed by running the receiver test for 1-5 seconds before ending the receiver test. When the test is ended the number of received packets is reported as 0:

The transmitter is setup as follows:

- RESET: 0x0000

- Top two bytes in length to 11: 0x010c

- PHY 2M: 0x0208

- TX power -8dBm: 0xb80b

- Start Transmit PRBS9 Max length @ 2442MHz: 0x94fc

The receiver is setup as follows:

- RESET: 0x0000

- Top two bytes in length to 11: 0x010c

- PHY 2M: 0x0208

- Start Receive PRBS9 Max length @ 2442MHz: 0x54fc

- Wait 1-5 seconds

- End Test: 0xc000

For each of the operations ble_dtm.c returns the result as 0, and the ending of the receiver test always returns 32768 which should be packet report: count=0, this is irregardless of the channel selected.

A couple of questions:
1) Is there anything wrong in the setup and commands used?

2) Any Idea why ending any test always returns the packet count as 0?

[Håkon Alseth]

Hi,

 

As the nRF52 chips are already integrated into our product we have implemented the DTM interface over I2C rather than serial.

 Is there a specific reason for not using UART with DTM? How do you interface the nRF? Using a USB->I2C bridge?

 

 

1) Is there anything wrong in the setup and commands used?

Do you parse the response data from the DUT? Command-wise, this looks OK.

 

Here's the log file from entering TX/RX with your specified settings taken from nRF Connect for desktop -> direct test mode application:

Fullscreen dtm_rx_2Mbit_2442MHz.txt Download

2021-03-08T13:27:47.466Z INFO Application data folder: /home/hkn/.config/nrfconnect/pc-nrfconnect-dtm
2021-03-08T13:27:47.555Z DEBUG App pc-nrfconnect-dtm v1.1.7 official
2021-03-08T13:27:47.555Z DEBUG App path: /home/hkn/.nrfconnect-apps/node_modules/pc-nrfconnect-dtm
2021-03-08T13:27:47.555Z DEBUG nRFConnect 3.6.1 is supported by the app (^3.2.0)
2021-03-08T13:27:47.555Z DEBUG nRFConnect path: /tmp/.mount_nrfcong25EQb/resources/app.asar
2021-03-08T13:27:47.555Z DEBUG HomeDir: /home/hkn
2021-03-08T13:27:47.555Z DEBUG TmpDir: /tmp
2021-03-08T13:27:48.345Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS0
2021-03-08T13:27:48.345Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS1
2021-03-08T13:27:48.345Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS10
2021-03-08T13:27:48.345Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS11
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS12
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS13
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS14
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS15
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS16
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS17
2021-03-08T13:27:48.346Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS18
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS19
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS2
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS20
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS21
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS22
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS23
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS24
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS25
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS26
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS27
2021-03-08T13:27:48.347Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS28
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS29
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS3
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS30
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS31
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS4
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS5
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS6
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS7
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS8
2021-03-08T13:27:48.348Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS9
2021-03-08T13:27:54.336Z INFO Validating firmware for device with s/n 000683340399
2021-03-08T13:27:56.742Z INFO Device selected successfully
2021-03-08T13:28:02.969Z INFO Running device setup
2021-03-08T13:28:02.969Z DEBUG DTM Transport: Create setup CMD with control: 0
2021-03-08T13:28:02.970Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-08T13:28:02.970Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:28:02.973Z DEBUG DTM Transport: Serialport is opened
2021-03-08T13:28:02.974Z DEBUG DTM Transport: Succeeded to open serialport
2021-03-08T13:28:02.975Z DEBUG DTM Transport: Sending data: 0x00 0x00
2021-03-08T13:28:02.982Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:28:02.983Z DEBUG DTM Transport: Create tx power CMD: 0
2021-03-08T13:28:02.983Z DEBUG DTM Transport: Sending data: 0x80 0x0B
2021-03-08T13:28:02.990Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:28:02.990Z DEBUG DTM Transport: Create setup CMD with control: 1
2021-03-08T13:28:02.990Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-08T13:28:02.990Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:28:02.990Z DEBUG DTM Transport: Sending data: 0x01 0x00
2021-03-08T13:28:02.997Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:28:02.997Z DEBUG DTM Transport: Create setup CMD with control: 3
2021-03-08T13:28:02.998Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-08T13:28:02.998Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:28:02.998Z DEBUG DTM Transport: Sending data: 0x03 0x00
2021-03-08T13:28:03.005Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:28:03.005Z DEBUG DTM Transport: Create setup CMD with control: 2
2021-03-08T13:28:03.005Z DEBUG DTM Transport: Create setup CMD with parameter: 2
2021-03-08T13:28:03.005Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:28:03.006Z DEBUG DTM Transport: Sending data: 0x02 0x08
2021-03-08T13:28:03.012Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:28:03.013Z INFO Starting test
2021-03-08T13:28:03.016Z DEBUG DTM Transport: Create receiver CMD with frequency: 2442
2021-03-08T13:28:03.016Z DEBUG DTM Transport: Create receiver CMD with length: 1
2021-03-08T13:28:03.016Z DEBUG DTM Transport: Create receiver CMD with packet type: 0
2021-03-08T13:28:03.032Z DEBUG DTM Transport: Sending data: 0x54 0x04
2021-03-08T13:28:03.038Z DEBUG DTM Transport: Receiving data: 0x00 0x00

Fullscreen dtm_tx_min8dbm_2Mbit_2442MHz.txt Download

2021-03-08T13:15:35.015Z INFO Application data folder: /home/hkn/.config/nrfconnect/pc-nrfconnect-dtm
2021-03-08T13:15:35.107Z DEBUG App pc-nrfconnect-dtm v1.1.7 official
2021-03-08T13:15:35.108Z DEBUG App path: /home/hkn/.nrfconnect-apps/node_modules/pc-nrfconnect-dtm
2021-03-08T13:15:35.108Z DEBUG nRFConnect 3.6.1 is supported by the app (^3.2.0)
2021-03-08T13:15:35.108Z DEBUG nRFConnect path: /tmp/.mount_nrfcong25EQb/resources/app.asar
2021-03-08T13:15:35.108Z DEBUG HomeDir: /home/hkn
2021-03-08T13:15:35.108Z DEBUG TmpDir: /tmp
2021-03-08T13:15:35.887Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS0
2021-03-08T13:15:35.888Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS1
2021-03-08T13:15:35.888Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS10
2021-03-08T13:15:35.888Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS11
2021-03-08T13:15:35.888Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS12
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS13
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS14
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS15
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS16
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS17
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS18
2021-03-08T13:15:35.889Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS19
2021-03-08T13:15:35.890Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS2
2021-03-08T13:15:35.890Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS20
2021-03-08T13:15:35.890Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS21
2021-03-08T13:15:35.890Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS22
2021-03-08T13:15:35.890Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS23
2021-03-08T13:15:35.890Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS24
2021-03-08T13:15:35.891Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS25
2021-03-08T13:15:35.891Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS26
2021-03-08T13:15:35.891Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS27
2021-03-08T13:15:35.891Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS28
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS29
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS3
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS30
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS31
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS4
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS5
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS6
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS7
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS8
2021-03-08T13:15:35.892Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS9
2021-03-08T13:15:38.769Z INFO Validating firmware for device with s/n 000683340399
2021-03-08T13:15:40.925Z INFO Device selected successfully
2021-03-08T13:15:52.980Z INFO Running device setup
2021-03-08T13:15:52.980Z DEBUG DTM Transport: Create setup CMD with control: 0
2021-03-08T13:15:52.980Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-08T13:15:52.981Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:15:52.985Z DEBUG DTM Transport: Serialport is opened
2021-03-08T13:15:52.985Z DEBUG DTM Transport: Succeeded to open serialport
2021-03-08T13:15:52.986Z DEBUG DTM Transport: Sending data: 0x00 0x00
2021-03-08T13:15:52.995Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:15:52.995Z DEBUG DTM Transport: Create tx power CMD: 56
2021-03-08T13:15:52.995Z DEBUG DTM Transport: Sending data: 0xB8 0x0B
2021-03-08T13:15:53.003Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:15:53.003Z DEBUG DTM Transport: Create setup CMD with control: 1
2021-03-08T13:15:53.004Z DEBUG DTM Transport: Create setup CMD with parameter: 3
2021-03-08T13:15:53.004Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:15:53.004Z DEBUG DTM Transport: Sending data: 0x01 0x0C
2021-03-08T13:15:53.012Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:15:53.012Z DEBUG DTM Transport: Create setup CMD with control: 3
2021-03-08T13:15:53.012Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-08T13:15:53.012Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:15:53.013Z DEBUG DTM Transport: Sending data: 0x03 0x00
2021-03-08T13:15:53.020Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:15:53.020Z DEBUG DTM Transport: Create setup CMD with control: 2
2021-03-08T13:15:53.021Z DEBUG DTM Transport: Create setup CMD with parameter: 2
2021-03-08T13:15:53.021Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-08T13:15:53.021Z DEBUG DTM Transport: Sending data: 0x02 0x08
2021-03-08T13:15:53.027Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-08T13:15:53.028Z INFO Starting test
2021-03-08T13:15:53.029Z DEBUG DTM Transport: Create transmitter CMD with frequency: 2442
2021-03-08T13:15:53.030Z DEBUG DTM Transport: Create transmitter CMD with length: 63
2021-03-08T13:15:53.030Z DEBUG DTM Transport: Create transmitter CMD with packet type: 0
2021-03-08T13:15:53.044Z DEBUG DTM Transport: Sending data: 0x94 0xFC
2021-03-08T13:15:53.053Z DEBUG DTM Transport: Receiving data: 0x00 0x00

 

Could it be that you are parsing the data in the reverse byte order?

 

2) Any Idea why ending any test always returns the packet count as 0?

Have you checked that the devices enter its respective RX and TX mode? If you do not have a spectrum analyzer, you can look at the current consumption when the nRF enters RX or TX mode.

 

Kind regards,

Håkon 

[Alex Crombie]

Håkon Alseth said:

 Is there a specific reason for not using UART with DTM? How do you interface the nRF? Using a USB->I2C bridge?

The nRF chip is slaved to the CPU embedded in our product and it only has connectivity to the CPU via I2C, and the SWD interface for debug purposes. Thus the only way we can send DTM commands is from userspace in the CPU via I2C.

Håkon Alseth said:

Do you parse the response data from the DUT? Command-wise, this looks OK.

The I2C command structure is a very thin wrapper around the interface provided by ble_dtm:

dtm_cmd_t cmd = ((action->parameter >> 14) & 0x03);
dtm_freq_t freq = ((action->parameter >> 8) & 0x3f);
uint32_t length = ((action->parameter >> 2) & 0x3f);
dtm_pkt_type_t payload = (action->parameter & 0x3);
dtm_event_t evt;

SEGGER_RTT_printf( 0, "cmd: %u(0x%02x), freq: %u(0x%02x), length: %u(%02x), payload: %u(0x%02x)\n",
                   cmd, cmd,
                   freq, freq,
                   length, length,
                   payload, payload);

uint32_t ret = dtm_cmd(cmd, freq, length, payload);
mcu_ctrl_add_event_w_extra(EVT_DTM_COMMAND_RESULT, 0, (uint16_t)ret, clock_get_elapsed_ms());

if (dtm_event_get(&evt)) {
    mcu_ctrl_add_event_w_extra(EVT_DTM_EVENT, 0, (uint16_t)evt, clock_get_elapsed_ms());
}

In the above code snippet the `mcu_ctrl_add_event*()` functions push a bit of data up the I2C lines, in this case first the result then the dtm event.  The `action->parameter` is a 32bit value. We definitely know that the commands for TX are operating correctly (including constant tone mode) and have verified this with a spectrum analyser. 

The receiver test is run as follows, which I believe should be quite close to the python test runner in AN34:

# echo 0x0000 > $DTM && echo 0x010c > $DTM && echo 0x0208 > $DTM && echo 0x54fc > $DTM && sleep 1 && echo 0xc000 > $DTM
DTM Result: 0
DTM Event: 0
DTM Result: 0
DTM Event: 0
DTM Result: 0
DTM Event: 0
DTM Result: 0
DTM Event: 0
# DTM Result: 0
DTM Event: 32768

Within 1s I would expect 1600 packets to be received which should come nowhere close to overflowing the packet report.

Håkon Alseth said:

Have you checked that the devices enter its respective RX and TX mode? If you do not have a spectrum analyzer, you can look at the current consumption when the nRF enters RX or TX mode.

As mentioned above we have checked that the device enters TX. I will check the current consumption but is there a way to check if the device has entered RX mode correctly (from a software standpoint) or some other definitive way of knowing? 

As a comparison of your logs to what we are sending the TX is pretty much identical except in your logs the tx power is set first then the top 2 bits of the packet length.
In terms of the RX we don't explicitly set the TX power, and we don't explicitly set the modulation index also the receive packet length in the receive test is set to 1 rather than max as per the TX test. Should any of these have an affect on receiving packets?

Another thing I noticed is that the logs don't contain the results from the end of the test, are these reporting the correct numbers as well?

Alex

[Håkon Alseth]

Hi Alex,

  

Alex Crombie said:

The nRF chip is slaved to the CPU embedded in our product and it only has connectivity to the CPU via I2C, and the SWD interface for debug purposes. Thus the only way we can send DTM commands is from userspace in the CPU via I2C.

Understood. The translation layer looks to be minimalistic, so I assume there's little issues there.

 

Alex Crombie said:

We definitely know that the commands for TX are operating correctly (including constant tone mode) and have verified this with a spectrum analyser. 

 This is good. I assume then its the RX that is misbehaving.

Alex Crombie said:

As mentioned above we have checked that the device enters TX. I will check the current consumption but is there a way to check if the device has entered RX mode correctly (from a software standpoint) or some other definitive way of knowing? 

As a comparison of your logs to what we are sending the TX is pretty much identical except in your logs the tx power is set first then the top 2 bits of the packet length.

When the RADIO is in RX mode, you can read the register contents of the NRF_RADIO peripheral:

STATE: https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.nrf52832.ps.v1.1/radio.html?cp=4_2_0_22_13_24#register.STATE

MODE: https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.nrf52832.ps.v1.1/radio.html?cp=4_2_0_22_13_10#register.MODE 

FREQ: https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.nrf52832.ps.v1.1/radio.html?cp=4_2_0_22_13_8#register.FREQUENCY

 

.STATE will give you if its actually running RX mode, .MODE will give you the modulation, and .FREQUENCY gives you the listening channel (2400 + register-value) 

 

Alex Crombie said:

In terms of the RX we don't explicitly set the TX power, and we don't explicitly set the modulation index also the receive packet length in the receive test is set to 1 rather than max as per the TX test. Should any of these have an affect on receiving packets?

 This is not a problem. RX does not have a transmit function, or a "gain" setting. The things that are required is the modulation scheme (BLE 2MBIT for instance) and the listening frequency.

 

Alex Crombie said:

Another thing I noticed is that the logs don't contain the results from the end of the test, are these reporting the correct numbers as well?

My apologies, I didn't stop the test when providing logs. Here's the snippet that ends the test when 0 packets are received:

2021-03-09T12:00:10.229Z INFO Ending test
2021-03-09T12:00:10.231Z DEBUG DTM Transport: Create test end CMD
2021-03-09T12:00:10.231Z DEBUG DTM Transport: Sending data: 0xC0 0x00
2021-03-09T12:00:10.250Z DEBUG DTM Transport: Receiving data: 0x80 0x00
2021-03-09T12:00:10.255Z INFO Receiver test finished successfully. Received 0 packets. 

 

Here's a RX log on 2442MHz (BLE2MBIT), and successfully receiving ~4k packets :

2021-03-09T12:08:34.562Z INFO Running device setup
2021-03-09T12:08:34.562Z DEBUG DTM Transport: Create setup CMD with control: 0
2021-03-09T12:08:34.562Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-09T12:08:34.562Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-09T12:08:34.562Z DEBUG DTM Transport: Sending data: 0x00 0x00
2021-03-09T12:08:34.569Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-09T12:08:34.569Z DEBUG DTM Transport: Create tx power CMD: 0
2021-03-09T12:08:34.570Z DEBUG DTM Transport: Sending data: 0x80 0x0B
2021-03-09T12:08:34.575Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-09T12:08:34.576Z DEBUG DTM Transport: Create setup CMD with control: 1
2021-03-09T12:08:34.576Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-09T12:08:34.576Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-09T12:08:34.576Z DEBUG DTM Transport: Sending data: 0x01 0x00
2021-03-09T12:08:34.582Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-09T12:08:34.583Z DEBUG DTM Transport: Create setup CMD with control: 3
2021-03-09T12:08:34.583Z DEBUG DTM Transport: Create setup CMD with parameter: 0
2021-03-09T12:08:34.583Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-09T12:08:34.583Z DEBUG DTM Transport: Sending data: 0x03 0x00
2021-03-09T12:08:34.591Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-09T12:08:34.591Z DEBUG DTM Transport: Create setup CMD with control: 2
2021-03-09T12:08:34.591Z DEBUG DTM Transport: Create setup CMD with parameter: 2
2021-03-09T12:08:34.591Z DEBUG DTM Transport: Create setup CMD with dc type: 00
2021-03-09T12:08:34.592Z DEBUG DTM Transport: Sending data: 0x02 0x08
2021-03-09T12:08:34.598Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-09T12:08:34.598Z INFO Starting test
2021-03-09T12:08:34.608Z DEBUG DTM Transport: Create receiver CMD with frequency: 2442
2021-03-09T12:08:34.608Z DEBUG DTM Transport: Create receiver CMD with length: 1
2021-03-09T12:08:34.608Z DEBUG DTM Transport: Create receiver CMD with packet type: 0
2021-03-09T12:08:34.614Z DEBUG DTM Transport: Sending data: 0x54 0x04
2021-03-09T12:08:34.620Z DEBUG DTM Transport: Receiving data: 0x00 0x00
2021-03-09T12:08:37.520Z INFO Ending test
2021-03-09T12:08:37.520Z DEBUG DTM Transport: Create test end CMD
2021-03-09T12:08:37.520Z DEBUG DTM Transport: Sending data: 0xC0 0x00
2021-03-09T12:08:37.540Z DEBUG DTM Transport: Receiving data: 0x92 0x40
2021-03-09T12:08:37.544Z INFO Receiver test finished successfully. Received 4672 packets.

 

Which SDK version have you based your firmware on?

 

Kind regards,

Håkon

[Alex Crombie]

Håkon Alseth said:

Which SDK version have you based your firmware on?

We are using Version 15.0.0.

Håkon Alseth said:

STATE: https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.nrf52832.ps.v1.1/radio.html?cp=4_2_0_22_13_24#register.STATE

MODE: https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.nrf52832.ps.v1.1/radio.html?cp=4_2_0_22_13_10#register.MODE 

FREQ: https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.nrf52832.ps.v1.1/radio.html?cp=4_2_0_22_13_8#register.FREQUENCY

Thank you for this, I will check what values these returns.

One thing I have noticed when running the commands in the order given above and also the ones from the logs is that when setting the PHY in the transmit test (0x0208) it returns 4(DTM_ERROR_ILLEGAL_CONFIGURATION) from the dtm_cmd() function and the event is 1. I have added debugging to ensure that I am not somehow corrupting the commands, but all the values seem fine, so I am not sure how I am getting into this code path.

Using the logging in my previous reply for the command above i am getting:

cmd: 0(0x00), freq: 2(0x02), length: 2(02), payload: 0(0x00)

The logging added in ble_dtm.c

else if (freq == LE_TEST_SETUP_SET_PHY)
{
    SEGGER_RTT_printf(0, "PHY: 1M=%u, 2M=%u, CS8=%u, CS2=%u, actual=%u\n",
                      LE_PHY_1M, LE_PHY_2M, LE_PHY_LE_CODED_S8, LE_PHY_LE_CODED_S2,
                      length);

The result from this logging is pretty much as expected:

PHY: 1M=1, 2M=2, CS8=3, CS2=4, actual=2

Given that the length matches the 2M PHY interface the case for LE_PHY_2M performs an explicit return of radio_init(). It appears it must be something in the validation of the configuration

# echo 0x0208 > $DTM
# DTM Result: 4
DTM Event: 1

EDIT:

There appears to be a bug in the setting of the TX power first and then starting the radio in 2M mode:

Bitwise the power calculation is correct however the fact that it is assigned to a signed int8 causes the issues later when assigning it to m_tx_power:

int8_t new_power8 = (int8_t)(new_tx_power & 0xFF);

// The two most significant bits are not sent in the 6 bit field of the DTM command.
// These two bits are 1's if and only if the tx_power is a negative number.
// All valid negative values have the fourth most significant bit as 1.
// All valid positive values have the fourth most significant bit as 0.
// By checking this bit, the two most significant bits can be determined.
new_power8 = (new_power8 & 0x30) != 0 ? (new_power8 | 0xC0) : new_power8;
...
m_tx_power = new_power8;

m_tx_power is defined as an int32_t which would result in a negative tx power level (i.e -8 being 0xFFFFFFF8).

When dtm_radio_validate() is called with the signed value and attempts to perform a comparison with a valid power level it fails due to RADIO_TXPOWER_TXPOWER_Neg8dBm being defined as:

#define RADIO_TXPOWER_TXPOWER_Neg8dBm (0xF8UL) /*!< -8 dBm */

If m_tx_power were to have been masked to 0xFF this would have worked correctly

However even with that fix, the RX test is still not reporting any packets

EDIT 2: 

When logging the state of the radio, the transmitter seems to be doing sensible stuff while the test is enabled:

170000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
170500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
171500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
172000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
173000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
173500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
174500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
175000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
176000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
176500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
177500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
178000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
179000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
179500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
180500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
181000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
182000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
182500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
183500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
184000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
185000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
185500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
186500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
187000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
188000: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
188500: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248
189500: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 248
190000: Radio - STATE: 11, MODE: 4, FREQ: 42, TX POWER: 248

It appears to be alternating between between disabled and Transmitting. As the sampling on occurs when an event wakes the nRF up I am missing the ramp up stage for the TX. Interestingly it appears the TX state occurs once a second or so based on events waking the nRF device up.

For the RX the situation is very different:

cmd: 1(0x01), freq: 20(0x14), length: 1(01), payload: 0(0x00)
Ret: 0 Evt: 0
Radio - STATE: 1, MODE: 4, FREQ: 42, TX POWER: 0
152936: Radio - STATE: 1, MODE: 4, FREQ: 42, TX POWER: 0
152936: Radio - STATE: 3, MODE: 4, FREQ: 42, TX POWER: 0
152936: Radio - STATE: 3, MODE: 4, FREQ: 42, TX POWER: 0
152946: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152946: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152947: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152974: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152974: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
152975: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
...
153930: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
153930: Radio - STATE: 0, MODE: 4, FREQ: 42, TX POWER: 0
Ret: 0 Evt: 32768 <- 1 second has passed and the RX test terminated

It starts by going into the RX ramp up state and then stays in RX mode for a very short amount of time (I estimate this to be maybe ~12ms) before going to disabled for the remainder of the time

[Håkon Alseth]

Hi,

 

Alex Crombie said:

It appears to be alternating between between disabled and Transmitting. As the sampling on occurs when an event wakes the nRF up I am missing the ramp up stage for the TX. Interestingly it appears the TX state occurs once a second or so based on events waking the nRF device up.

This is expected. The DTM protocol states that each slot should be setup in a n*625 (n=1..4, based on payload length). When the transmission is finished, it will return to idle state and await for the next slot to occur. 

 

Alex Crombie said:

It starts by going into the RX ramp up state and then stays in RX mode for a very short amount of time (I estimate this to be maybe ~12ms) before going to disabled for the remainder of the time

The receiver should work similar as the TX part, meaning that it should be disabled upon valid NRF_RADIO->EVENTS_END event, and restart the RX again in the function "dtm_wait()". Very strange that it does not restart into RX mode here.

 

Alex Crombie said:

There appears to be a bug in the setting of the TX power first and then starting the radio in 2M mode:

If you update to a newer ble_dtm, the power-setting bug should be fixed.

This bug should not affect the RX test.

 

Alex Crombie said:

It starts by going into the RX ramp up state and then stays in RX mode for a very short amount of time (I estimate this to be maybe ~12ms) before going to disabled for the remainder of the time

 Could you try with another test setup, for instance: channel 2440, 1MBit, 37 bytes payload length?

 

Kind regards,

Håkon