i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Stanislav Meduna]

Hi,

on a i.MX28:

Linux nxt 3.12.15-rt25+ #83 PREEMPT RT Thu Apr 17 20:54:00 CEST 2014 armv5tejl GNU/Linux


# tracer: irqsoff
#
# irqsoff latency trace v1.1.5 on 3.12.15-rt25+
# --------------------------------------------------------------------
# latency: 2224 us, #6/6, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
#    -----------------
#    | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
#    -----------------
#  => started at: rcu_idle_enter
#  => ended at:   arch_cpu_idle
#
#
#                   _--------=> CPU#
#                  / _-------=> irqs-off
#                 | / _------=> need-resched
#                 || / _-----=> need-resched_lazy
#                 ||| / _----=> hardirq/softirq
#                 |||| / _---=> preempt-depth
#                 ||||| / _--=> preempt-lazy-depth
#                 |||||| / _-=> migrate-disable
#                 ||||||| /     delay
#  cmd     pid    |||||||| time  |   caller
#     \   /      ||||||||  \   |   /
  <idle>-0       0d...1..    2us+: rcu_idle_enter
  <idle>-0       0d...2..   11us+: T.796 <-rcu_idle_enter
  <idle>-0       0d...2..   17us!: arch_cpu_idle <-cpu_startup_entry
  <idle>-0       0d...1.. 2219us+: arch_cpu_idle
  <idle>-0       0d...1.. 2234us+: trace_hardirqs_on <-arch_cpu_idle
  <idle>-0       0d...1.. 2303us : <stack trace>
 => arch_cpu_idle
 => cpu_startup_entry
 => start_kernel

Why are interrupts disabled here (and are they really disabled)?

$ egrep "IDLE|SMP|HZ" .config
CONFIG_BROKEN_ON_SMP=y
CONFIG_HZ_PERIODIC=y
# CONFIG_NO_HZ_IDLE is not set
# CONFIG_NO_HZ is not set
CONFIG_GENERIC_SMP_IDLE_THREAD=y
CONFIG_GENERIC_IDLE_POLL_SETUP=y
CONFIG_HZ_FIXED=0
# CONFIG_HZ_100 is not set
# CONFIG_HZ_200 is not set
CONFIG_HZ_250=y
# CONFIG_HZ_300 is not set
# CONFIG_HZ_500 is not set
# CONFIG_HZ_1000 is not set
CONFIG_HZ=250
# CONFIG_CPU_IDLE is not set
# CONFIG_ARCH_NEEDS_CPU_IDLE_COUPLED is not set

Configuring
CONFIG_CPU_IDLE=y
CONFIG_CPU_IDLE_GOV_LADDER=y
does not help

Maybe it is just some tracing infrastructure interference - the effect
of enabling the tracing is huge on this platform for some reason.
Just enabling the irqsoff tracing makes the machine unsuitable
for any serious load.

Thanks
-- 
                                                       Stano

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Tim Sander]

