RTOS/TMS320C6654: interrupt: time before subroutine execution

Hi Gildas,

I've forwarded this to the RTOS GPIO experts. Their feedback should be posted here.

BR
Tsvetolin Shulev

Hi,

I do the same test on gpio 4 and measure time between 200 ns and 400 ns. (compare to 1.45 µs on gpio18)

I know that gpio18 uses cic and cpintc dispatcher, but how to explain this difference?

regards

In my original code, hwi directly called Cpintc_dispatch. I've modified it so now hwi call a function in my code, that toggle a gpio and call CpintcDispatch

hwi_handle_gpio18 = Hwi_create(hwi_gpio18, &Application::dispatch, &params, &eb);

void Application::dispatch(UArg arg)
{
    DEBUG_IO3_ON;
    CpIntc_dispatch(arg);
    DEBUG_IO3_OFF;
}

So I can see that I enter in this new fonction 275 ns after my external signal and in my real interrupt routine call by the dispatcher 1.22 µs after this first stage function.

My issue is not related to RTOS GPIO but to CpIntc. Why CpIntc_dispatch take 1.22 µs to call my interrupt routine?

Following screenshot show gpio18 in khaki, before Cpintc_dispatch call in pale blue, after Cpintc_dispatch call in dark blue

regards

Gildas,

Here is some code that we have previously on this device.

    CpIntc_mapSysIntToHostInt(0, 15, 8);                  // map system interrupt 15 to host interrupt 8
    CpIntc_dispatchPlug(15, &event15Fxn, 15, TRUE);       // plug function for system interrupt 15
    CpIntc_enableHostInt(0, 8);                           // enable host interrupt 8
    eventId = CpIntc_getEventId(8);                       // get the event id for host interrupt 8

    Hwi_Params_init(&params);
    params.arg = 8;                                      // make sure this value is the host interrupt #
    params.eventId = eventId;                            //   make sure this is the event id for your host interrupt
    params.enableInt = TRUE;                             // enable the Hwi
    Hwi_create(4, &CpIntc_dispatch, &params, NULL);      // plug interrupt vector 4, make sure function here is the CpIntc_dispatch


Using the guidance provided here:
http://processors.wiki.ti.com/index.php/Configuring_Interrupts_on_Keystone_Devices#CpIntc

Most of your code matches the configuration so at the moment it is unclear what is causing the Jitter. I know you mentioned that there are no other interrupts in the system but can you check the masking option on the interrupt. I would explicitly set the masking option to

params.maskSetting = Hwi_MaskingOption_SELF;  or params.maskSetting = MaskingOption_ALL;

I am also looping in my colleagues TI RTOS development team to provide inputs and comments on your CpIntc_disptach configuration.

Regards,

Rahul

Hi,

I've tried SELF and ALL configurations and get same results as yesterday.

My interrupt is the only cyclic one, all other are error interrupts that should never occur or interrupts used only at initialisation and not when I do my measurement. However, to be sure, I 've added a function to disabled all interrupt exept my gpio while my system have finished to initialize. I also see no changes.

My system use falling edge of gpio to trigger. I try to change to rising, but still get same result.

Regards

Gildas

Hi,

I keep my dispatch function that call Cpintc_Dispatch (see previous posts for details) and use trace to get following screenshoots:

I can't see __ti_sysbios__ detail, but before my dispatch function it's HWI management and after it's CpIntc_dispatch.

CpIntc_Dispatch have 956 "other stalls"

Do you have any update on your side?

Gildas

Do you have any answer from your colleagues ?

Hi Gildas,

CpIntc_dispatch() is a pretty simple function. It is surprising that it alone is adding ~1.22us to the interrupt dispatch time. A few comments/suggestions...

 - The CpIntc_dispatch() function is more efficient if a single system interrupt is mapped to a host interrupt. If multiple system interrupts are mapped then it has to loop through the system interrupt status registers which can add to the cycles.

 - I presume you have caching enabled. Another thing you can do to improve performance is to place the SYS/BIOS kernel code & data in L2SRAM. CpIntc_dispatch() function needs to perform a few memory reads and having the kernel data in L2SRAM might help.

