This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

CCS/AM6548: R5F interrupt jitter

Part Number: AM6548
Other Parts Discussed in Thread: SYSBIOS,

Tool/software: Code Composer Studio

Hello,

Environment:

  • Hardware: AM65x EVM board
  • Software: minimal example code with SYS/BIOS w/ modification (the code is attached below)

We have conducted a experiment measuring the interrupt jitter on the R5F which runs TI-RTOS. We ran the measurement for over 15 hours and the results shows the jitter is around 3.83us. We are wondering if this number is reasonable? Or is there any way to lower the jitter?

The following are the code and cfg :

/*
 *  ======== main.c ========
 */

#include <xdc/std.h>

#include <xdc/runtime/System.h>
#include <xdc/runtime/Error.h>
#include <xdc/runtime/Timestamp.h>
#include <xdc/runtime/Types.h>

#include <ti/sysbios/BIOS.h>
#include <ti/sysbios/knl/Task.h>
#include <ti/sysbios/hal/Timer.h>
#include <ti/sysbios/hal/Hwi.h>

Int myHookSetId1, myHookSetId2;
volatile Bool myEnd2Flag = FALSE;
extern Timer_Handle myTimer;
volatile unsigned int *CTRLMMR_PADCONFIG192 = (volatile unsigned int *)0x11C300;
volatile unsigned int *CTRLMMR_LOCK7_KICK0 = (volatile unsigned int *)0x11D008;
volatile unsigned int *CTRLMMR_LOCK7_KICK1 = (volatile unsigned int *)0x11D00C;
volatile unsigned int *GPIO_DIR45 = (volatile unsigned int *)0x601060;
volatile unsigned int *GPIO_OUT_DATA45 = (volatile unsigned int *)0x601064;
volatile unsigned int *GPIO_SET_DATA45 = (volatile unsigned int *)0x601068;
volatile unsigned int *GPIO_CLR_DATA45 = (volatile unsigned int *)0x60106C;

#if 0
Void myRegister1(Int hookSetId)
{
    System_printf("myRegister1: assigned hookSet Id = %d\n", hookSetId);
    myHookSetId1 = hookSetId;
}

/* ======== myCreate1 ========
 * invoked during Hwi module startup before main()
 * for statically created Hwis */
Void myCreate1(Hwi_Handle hwi, Error_Block *eb)
{
    Ptr pEnv;
    pEnv = Hwi_getHookContext(hwi, myHookSetId1);
    /* pEnv should be 0 at this point. If not, there's a bug. */
    System_printf("myCreate1: pEnv = 0x%x, time = %d\n", pEnv,
                  Timestamp_get32());
    Hwi_setHookContext(hwi, myHookSetId1, (Ptr) 0xdead1);
}

/* ======== myBegin1 ========
 * invoked before Timer Hwi func */
Void myBegin1(Hwi_Handle hwi)
{
    //Ptr pEnv;
    //pEnv = Hwi_getHookContext(hwi, myHookSetId1);
    System_printf("myBegin1: time = %d\n", Timestamp_get32());
    //Hwi_setHookContext(hwi, myHookSetId1, (Ptr) 0xbeef1);
}

/* ======== myEnd1 ========
 * invoked after Timer Hwi func */
Void myEnd1(Hwi_Handle hwi)
{
    //Ptr pEnv;
    //pEnv = Hwi_getHookContext(hwi, myHookSetId1);
    System_printf("myEnd1: time = %d\n", Timestamp_get32());
    //Hwi_setHookContext(hwi, myHookSetId1, (Ptr) 0xc0de1);
}
#endif

unsigned int last = 0, now = 0;
unsigned int mindelta = 0xFFFFFFFF;
unsigned int maxdelta = 0;
unsigned int avgdelta = 0;
unsigned int delta = 0;
unsigned long long count = 0;
unsigned long long overcount = 0;
unsigned long long overcount_ts = 0;
unsigned long long undercount = 0;
unsigned long long undercount_ts = 0;
unsigned int firstdelta = 0;
//volatile unsigned int *buffer = (volatile unsigned int*);

