timestamp and TSC profiling results are different

gaotai zhang

Other Parts Discussed in Thread: SYSBIOS

I'm profiling some code on C6678 using both timestamp provided by SYS/BIOS and the TSCH TSCL timer registers. The strange thing is, the results produced by these two methods are different. Generally, the CPU cycle count provided by timestamp is 4 times that of timer registers and varies each time I do a new profile. The frequency returned by calling Timestamp_getFreq() is 1GHZ which is what I configured. I don't know why the cycle count produced by timestamp is bigger ?

over 13 years ago

0 Karl Wechsler over 13 years ago

TI__Mastermind 20805 points

Hi Gaotai --

Can you please attach some code that illustrates the problem? The Timestamp_get32() API internally just reads the TSCL register. Timestamp_get32() calls the 6x-specific function to get the timestamp(). I don't see how one could be 4x the other.

/*
* ======== TimestampProvider_get32 ========
*/
Bits32 TimestampProvider_get32()
{
return (TSCL);
}

Thanks,
-Karl-

0 Karl Wechsler over 13 years ago in reply to Karl Wechsler

TI__Mastermind 20805 points

Someone here had another idea.

Are you benchmarking a very small piece of code? If so, the function call overhead of Timestamp_get32() might be to blame for the delta.

For our benchmarks, we call Timestamp_get32() back-to-back and compute the overhead. And then subtract this overhead from the measurement. See below for example.

#include <xdc/std.h>
#include <xdc/runtime/System.h>
#include <xdc/runtime/Timestamp.h>

#include <ti/sysbios/BIOS.h>
#include <ti/sysbios/knl/Clock.h>
#include <ti/sysbios/knl/Task.h>
#include <ti/sysbios/knl/Semaphore.h>

#include <xdc/cfg/global.h>

Void task1(UArg arg0, UArg arg1);
Void task2(UArg arg0, UArg arg1);

Semaphore_Handle sem;
Task_Handle tsk1;
Task_Handle tsk2;

#define NSAMPLES 10

UInt32 t0, t1;
UInt32 overhead;
UInt32 deltas[NSAMPLES];

/*
* ======== main ========
*/
Void main()
{
    Task_Params taskParams;

    /* Create a Semaphore object to be use as a resource lock */
    sem = Semaphore_create(0, NULL, NULL);

    /* Create two tasks that share a resource*/
    Task_Params_init(&taskParams);
    taskParams.priority = 1;
    taskParams.arg0 = 0;
    taskParams.arg1 = 1;
    tsk1 = Task_create (task1, &taskParams, NULL);

    Task_Params_init(&taskParams);
    taskParams.priority = 2;
    tsk2 = Task_create (task2, &taskParams, NULL);

    BIOS_start();
}

/*
* ======== task2 ========
*/
Void task2(UArg arg0, UArg arg1)
{
    Int i;

    System_printf("Running task1 function\n");

    /* compute the overhead of Timestamp module so we can subtract it from our measurements */
    t0 = Timestamp_get32();
    t1 = Timestamp_get32();
    overhead = t1 - t0;

    for (i=0; i < NSAMPLES; i++) {
        Semaphore_pend(sem, BIOS_WAIT_FOREVER);

        t1 = Timestamp_get32();

        deltas[i] = t1 - t0 - overhead;
    }

    BIOS_exit(0);
}

/*
* ======== task1 ========
*/
Void task1(UArg arg0, UArg arg1)
{
    System_printf("Running task1 function\n");

    for (;;) {
        t0 = Timestamp_get32();

        Semaphore_post(sem);
    }
}

-Karl-

0 gaotai zhang over 13 years ago in reply to Karl Wechsler

Intellectual 415 points

Karl,

It turns out that I use Timestamp_get32() and TSC to test two same blocks in a sequential manner. Unfortunately, the test block involves reading operation from external memory, the TSC test gets a smaller result only because the data is cached. I correct my code and the two test methods give the same results because ,as you said ,the Timestamp just read from TSC.

Thanks,

Roy

Processors

Processors forum

timestamp and TSC profiling results are different