Best,

Ashish

Hi,

To answer to your comments:

- I have only one system interrupt by host interrupt and I confirm this with step by step execution of CpIntc_dispatch

- I have all L1 configured as cache, no L2 cache. SYSBIOS kernel and data are in L2SRAM except the heap that is in DDR3

Could you confirm me that the "Other stall" in previous screenshot could explain this. If yes, how to explain this stall?

Gildas

Hi Gildas,

I have requested that a HW expert chime in to comment on how long can CINTC MMR accesses stall. In the meantime can you try disabling Hwi auto nesting support ? This would rule out nested interrupts delaying interrupt processing.

*.cfg

Hwi.dispatcherAutoNestingSupport = false;

Best,

Ashish

Hi Ashish,

Hwi auto nesting is already disabled in my .cfg file.

Regards

Gildas

Ashish,

My project use gpio17, gpio18, and gpio19 as interrupt. Each one is linked to its host interrupt (0, 1, 2).

I've put a breakpoint at start of CpIntc_mapSysIntToHostInt and display ti_sysbios_family_c66_tci66xx_CpIntc_Module_State_0_hostIntToSysInt__A. I discover that at my first call of CpIntc_mapSysIntToHostInt , index 0 and 1 does not contains 0xFFFF.

I've put watchpoint to these address and saw that initialize value are 0xFFFF, but __call_stub() update this value. So after mapping my interrypt I have 0xFFFE which is code for multiple sys int on same host int.

I suppose that host 0 and 1 are used by ti edma3 driver as I catch sys int 24 in host 0 and sys int 16, 19, 20, 21 in host 1

I've tried linked gpio18 to host interrupt 4 instead of 1 and get really better result:

main time is now between 320 and 500 ns, but I still have few time between 520 and 700 ns and random time like 1.39 µs on this screenshot

So main time is now correct (hwi + CpIntc dispatch time), but the random value is still not acceptable.

[EDIT] As I have already noticed in my original post, using compiler 7.4.21 instead of 7.4.16 remove random time, so I measure time between 337 to 675 ns

Thanks in advance for your help

Gildas

Hi,

Now 'fixed' long time before routine execution is explained, I'm still trying to explain jitter that could randomly delay my execution.

I've suspected cache management, but I've tried to disable L1 cache and nothing change.

I've added hwi hook. My aimis to check in end hook if my gpio18 interrupt is pending.

void myEnd1(Hwi_Handle hwi)
{
    UArg arg;
    Hwi_FuncPtr funcPtr;

    funcPtr = Hwi_getFunc(hwi, &arg);
 
    if (0 != (IFR & (1 << hwi_gpio18)))
    {
        DEBUG_IO3_ON;
        LOG_Error("interrupt pending: hwi: 0x%x, FuncPtr: 0x%x(arg %d), IFR: 0x%x", (int)hwi, (int)funcPtr, arg,  IFR);
        DEBUG_IO3_OFF;
    }
}

This gave me strange result:

interrupt pending: hwi: 0x8e23b8, FuncPtr: 0x40004000(arg 1), IFR: 0x40

hwi corresponds to address of ti_sysbios_family_c64p_Hwi_Object__table__V; IFR corresponds to my gpio18 interrupt; FuncPtr points to unmapped address.

I've also discovered that primary event (gpio4) have same jitter that second (gpio18); I previously missed it as I didn't look enough time on my scope

What is your opinion on these results?

Gildas

Hi,

Is there a way in hwi end hook to know current interrupt?

Thanks

Hi Gildas,

Here's a code snippet that shows how you can access the interrupt number from the Hwi end hook:

#define ti_sysbios_family_c64p_Hwi__internalaccess
#define ti_sysbios_family_c64p_Hwi_Module_State__ ti_sysbios_family_c64p_Hwi_Module_State
#include <ti/sysbios/family/c64p/Hwi.h>

func() {
   ...
   i = ti_sysbios_family_c64p_Hwi_Module__state__V.intNum;
   ...
}