Hi Stanislav
> Linux nxt 3.12.15-rt25+ #83 PREEMPT RT Thu Apr 17 20:54:00 CEST 2014
> armv5tejl GNU/Linux
> 
> 
> # tracer: irqsoff
> #
> # irqsoff latency trace v1.1.5 on 3.12.15-rt25+
> # --------------------------------------------------------------------
> # latency: 2224 us, #6/6, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
> #    -----------------
> #    | task: swapper-0 (uid:0 nice:0 policy:0 rt_prio:0)
> #    -----------------
> #  => started at: rcu_idle_enter
> #  => ended at:   arch_cpu_idle
> #
> #
> #                   _--------=> CPU#
> #                  / _-------=> irqs-off
> #                 | / _------=> need-resched
> #                 || / _-----=> need-resched_lazy
> #                 ||| / _----=> hardirq/softirq
> #                 |||| / _---=> preempt-depth
> #                 ||||| / _--=> preempt-lazy-depth
> #                 |||||| / _-=> migrate-disable
> #                 ||||||| /     delay
> #  cmd     pid    |||||||| time  |   caller
> #     \   /      ||||||||  \   |   /
>   <idle>-0       0d...1..    2us+: rcu_idle_enter
>   <idle>-0       0d...2..   11us+: T.796 <-rcu_idle_enter
>   <idle>-0       0d...2..   17us!: arch_cpu_idle <-cpu_startup_entry
>   <idle>-0       0d...1.. 2219us+: arch_cpu_idle
>   <idle>-0       0d...1.. 2234us+: trace_hardirqs_on <-arch_cpu_idle
>   <idle>-0       0d...1.. 2303us : <stack trace>
>  => arch_cpu_idle
>  => cpu_startup_entry
>  => start_kernel
> 
> Why are interrupts disabled here (and are they really disabled)?
> 
> $ egrep "IDLE|SMP|HZ" .config
> CONFIG_BROKEN_ON_SMP=y
> CONFIG_HZ_PERIODIC=y
> # CONFIG_NO_HZ_IDLE is not set
> # CONFIG_NO_HZ is not set
> CONFIG_GENERIC_SMP_IDLE_THREAD=y
> CONFIG_GENERIC_IDLE_POLL_SETUP=y
> CONFIG_HZ_FIXED=0
> # CONFIG_HZ_100 is not set
> # CONFIG_HZ_200 is not set
> CONFIG_HZ_250=y
> # CONFIG_HZ_300 is not set
> # CONFIG_HZ_500 is not set
> # CONFIG_HZ_1000 is not set
> CONFIG_HZ=250
> # CONFIG_CPU_IDLE is not set
> # CONFIG_ARCH_NEEDS_CPU_IDLE_COUPLED is not set
> 
> Configuring
> CONFIG_CPU_IDLE=y
> CONFIG_CPU_IDLE_GOV_LADDER=y
> does not help
> 
> Maybe it is just some tracing infrastructure interference - the effect
> of enabling the tracing is huge on this platform for some reason.
> Just enabling the irqsoff tracing makes the machine unsuitable
> for any serious load.
Are you sure that this is not the cpu idle latency? I patched out the idle 
mechanism on i.mx35 since waking up took much to long for RT usage.
The CPU is running a little hotter then, but after all the thermal envelop 
always has to to cope with maximum load, so i guess this should do no harm 
besides more energy churn.

Best regards
Tim

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Stanislav Meduna]

On 18.04.2014 18:09, Tim Sander wrote:

> Are you sure that this is not the cpu idle latency?

Don't think so. However it is close to what I'd expect as an average
idle time (capped up by periodic ticks @ 250 Hz = 4 ms).

But thanks for the idea, I investigated and booting with kernel
parameter nohlt results in usual latencies reported (372 us max,
not great but acceptable for our usage).

The tracer is in fact right - the interrupts _are_ meant to be off:

arch/arm/mm/proc-arm926.S:

/*
 * cpu_arm926_do_idle()
 *
 * Called with IRQs disabled
 */

Would it be possible to 'lie' to the tracing infrastructure and
treat the cpu_do_idle() as interrupts enabled without
actually enabling them?

Thanks
-- 
                                    Stano

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Stanislav Meduna]

On 18.04.2014 20:12, Stanislav Meduna wrote:

> Would it be possible to 'lie' to the tracing infrastructure and
> treat the cpu_do_idle() as interrupts enabled without
> actually enabling them?

Hm.. but this actually happens - the call to arch_cpu_idle()
is surrounded by stop_critical_timings()/start_critical_timings()
so the time should not be traced. Weird...

-- 
                                  Stano

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Tim Sander]

Hi Stanislav
Am Freitag, 18. April 2014, 20:12:41 schrieb Stanislav Meduna:
> On 18.04.2014 18:09, Tim Sander wrote:
> > Are you sure that this is not the cpu idle latency?
> 
> Don't think so. However it is close to what I'd expect as an average
> idle time (capped up by periodic ticks @ 250 Hz = 4 ms).
Have you tried patching out the wfi in the idle loop? At least the i.mx35 does 
some strange l2cache dance due to an hw bug. Patching out this whole stuff 
helped a lot with latencys on an unloaded system.

