Re: [Xenomai-help] Interrupt latency greater than 250ms

[Philippe Gerum <rpm@xenomai.org>]

On 04/12/2012 05:57 PM, Philippe Gerum wrote:
> On 04/12/2012 05:45 PM, Michael Pustylnik wrote:
>> The code masking the interrupt in IPIC (call for
>> ipipe_pre_cascade_noeoi()) initially showed up in the patch you
>> recommended (see your email attached).
>>
>> Later on it was integrated in Xenomai commit
>> "9a5e42df8bccc59620c08caeb4b9fe92dbf94a1b".
>>
>> As shown in the trail below, it keeps interrupts all the time until the
>> scheduler returns, thus breaking real-time responsiveness.
>>
>> A solution to this is probably to remove calling
>> ipipe_pre_cascade_noeoi() and let the cascading handler mask the
>> interrupt. Am I missing something? Do you think it is safe to use this
>> solution?
> 
> No, as interrupts could be re-enabled before invoking the handler, you 
> would get an IRQ storm.
> 
> The solution is to rework the cascaded IRQ handling in the generic 
> pipeline core, so that all decoded IRQs are acked/masked, then the 
> multiplex IRQ unmasked, then all the decoded IRQ handlers fired when 
> syncing the relevant pipeline stage.
> 
> A fix for this will follow when enough testing will have been done on 
> arm and ppc, to check whether that logic does not raise other issue.
> 

This is the patch series fixing the issue in the newest pipeline "core"
implementation, currently for kernel 3.2. Something along these lines would work for
earlier kernels as well.

http://git.denx.de/?p=ipipe-2.6.git;a=commit;h=0a9a7b4e4ce9f4196a574471ad58f4389820c438
http://git.denx.de/?p=ipipe-2.6.git;a=commit;h=f2ca3c2baf58bf43f4c00fb05b91b16da9fd77f2
http://git.denx.de/?p=ipipe-2.6.git;a=commit;h=a4b909ccf80c5afa132aa7a9ccf0022cb8a6e6f2
http://git.denx.de/?p=ipipe-2.6.git;a=commit;h=b47bc773ff07ce886aaf490921ac59e98ed9575a

