Time taken by a code snippet

[Sai Kiran]

Hi

I want to know the time taken(in us) by a code snippet. I had a look at app_timer functionality with the help of this post. But the timer value always shows 0. I am not sure on how to create a dummy timer. Can someone help me with this? Also which is more accurate, RTC or APP_TIMER?

Thanks in advance.

-Sai Kiran

[Edvin]

Hello Sai Kiran,

 

Also which is more accurate, RTC or APP_TIMER?

 The app_timer uses the RTC, So they should be equally accurate, but it depends on how you use it. 

The easiest way to measure how long something takes is to toggle a pin before and after that piece of code, and then use a logic analyzer to measure how long the pin was high/low. 

Secondly, if you want to measure in µs how long something takes, I recommend that you use a TIMER, instead of the RTC (the app_timer uses the RTC). The difference is that the timers can run on 32MHz, while the RTC is running on the 32kHz clock, giving you a resolution of ~30µs. 

If you do not have a logic analyzer, you can try something like this:

void timer_init()
{
    NRF_TIMER3->BITMODE                 = TIMER_BITMODE_BITMODE_32Bit << TIMER_BITMODE_BITMODE_Pos;
    NRF_TIMER3->PRESCALER               = 4; // will give 1tick/µs
    NRF_TIMER3->SHORTS                  = TIMER_SHORTS_COMPARE0_CLEAR_Disabled << TIMER_RELOAD_CC_NUM;
    NRF_TIMER3->MODE                    = TIMER_MODE_MODE_Timer << TIMER_MODE_MODE_Pos;
    
    
    TIMER3->TASKS_START = 1;
}

Call this some time before you want to measure what you will measure, because the timer uses some time to start up the XTAL. 

Then, when you want to measure, you need to capture two timestamps:

NRF_TIMER3->TASKS_CAPTURE[0];
do_tasks_I_want_to_time();
NRF_TIMER3->TASKS_CAPTURE[1];

uint32_t diff_time = NRF_TIMER3->CC[1] - NRF_TIMER3->CC[0];

// diff_time should hold the time different in µs. NB: If this took more than 2^32 µs, 
// you will not know whether or not the timer has rolled over, or how many times. 
// As long as you use the timer in 32bit mode, it shouldn't matter if the timer's counter
// register has ticked from 0xFFFFFFFF to 0x0000000, as long as you take the diff_time
// = CC[1] - CC[0]

Best regards,

Edvin

[Sai Kiran]

I have tried the code you have posted. Modified a couple of things as there were some issues while compiling. Here is my code.

 void timer_init()
{
    NRF_TIMER3->BITMODE                 = TIMER_BITMODE_BITMODE_32Bit << TIMER_BITMODE_BITMODE_Pos;
    NRF_TIMER3->PRESCALER               = 4; // will give 1tick/µs
    NRF_TIMER3->SHORTS                  = TIMER_SHORTS_COMPARE0_CLEAR_Disabled << TIMER3_CC_NUM;
    NRF_TIMER3->MODE                    = TIMER_MODE_MODE_Timer << TIMER_MODE_MODE_Pos;
    
    NRF_TIMER3->TASKS_START = 1;
}

int main(void)
{
    timer_init();
    NRF_TIMER3->TASKS_CAPTURE[0];
    my_function();
    NRF_TIMER3->TASKS_CAPTURE[1];
    uint32_t diff_time = NRF_TIMER3->CC[1] - NRF_TIMER3->CC[0];
    NRF_LOG_INFO("Time taken: %d", diff_time);
}

I get "Time taken: 0". Any idea what's happening? Something to do with sdk_config.h?

[Edvin]

It takes some time to actually start the timer. Can you try:

timer_init();
nrf_delay_ms(100);
NRF_TIMER3->TASKS_CAPTURE[0];
my_function();
NRF_TIMER3->TASKS_CAPTURE[1];
uint32_t diff_time = NRF_TIMER3->CC[1] - NRF_TIMER3->CC[0];
NRF_LOG_INFO("Time taken: %d", diff_time);
NRF_LOG_INFO("CC[0]: %08x, CC[1]: %08x", NRF_TIMER3->CC[0], NRF_TIMER3->CC[1]);

You also need to include "nrf_delay.h" in order to use the nrf_delay_ms function.

What does the log say now?

Are you actually getting this printed in your log, or are you debugging to see what diff_time is? If you are debugging, have you remembered to turn off the optimization?

Best regards,

Edvin

[Sai Kiran]

I have put delay. I am printing in the log. I still get 0 as output. This is the code I have used.

    timer_init();
    nrf_delay_ms(100);
    NRF_TIMER3->TASKS_CAPTURE[0];
    nrf_delay_us(100);
    my_function();
    NRF_TIMER3->TASKS_CAPTURE[1];
    float diff_time = (float)NRF_TIMER3->CC[1] - (float)NRF_TIMER3->CC[0];
    NRF_LOG_INFO("CC[0]: %08x, CC[1]: %08x", NRF_TIMER3->CC[0], NRF_TIMER3->CC[1]);
    NRF_LOG_INFO("Time in us: " NRF_LOG_FLOAT_MARKER "\r\n",  NRF_LOG_FLOAT(diff_time));

[Edvin]

Sorry. I wrote that code without testing it. I was missed the part that the tasks has to be set to 1 (like the NRF_TIMER3->TASKS_START = 1;)

Try the following:

void timer_init(void)
{
    NRF_TIMER3->BITMODE         = TIMER_BITMODE_BITMODE_32Bit << TIMER_BITMODE_BITMODE_Pos;
    NRF_TIMER3->PRESCALER       = 4;
    NRF_TIMER3->SHORTS          = TIMER_SHORTS_COMPARE0_CLEAR_Disabled << TIMER3_CC_NUM;
    NRF_TIMER3->MODE            = TIMER_MODE_MODE_Timer << TIMER_MODE_MODE_Pos;
    
    NRF_TIMER3->TASKS_START = 1;
}

int main(void)
{
    bsp_board_init(BSP_INIT_LEDS);

    APP_ERROR_CHECK(NRF_LOG_INIT(NULL));
    NRF_LOG_DEFAULT_BACKENDS_INIT();
    
    timer_init();
    
    NRF_LOG_INFO("test");
    while (1)
    {
        bsp_board_led_invert(0);
        NRF_TIMER3->TASKS_CAPTURE[0] = 1;
        nrf_delay_ms(1000);
        NRF_TIMER3->TASKS_CAPTURE[1] = 1;
        NRF_LOG_INFO("diff_time: %08d µs", (NRF_TIMER3->CC[1] - NRF_TIMER3->CC[0]));
        
        NRF_LOG_FLUSH();
        __WFE();
    }
}

BR,

Edvin