Time required to send a mesh message from client to server

[Mela]

Hi,

I am using two nrf52840 boards and a Light-Switch example included in the mesh SDK_v5.0. I would like to measure the time required to send a message from client to server. I have enabled logging via RTT for example to see when the message gets sent from the client and when the client gets the ACK from the server.

In the Debug Terminal area I see for example:

 

<t:   14650346>, access.c,  425, TX: [aop: 0x8202]
<t:   14650348>, access.c,  426, TX: Msg: 82020013010A
<t:   14651927>, access.c,  253, RX: [aop: 0x8204]
<t:   14651929>, access.c,  276, RX: Msg: 010001
<t:   14651933>, main.c,  171, Acknowledged transfer success.
<t:   14651935>, main.c,  196, OnOff server: 0x0006, Present OnOff: 1, Target OnOff: 0, Remaining Time: 100 ms

 

I am now confused with those timestamps. Is there s waý to convert it to a human readable format? My goal is to calculate Round Trip Delay in seconds.

I tried to see if it was a UNIX timestamp by converting it online but the value return June 19, 1970 some:time

Best regards,

Mela

[Hung Bui]

Hi Mela, 

If you have a look into the log.h you can find this: 

/**
 * Prints a log message.
 * @param[in] source Log source
 * @param[in] level  Log level
 * @param[in] ...    Arguments passed on to the callback (similar to @c printf)
 */
#define __LOG(source, level, ...)                                       \
    if ((source & g_log_dbg_msk) && level <= g_log_dbg_lvl)             \
    {                                                                   \
        log_printf(level, __FILENAME__, __LINE__, log_timestamp_get(), __VA_ARGS__); \
    }

And this: 

static inline uint32_t log_timestamp_get(void)
{
#if defined(HOST)
    #if defined(__linux__)
        struct timespec now;
        clock_gettime(CLOCK_REALTIME, &now);
        return (now.tv_sec * 1000000UL) + (now.tv_nsec / 1000UL);
    #else
        return 0;
    #endif
#else
    return NRF_RTC1->COUNTER;
#endif
}

So what you see in the log is the RTC's counter. And RTC1 by default is initialized with prescaler = 0. so the frequency is 32.768kHz. 
So each second this counter counts 32768 unit. 
Use this you can do calculation and can convert it to second and minute etc. But note that the counter is 24 bits, so it wraps around every 512 seconds. You would need to use some more variable to count if you want to count minutes and hours etc. It's up to you to modify the log_timestamp_get() function to add more info. 

[Mela]

Thanks for the quick reply and for your help, much appreciated.