Void myTimerFunc(UArg arg)
{
    //System_printf("Entering myTimerHwi at %d\n", Timestamp_get32());

    if (0 == last)
    {
        last = Timestamp_get32();
    }
    else
    {
        now = Timestamp_get32();
        delta = now - last;
        last = now;

        if (delta > maxdelta)
        {
            if (count != 0)
            maxdelta = delta;
        }

        if (delta < mindelta)
            mindelta = delta;

        avgdelta = (avgdelta * count + delta) / (count+1);

        if (delta > 50400)
        {
            if (count == 0)
            {
                firstdelta = delta;
            }
            else
            {
                overcount++;
                overcount_ts = count;
            }
        }

        if (delta < 49600)
        {
            undercount++;
            undercount_ts = count;
        }

        count++;

        *CTRLMMR_LOCK7_KICK0 = 0x68EF3490;
        *CTRLMMR_LOCK7_KICK1 = 0xD172BC5A;
        *CTRLMMR_PADCONFIG192 = 0x8000007;
        *GPIO_DIR45 = 0xFEFFFFFF;

        if (*GPIO_OUT_DATA45 == 0)
            *GPIO_SET_DATA45 = 0x1000000;
        else
            *GPIO_CLR_DATA45 = 0x1000000;
    }
}

double aaa = 0.1;
double bbb = 0.2;
double ccc = 0.3;
double ddd = 0.4;

/*
 *  ======== taskFxn ========
 */
Void taskFxn(UArg a0, UArg a1)
{
    System_printf("enter taskFxn()\n");

	
    Timer_start(myTimer);

    while (1)
    {
        //Task_sleep(100);
        aaa = aaa + bbb * ccc / ddd;
    }

    //Task_sleep(10);

    System_printf("exit taskFxn()\n");
}

Void taskFxn1(UArg a0, UArg a1)
{
    System_printf("enter taskFxn1()\n");

    while (!myEnd2Flag) ;

    System_printf("exit taskFxn1()\n");
}


/*
 *  ======== main ========
 */

Int main()
{ 
    /*
     * use ROV->SysMin to view the characters in the circular buffer
     */
    System_printf("enter main()\n");

    BIOS_start();    /* does not return */
    return(0);
}
var Defaults = xdc.useModule('xdc.runtime.Defaults');
var Diags = xdc.useModule('xdc.runtime.Diags');
var Error = xdc.useModule('xdc.runtime.Error');
var Log = xdc.useModule('xdc.runtime.Log');
var LoggerBuf = xdc.useModule('xdc.runtime.LoggerBuf');
var Main = xdc.useModule('xdc.runtime.Main');
var SysMin = xdc.useModule('xdc.runtime.SysMin');
var System = xdc.useModule('xdc.runtime.System');
var Text = xdc.useModule('xdc.runtime.Text');

var BIOS = xdc.useModule('ti.sysbios.BIOS');
var Hwi = xdc.useModule('ti.sysbios.hal.Hwi');
var Task = xdc.useModule('ti.sysbios.knl.Task');

/*
 * Uncomment this line to globally disable Asserts.
 * All modules inherit the default from the 'Defaults' module.  You
 * can override these defaults on a per-module basis using Module.common$.
 * Disabling Asserts will save code space and improve runtime performance.
Defaults.common$.diags_ASSERT = Diags.ALWAYS_OFF;
 */

/*
 * Uncomment this line to keep module names from being loaded on the target.
 * The module name strings are placed in the .const section. Setting this
 * parameter to false will save space in the .const section.  Error and
 * Assert messages will contain an "unknown module" prefix instead
 * of the actual module name.
 */
Defaults.common$.namedModule = false;

/*
 * Minimize exit handler array in System.  The System module includes
 * an array of functions that are registered with System_atexit() to be
 * called by System_exit().
 */
System.maxAtexitHandlers = 4;

/*
 * Uncomment this line to disable the Error print function.
 * We lose error information when this is disabled since the errors are
 * not printed.  Disabling the raiseHook will save some code space if
 * your app is not using System_printf() since the Error_print() function
 * calls System_printf().
Error.raiseHook = null;
 */