>>
>> Michael Pustylnik, P.Eng.
>> Senior Software Engineer
>> *RuggedCom Inc.*
>> www.ruggedcom.com <http://www.ruggedcom.com/>
>> 300 Applewood Crescent
>> Concord, Ontario, L4K 5C7
>> Tel: (905)482-4523
>> Fax: (905)856-1995
>>
>> ------------------------------------------------------------------------
>>
>> *From:*xenomai-help-bounces@domain.hid
>> [mailto:xenomai-help-bounces@domain.hid] *On Behalf Of *Makarand Pradhan
>> *Sent:* Wednesday, April 04, 2012 12:59 PM
>> *To:* Philippe Gerum
>> *Cc:* xenomai@xenomai.org
>> *Subject:* Re: [Xenomai-help] Interrupt latency greater than 250ms.
>> Question.
>>
>> Hi Philippe,
>>
>> We have found that the problem is that the interrupt is unexpectedly
>> held masked at the IPIC level for a long time. Please find the trace 
>> below:
>>
>> 2552 :| + func -54413 0.590 qe_ic_cascade_low_ipic+0x8
>> (__ipipe_ack_irq+0x2c)
>> 2553 :| + func -54412 0.696 qe_ic_get_low_irq+0x8
>> (qe_ic_cascade_low_ipic+0x30)
>> 2554 :| + func -54411 0.666 irq_linear_revmap+0x8 
>> (qe_ic_get_low_irq+0x5c)
>>
>> *MASK in IPIC (SIMSR_H register bit 1)*
>> 2555 :| + func -54411 0.606 ipic_mask_irq+0x8 
>> (qe_ic_cascade_low_ipic+0x48)
>> 2556 :| + func -54410 0.590 irqd_to_hwirq+0x8 (ipic_mask_irq+0x30)
>> 2557 :| + func -54410 0.909 __ipipe_spin_lock_irqsave+0x8
>> (ipic_mask_irq+0x40)
>> 2558 :| # func -54409 0.727 __ipipe_spin_unlock_irqrestore+0x8
>> (ipic_mask_irq+0xa8 )
>> 2559 :| + func -54408 0.560 __ipipe_qe_ic_cascade_irq+0x8
>> (qe_ic_cascade_low_ipic+ 0x5c)
>> 2560 :| + begin 0x0000002b -54407 0.530 __ipipe_qe_ic_cascade_irq+0x2c
>> (qe_ic_cascade_low_ipic +0x5c)
>> 2561 :| + func -54407 0.651 __ipipe_handle_irq+0x8
>> (__ipipe_qe_ic_cascade_irq+0x38 )
>> 2562 :| + func -54406 0.939 __ipipe_ack_level_irq+0x8
>> (__ipipe_handle_irq+0xbc)
>>
>> *MASK in QUICC (CIMR register bit 11)*
>> 2563 :| + func -54405 0.787 qe_ic_mask_irq+0x8 
>> (__ipipe_ack_level_irq+0x40)
>>
>> *XENOMAI SCHEDULER IS INVOKED*
>> 2576 :| # func -54393 0.590 __xnpod_schedule+0x8 
>> (xnintr_irq_handler+0x1f8)
>> *
>> UNMASK in QUICC (done by our user space handler)*
>> 2595 : + func -54377 0.621 __rt_intr_enable+0x8 [xeno_native]
>> (hisyscall_event+0x 1e4)
>>
>> *UNMASK in IPIC (after 50ms, i.e. only after the scheduler returns):*
>> 31637 :| #end 0x0000002b -518+ 2.272 __ipipe_qe_ic_cascade_irq+0x40
>> (qe_ic_cascade_low_ipic+ 0x5c)
>> 31638 :| #func -516+ 1.090 ipic_unmask_irq+0x8 
>> (qe_ic_cascade_low_ipic+0x70)
>>
>> As you can see from the trace above, the interrupt is held masked at the
>> IPIC level all the time until the Xenomai scheduler returns and is only
>> unmasked after that.
>>
>> Is it really the way it should be? Shouldn’t the interrupt be unmasked
>> at the IPIC level right after masking it at the QUICC engine level?
>>
>> Rgds,
>> Mak.
>>
>>
>>
>> On 28/03/12 02:23 PM, Makarand Pradhan wrote:
>>
>> Hi Philippe,
>>
>>
>>
>> On 28/03/12 12:17 PM, Philippe Gerum wrote:
>>
>>> The log says your code wants to control when the IRQ is enabled again,
>>> by calling rt_intr_enable() from userland. I guess you are setting
>>> I_NOAUTOENA too. Correct?
>>
>>
>> That is correct. I_NOAUTOENA is used in rt_intr_create. Otherwise the
>>
>> level trigerred interrupt will not allow the userland processing of the
>>
>> int. The userland handler is very small and it unconditionally
>>
>> rt_intr_enables the intr.
>>
>>
>>
>> Testing indicates that the interrupt is always enabled from user space
>>
>> within 250 usec after kernel gets the interrupt.
>>
>>
>>
>> I have noted that unless I see"#end 0x0000002b" and a hit to the
>>
>> ipic_unmask_irq, the next interrupt is not processed.
>>
>>
>>
>> And this is getting delayed once in a while which causes a delay in
>>
>> processing the next interrupt.
>>
>>
>>
>> So the sequence of events leading to the problem is:
>>
>>
>>
>> 1. Get interrupt: #begin 0x0000002b noted in ipipe trace
>>
>> 2. Intr enabled from user space. Always happens roughly within 250usec.
>>
>> 3. #end 0x0000002b noted in ipipe trace where the int is unmasked by 
>> ipipe.
>>
>>
>>
>> When I see the problem, step 3 is delayed. I am trying to capture a
>>
>> trace where the begin, int enable and end are captured.
>>
>>
>>
>> Your thoughts on what might cause this delay would be appreciated.
>>
>>
>>
>> Rgds,
>>
>> Mak.
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>> -- 
>>
>> ___________________________________________________________________________ 
>>
>>
>> NOTICE OF CONFIDENTIALITY:
>>
>> This e-mail and any attachments may contain confidential and 
>> privileged information. If you are
>>
>> not the intended recipient, please notify the sender immediately by 
>> return e-mail and delete this
>>
>> e-mail and any copies. Any dissemination or use of this information by 
>> a person other than the
>>
>> intended recipient is unauthorized and may be illegal.
>>
>> _____________________________________________________________________
>>
>>
>>
>>
>>
>> No virus found in this incoming message.
>> Checked by AVG - www.avg.com
>> Version: 8.5.455 / Virus Database: 271.1.1/4175 - Release Date: 04/03/12
>> 18:35:00
>>
> 
> 


-- 
Philippe.