sd_ecb_block_encrypt() execution time

Question

We have a custom protocol with strict deadlines in the radio stack between receiving a packet, decrypting it, processing encrypting an ack and send the ack. 
 For that reason, we have strict deadlines on sd_ecb_block_encrypt(), and it seems to work for every case, except now one.

In this case, we are running: 
 - nrf52840 
 - Softdevice s140 v7.2.0 
 - nrf5-sdk 17.0.2 
 - FreeRTOS 10.0.0, the version shipped with nrf5-sdk 
 Our setup runs all radio code from the radio interrupt in an allocated radio slot, and thus on priority 0. Except the calls to softdevice, in which we trigger an SWI and drops to interrupt priority 5 for that call, and has the deadline specified on a TIMER0 compare. If we miss the deadline, then we log and retries later. Otherwise, we don't have any other interrupts during that period 
 I have measured that the call to sd_ecb_block_encrypt() and a block copy takes 15.8us in every case we have without running FreeRTOS, or when using that version of FreeRTOS while connected to a debugger, but in running state. But when disconnecting the debugger and reset the CPU, many of those calls starts 26.8us each, in a rate so we miss the deadline when sending bigger packets. 
 Also have a version where we upgraded FreeRTOS to a later version, and the issue seems to be gone. 
 We are not running any concurrent bluetooth, or having any other code using the encyrption. 
 To measure it, I'm using a saleae logic analyzer and pull a pin low just before the call, and high afterwards, to be able to measure timings without debugger/trace. I can't really find a pattern for it, but it seems to affect when running multiple in a row. Note: In the plot low signal means call to sd_ecb_block_encrypt() 
 I would have preferred to provide more steps to reproduce for this issue, but by the nature of not being able to track any pattern or being able to look at it with a debugger make it lot harder. But feeling uncomfortable without knowing the reason for this issue, since we don't know when it will appear or how to get around it. And thus lost in what to test 
 So what could make sd_ecb_block_encrypt() increase in execution time when not having debugger connected?

Susheel Nuguru · Accepted Answer

I know that there was a fix inside sd_ecb_block_encrypt applied in S140v7.2.0 to solve a power consumption issue which is relevant when we use SEVONPEND bit. The inclusion of this fix seems to have another side affect of wakeup time being longer in many cases. I see that this fix inside the sd_ecb_block_encrypt is removed later in our repo was not being released in nRF5 SDK.

I think you can have a workaround to temporarily disable the SEVONPEND while requesting to block encrypt, something like below.

void ENCRYPT_IRQHandler(
    void)
{
    int i;
    ENCRYPT_GPIO_PORT->OUTSET = 1 << ENCRYPT_GPIO_TRIG_PIN;
    for (i = 0; i < 20; i++) {
        /* Just fill with something */
        memset(&ecb_buf, i, sizeof(nrf_ecb_hal_data_t));

        /* Disable temporarily */
        SCB->SCR &= ~SCB_SCR_SEVONPEND_Msk;

        ENCRYPT_GPIO_PORT->OUTSET = 1 << ENCRYPT_GPIO_ENC_PIN;
        sd_ecb_block_encrypt(&ecb_buf);
        ENCRYPT_GPIO_PORT->OUTCLR = 1 << ENCRYPT_GPIO_ENC_PIN;

        /* Re-enable */
        SCB->SCR |= SCB_SCR_SEVONPEND_Msk;
    }
    ENCRYPT_GPIO_PORT->OUTCLR = 1 << ENCRYPT_GPIO_TRIG_PIN;
}

I have tested this on my end and it seems to work. Can you please test the above changes of code in your vendor\nRF5_SDK_17.0.2_d674dde\examples\peripheral\freertos-nrf-encrypt-timings-main\src\encrypt.c

sd_ecb_block_encrypt() execution time

Top Replies