/*
 * Uncomment this line to keep Error, Assert, and Log strings from being
 * loaded on the target.  These strings are placed in the .const section.
 * Setting this parameter to false will save space in the .const section.
 * Error, Assert and Log message will print raw ids and args instead of
 * a formatted message.
 */
Text.isLoaded = false;

/*
 * Uncomment this line to disable the output of characters by SysMin
 * when the program exits.  SysMin writes characters to a circular buffer.
 * This buffer can be viewed using the SysMin Output view in ROV.
 */
SysMin.flushAtExit = false;

/*
 * The BIOS module will create the default heap for the system.
 * Specify the size of this default heap.
 */
BIOS.heapSize = 0x0;

/* System stack size (used by ISRs and Swis) */
Program.stack = 0x400;

/* Circular buffer size for System_printf() */
SysMin.bufSize = 128;

/*
 * Create and install logger for the whole system
 */
var loggerBufParams = new LoggerBuf.Params();
loggerBufParams.numEntries = 4;
var logger0 = LoggerBuf.create(loggerBufParams);
Defaults.common$.logger = logger0;
Main.common$.diags_INFO = Diags.ALWAYS_ON;

System.SupportProxy = SysMin;

/*
 * Build a custom BIOS library.  The custom library will be smaller than the
 * pre-built "instrumented" (default) and "non-instrumented" libraries.
 *
 * The BIOS.logsEnabled parameter specifies whether the Logging is enabled
 * within BIOS for this custom build.  These logs are used by the RTA and
 * UIA analysis tools.
 *
 * The BIOS.assertsEnabled parameter specifies whether BIOS code will
 * include Assert() checks.  Setting this parameter to 'false' will generate
 * smaller and faster code, but having asserts enabled is recommended for
 * early development as the Assert() checks will catch lots of programming
 * errors (invalid parameters, etc.)
 */
BIOS.libType = BIOS.LibType_Custom;
BIOS.logsEnabled = false;
BIOS.assertsEnabled = true;
 
/*
 * Create a task.  The 'taskFxn' function can be found in main.c.
 */
var task0Params = new Task.Params();
var task0 = Task.create("&taskFxn", task0Params);

//var task1Params = new Task.Params();
//var task1 = Task.create("&taskFxn1", task1Params);

xdc.loadCapsule("r5_mpu.xs");

var Timer = xdc.useModule('ti.sysbios.hal.Timer');
var timerParams = new Timer.Params();
timerParams.startMode = Timer.StartMode_USER;
timerParams.runMode = Timer.RunMode_CONTINUOUS; //Timer.RunMode_ONESHOT;
timerParams.period = 125; // 1ms
Program.global.myTimer = Timer.create(Timer.ANY, "&myTimerFunc", timerParams);

BIOS.clockEnabled = false;