Please note that the above code accesses the kernel's internal data structure which may change in the future. So, you should only use the above code for debugging purposes.

Another point to notes is that with nested interrupts the intNum will be incorrect as it will point to the nested interrupt's number and not the currently running ISR's interrupt number. In your case however interrupt nesting is disabled so it does not matter.

Best,
Ashish

Thanks for this code.

I've discovered what generates random long time. Sysbios is using a timer connected to IRQ14. I remove this with:

BIOS.clockEnabled = false;

This is a vicious configuration because I've already checked that I didn't used neither timer module nor clock module, but this timer is inside kernel.

So, long time and random time are now explained, but I still have the second "group" of interrupt (in red circle of screenshoot) to explain. Why few interrupts take around 200 ns more than the others?

Gildas

Any idea?

Hello:

The interconnect latency for a read from the GEM to the INTC MMR, is estimated as 72 CPU cycles for the round trip (address out and data back). This translates to ~84ns latency assuming the device is running at 850MHz. Again this only counts from the GEM master port to the INTC IP boundary. 

Jian

Hi,

I have modified my hardware and software for test:
- my source signal is sent on both gpio 4 and gpio 18
- same sub routine function is registered in both Hwi_create (so for gpio 18 I've bypassed CpIntc to directly access to my function which clear CIC sys int)
- I've generated 2 binaries, one with interrupt enabled only on gpio 4 and the other with interrupt enabled only on gpio 18

for remember kaki signal is my interrupt source and blue is the enter in my sub routine (display with infinite persistence)

interrupt enabled only on gpio 4:

interrupt enabled only on gpio 18:

HOW TO EXPLAIN THIS DIFFERENCE ? Could this be due to :

- hardware management of gpio 16-31 with is different that gpio 0-15?

- difference in sysbios HWI if event is from CIC?

- cache management? (recompil change mapping and so need of cache reload)

Just a precision.

The 2 previous screenshot have been obtained with the same source code execpt the number of the interrupt anabled.

I've compared the map files of the 2 associated binaries and they are identical.

TI documentation is false on gpio 16-31 usage as interrupt. Is it possible that there is also a hardware bug that could explain my behaviour?

Hi,

I've added a measurement of time between my interrupts (based on TCSL, TCSH). This allow me to detect when the call of my routine is delayed and so to break when the problem occured.

This is a screenshot of function profiller in case of delayed interrupt:

(sysbios before hwi_int6 is just profiller display artifact as before interrupt I'm in task context and not hwi context)

To compare the previous interrupt (in the same profiller trace) with the same zoom level:

I keep my dispatch function that is registered into hwi_create, and just call CpIntc_dispatch to distinguish time in sysbios, and time in CpIntc. So the lost time is in sysbios and not in CpIntc

stall profilling screenshot:

regards

Hi,

I've done the same with CCS V7 profiler which give me the detail of sysbios function:

The trave viewer show exactly when the stall occured:

I hope that with this information TI could tell me what's happened and how to avoid this stall

Gildas:

Not sure if you noticed in the c6655 data sheet, the GPIO4 maps to the C66 CorePAC primary interrupts directly, while the GPIO18 maps to the CIC0, then the output of CIC0 maps to the CorePAC events. If you looks them up, they are called GPINT4 and GPINT18 in the datasheet.

This still does not explain the spurious latency on GPINT18. I am not family with the sysbios routines, but can either you or Ashish trace if the GPI18 is mapped to the CIC0 correctly, and then CIC0 maps to CorePAC?

regards
Jian

also, forgot to ask, please also confirm other interrupts to CIC0 is masked.
Jian

Hi,

All is clean regarding CIC configuration with unique interrupt to optimize dispatch time.

What I have discovered is that Hwi_dispatchCore need information stored in heap and in my project heap is in DDR3. Some time DDR access generate long stall of core.

Gildas

yes I saw your other post on heaps configuration. let us know what happens once you can put heap in L2.
though still, not sure how to make sense, why GPINT4 is serviced without spurious delays.
jian