Best regards
Tim

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Stanislav Meduna]

On 19.04.2014 23:24, Tim Sander wrote:

>>> Are you sure that this is not the cpu idle latency?
>>
>> Don't think so. However it is close to what I'd expect as an average
>> idle time (capped up by periodic ticks @ 250 Hz = 4 ms).
> Have you tried patching out the wfi in the idle loop? At least the i.mx35 does 
> some strange l2cache dance due to an hw bug. Patching out this whole stuff 
> helped a lot with latencys on an unloaded system.

This is indeed some interference in the tracing infrastructure.
Disabling it and looking at the cyclictest output instead gives
much more consistently looking numbers.

Yes the wfi stuff generates a good amount of latency - running
with nohlt is very visible in the cyclictest, but this is in the
~100-300 us range, not the numbers I was seeing.

Thanks
-- 
                                        Stano

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Gilles Chanteperdrix]

Le 17/04/2014 22:38, Stanislav Meduna a écrit :
> Hi,
> 
> on a i.MX28:
> 
> Linux nxt 3.12.15-rt25+ #83 PREEMPT RT Thu Apr 17 20:54:00 CEST 2014 armv5tejl GNU/Linux
>
> (...)
>
> Maybe it is just some tracing infrastructure interference - the effect
> of enabling the tracing is huge on this platform for some reason.
> Just enabling the irqsoff tracing makes the machine unsuitable
> for any serious load.

For the record, latencies on imx28 are high because:
1- it has an arm926 core, which uses a VIVT cache, and Linux chooses to
flush cache at each mm switch to avoid aliasing issues;
2- the arm926 idle routine, in order to work around a hardware bug
flushes the instruction cache before calling the "wfi" instruction.

#2 can be avoided by using nohlt
#1 can be avoided by using the ARM FCSE extension.

A patch exists for #1 which is currently integrated into the Adeos patch
but could exist independently. I could post the patch here for Linux
vanilla here if there is enough interest, and let you do the merge with
the preempt_rt patch.

Regards.

-- 
Gilles.
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Stanislav Meduna]

On 19.04.2014 12:36, Gilles Chanteperdrix wrote:

> #1 can be avoided by using the ARM FCSE extension.

An interesting stuff, thanks for pointing this up.

> A patch exists for #1 which is currently integrated into the Adeos patch
> but could exist independently. I could post the patch here for Linux
> vanilla here if there is enough interest, and let you do the merge with
> the preempt_rt patch.

I am surely not skilled enough to merge and test this, but publishing
the patch rebased to current kernels somewhere would be surely
interesting.

Thanks
-- 
                                            Stano

Re: i.MX28 milliseconds latencies, interrupts disabled in arch_cpu_idle?

[Gilles Chanteperdrix]

Le 21/04/2014 11:11, Stanislav Meduna a écrit :
> On 19.04.2014 12:36, Gilles Chanteperdrix wrote:
> 
>> #1 can be avoided by using the ARM FCSE extension.
> 
> An interesting stuff, thanks for pointing this up.
> 
>> A patch exists for #1 which is currently integrated into the Adeos patch
>> but could exist independently. I could post the patch here for Linux
>> vanilla here if there is enough interest, and let you do the merge with
>> the preempt_rt patch.
> 
> I am surely not skilled enough to merge and test this, but publishing
> the patch rebased to current kernels somewhere would be surely
> interesting.

The patch has been posted three times on the linux-arm-kernel mailing
list, and received absolutely no comments. So, it does not interest the
mainline ARM linux community. Besides armv5 cores are almost dead now.
However, it may interest the preempt_rt community, which is why I
propose to post it here. The gain in worst case latency is in the 70us
range. Merging with the preempt_rt patch should not be very difficult as
normally, there is no reason for conflicts, the patch only touches ARM
memory management, which the preempt_rt patch probably does not touch.

-- 
Gilles.
--
To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html