/* Hook Set 1 */
Hwi.addHookSet({
registerFxn: '&myRegister1',
createFxn: '&myCreate1',
beginFxn: '&myBegin1',
endFxn: '&myEnd1',
});

 

  • Hi Hungwei,

    I have several questions for you:

    • Which SYS/BIOS version are you using?
    • Where is code/data placed in memory (ATCM, BTCM, OCMRAM, MSMC, DDR)?
    • For your time stamp delta, have you subtracted the overhead associated with reading the timer?
    • Have you confirmed the R5F frequency set at 400 MHz?
    • Would it be possible for you to share your complete profiling application (linker command file, CCS or make file, etc.)?

    I suggest you use the PMU for profiling on R5F since the results will be in CPU cycles. Please see CSL source code in these files:

    • pdk_am65xx_1_0_6\packages\ti\csl\arch\r5\csl_arm_r5_pmu.h
    • pdk_am65xx_1_0_6\packages\ti\csl\arch\r5\src\csl_arm_r5_pmu.asm

    You can use the "wrapper" functions below.

    void init_profiling(void)
    {
        CSL_armR5PmuEnableAllCntrs(1);  /* Set/clear PMCR E-bit */
        CSL_armR5PmuResetCntrs();       /* Set PMCR P-bit */
        CSL_armR5PmuResetCycleCnt();    /* Set PMCR C-bit */
        CSL_armR5PmuEnableCntr(CSL_ARM_R5_PMU_CYCLE_COUNTER_NUM, 1);    /* Set PMCNTENSET for event */
        CSL_armR5PmuClearCntrOverflowStatus(0x80000007);
    }
    
    uint32_t readPmu(void)
    {
        return (CSL_armR5PmuReadCntr(0x1F));
    }

    There are existing SYS/BIOS timing benchmarks for AM65xx:R5F. Please see these docs:

    • bios_6_76_02_02/docs/Bios_User_Guide.pdf, Appendix B:Timing Benchmarks
    • bios_6_76_02_02/packages/ti/sysbios/benchmarks/doc-files/TI_R5F_ti_platforms_cortexR_AM65X_time.html

    The worst-case time from an event occurrence to when the user C function is called for an ISR is the sum of "Interrupt Latency" + "HWI dispatch prolog". From TI_R5F_ti_platforms_cortexR_AM65X_time.html:

    • Interrupt Latency: 238
    • Hwi dispatcher prolog: 199
    • (238+199)/400e6*1e6 = 1.0925 usec.

    The SYS/BIOS benchmark application is provided in the SYS/BIOS release. Please follow these steps in CCS to import the project:

    • File->New->CCS Project
    • Target: AM6548, Select Cortex R [ARM]
    • Under "Project template and examples", expand SYS/BIOS, More Examples... Click "Search using Import Wizard..."
    • Select "benchmark" application.

    You can compile the CCS project with the Debug build configuration, and then load / execute the build on R5F0.

    Regards,
    Frank

  • Hello,

    Responses to your questions:

    • Which SYS/BIOS version are you using?
      • bios_6_76_02_02
    • Where is code/data placed in memory (ATCM, BTCM, OCMRAM, MSMC, DDR)?
      • OCMRAM
    • For your time stamp delta, have you subtracted the overhead associated with reading the timer?
      • No. Would reading the MCU_TIMER contribute some jitter?
    • Have you confirmed the R5F frequency set at 400 MHz?
      • Yes. It is 400Mhz by checking with Clock Tree Tool.
    • Would it be possible for you to share your complete profiling application (linker command file, CCS or make file, etc.)?

    >I suggest you use the PMU for profiling on R5F since the results will be in CPU cycles.

    Is there any differences between PMU and Timestamp_get32() when it comes to measure CPU cycle? I thought the unit of Timestamp_get32() is CPU cycles!?

    >Interrupt Latency: 238
    >Hwi dispatcher prolog: 199
    >(238+199)/400e6*1e6 = 1.0925 usec.

    Do you mean interrupt latency could be 0 ~ 238 and Hwi dispatcher prolog could be 0 ~ 199? Is it possible to optimize these two values by higher CPU clock or other ways?

  • hungwei yang said:
    Is there any differences between PMU and Timestamp_get32() when it comes to measure CPU cycle? I thought the unit of Timestamp_get32() is CPU cycles!?

    The timestamp provider for the R5f is the PMU, so you're already using that.

    hungwei yang said:
    Do you mean interrupt latency could be 0 ~ 238 and Hwi dispatcher prolog could be 0 ~ 199? Is it possible to optimize these two values by higher CPU clock or other ways?

    I believe the numbers Frank posted are cycle counts, taken from "bios_6_76_02_02/packages/ti/sysbios/benchmarks/doc-files/TI_R5F_ti_platforms_cortexR_AM65X_time.html".

    These numbers are only valid if you're able to execute all of your interrupt handler with zero waitstates, i.e. either fully cached or from TCM.

    hungwei yang said:
    Where is code/data placed in memory (ATCM, BTCM, OCMRAM, MSMC, DDR)?
    • OCMRAM

    Reading from OCMRAM takes the R5f ~34 cycles (see https://e2e.ti.com/support/processors/f/791/t/840395). Even with caches enabled you'll end up stalling the processor quite often. If a minimal interrupt latency is important to you, you should consider moving all critical parts of your application to TCM.

    Regards,

    Dominic

  • Part Number: AM6548

    Tool/software: Code Composer Studio

    Hello,

    Environment:

    • Hardware: AM65x IDK
    • Software: ti-processor-sdk-rtos-am65xx-evm-06_01_00_08

    We have conducted the same experiment in this post without TI-RTOS. This time we took your advice and put everything inside TCMA and TCMB.

    The experiment is like:

    1. we utilize the example code <PDK>\packages\ti\csl\test\dmTimerUt\
    2. and create a timer which generates interrupts every 125us
    3. get CPU tick returned by CSL_armR5PmuReadCntr() in the beginning of the Timer ISR
    4. calculate the difference time between every two interrupts

    The theoretical value of the difference time should be 125us; however, after running the program for one hour we get the min value is 124.035 us and max value is 126.045 us which shows the jitter is around 2.01 (126.045 - 124.035) us.

    Are the numbers reasonable? Or is there anything I understand or configure wrong?

    The source code:

    2474.dmTimerUt.zip

    The linker file:

    linker_r5.zip

  • Hello,

    We have conducted the same experiment without TI-RTOS in this post. We took your advice and put everything in TCM. Please take a look.

  • Hi Hungwei,

    The link you shared seems broken. Can you please share it again?

    Thanks,
    Frank

  • Hi Hungwei,

    I now have access to the other E2E thread regarding the bare-metal R5F interrupt timing.

    Regards,
    Frank

  • Hi Hungwei,

    I'll try to reproduce your results, and see if I obtain the same results using SYS/BIOS 6.76.04.02 (I believe this is the SYS/BIOS version containing the VIM/VIC hardware workaround mentioned by Dominic here: https://e2e.ti.com/support/processors/f/791/p/878856/3276542#3276542).

    Regards,
    Frank

  • Hi Hungwei,

    For your original code and SYS/BIOS 6.76.02.02, I observe the following for a 10 minute run:

    Timestamp_get32() (I confirmed the time stamp provider is the PMU):

    • mindelta=49563
    • maxdelta=50030

    Using a logic analyzer on GPIO1_88, I see these stats for 500 Msps sampling rate:

    • min/max positive pulse: 123.6 usec. / 125.1 usec.
    • min/max negative pulse: 124.8. usec. / 125.1 usec.

    If I exclude the GPIO toggles from the first four timer ISRs, I see these stats from the logic analyzer:

    • min/max positive pulse: 124.9 usec / 125.1 usec
    • min/max negative pulse: 124.9 usec / 125.1 usec

    Regards,
    Frank

  • Hi Hungwei,

    I noticed you have all code/data allocated to OCRAM, so I decided to experiment with moving all code/data to TCMA/B. With this update, I see these stats for a 10 minute run:

    PMU:

    • mindelta=49988
    • maxdelta=50004

    Logic analyzer:

    • min/max positive pulse: 124.9 usec / 125 usec
    • min/max negative pulse: 124.9 usec / 125 usec

    Regards,
    Frank

  • Hi Hungwei,

    I tried the same experiment, but using SYS/BIOS 6.76.04.02 (the version that contains the workaround for the VIM/VIC bug). In this case, I obtained these stats for a 10 minute run:

    PMU:

    • mindelta=49980
    • maxdelta=50004

    Logic analyzer:

    • min/max positive pulse: 124.9 usec / 125 usec
    • min/max negative pulse: 124.9 usec / 125 usec

    Regards,
    Frank

  • Hello Frank,

    Thanks for the update! I will move the code to TCM and conduct the measurement again.

  • Hello Frank,

    I have conducted another measurement after moving code/data to TCM. The result shows the jitter is 0.124999 us. Thanks for you help!

    image-2020-03-10-08-54-31-472.png

  • Hungwei,

    Thanks much for the feedback. I'll go ahead and close this thread. Please let me know if there are any further questions or concerns.

    Regards,
    Frank