| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Thu, 13 Nov 2014 12:52:57 +0530
From: Viresh Kumar <viresh.kumar@...aro.org>
To: Peter Zijlstra <peterz@...radead.org>
Cc: Frederic Weisbecker <fweisbec@...il.com>,
Christoph Lameter <cl@...ux.com>,
"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>,
Thomas Gleixner <tglx@...utronix.de>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
Gilad Ben-Yossef <gilad@...yossef.com>,
Tejun Heo <tj@...nel.org>,
John Stultz <john.stultz@...aro.org>,
Mike Frysinger <vapier@...too.org>,
Minchan Kim <minchan.kim@...il.com>,
Hakan Akkan <hakanakkan@...il.com>,
Max Krasnyansky <maxk@....qualcomm.com>,
Hugh Dickins <hughd@...gle.com>,
"H. Peter Anvin" <hpa@...or.com>, Ingo Molnar <mingo@...nel.org>,
Kevin Hilman <khilman@...aro.org>
Subject: Re: Future of NOHZ full/isolation development (was Re: [NOHZ] Remove scheduler_tick_max_deferment)
On 12 November 2014 20:46, Viresh Kumar <viresh.kumar@...aro.org> wrote:
> On 12 November 2014 20:36, Peter Zijlstra <peterz@...radead.org> wrote:
>> I don't think you need to add anything. We already have tracepoints for
>> every single interrupt (and therefore also for the hrtimer one) and we
>> have expiry tracepoints.
>
> I will crosscheck this again but as far as I remember these spurious interrupts
> aren't caught with tracers currently. Not even the irq_enter/exit ones.
So yes, we do get irq_handler_entry/exit traces for the clockevent device.
The problem here is that people miss these as there are no warnings issued
here. And so nobody tried to resolve these spurious interrupts.
This is how it looks on a ARM machine (With trace_hrtimer_spurious), though
it is relevant for all architectures which emulate ONESHOT mode over
PERIODIC mode:
<idle>-0 [001] d.h2 719.642085: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.646506: hrtimer_spurious: count:105
<idle>-0 [001] d.h2 719.646511: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.646522: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719640000000
softexpires=719640000000
<idle>-0 [001] d..3 719.646545: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.647086: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.651540: hrtimer_spurious: count:106
<idle>-0 [001] d.h2 719.651545: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.651554: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719645000000
softexpires=719645000000
<idle>-0 [001] d..3 719.651576: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.652084: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.656571: hrtimer_spurious: count:107
<idle>-0 [001] d.h2 719.656575: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.656583: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719650000000
softexpires=719650000000
<idle>-0 [001] d..3 719.656601: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.657084: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.661611: hrtimer_spurious: count:108
<idle>-0 [001] d.h2 719.661616: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.661627: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719655000000
softexpires=719655000000
<idle>-0 [001] d..3 719.661652: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.662086: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.666643: hrtimer_spurious: count:109
<idle>-0 [001] d.h2 719.666648: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.666657: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719660000000
softexpires=719660000000
<idle>-0 [001] d..3 719.666680: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.667084: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.671678: hrtimer_spurious: count:110
<idle>-0 [001] d.h2 719.671682: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.671693: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719665000000
softexpires=719665000000
<idle>-0 [001] d..3 719.671714: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.672085: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.676712: hrtimer_spurious: count:111
<idle>-0 [001] d.h2 719.676717: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.676726: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719670000000
softexpires=719670000000
<idle>-0 [001] d..3 719.676749: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.677087: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.681745: hrtimer_spurious: count:112
<idle>-0 [001] d.h2 719.681750: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.681759: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719675000000
softexpires=719675000000
<idle>-0 [001] d..3 719.681780: hrtimer_cancel: hrtimer=ee7bb740
<idle>-0 [001] d.h2 719.682084: irq_handler_entry:
irq=30 name=arch_timer
<idle>-0 [001] d.h3 719.686783: hrtimer_spurious: count:113
<idle>-0 [001] d.h2 719.686787: irq_handler_exit:
irq=30 ret=handled
<idle>-0 [001] d..3 719.686797: hrtimer_start:
hrtimer=ee7bb740 function=tick_sched_timer expires=719680000000
softexpires=719680000000
<idle>-0 [001] d..3 719.686819: hrtimer_cancel: hrtimer=ee7bb740
Normally this happens on a non-spurious interrupt:
is-cpu-isolated-1963 [000] d.h1 719.642080: irq_handler_entry:
irq=30 name=arch_timer
is-cpu-isolated-1963 [000] d.h2 719.642086: hrtimer_cancel: hrtimer=ee7b3740
is-cpu-isolated-1963 [000] d.h1 719.642089: hrtimer_expire_entry:
hrtimer=ee7b3740 function=tick_sched_timer now=719635008926
is-cpu-isolated-1963 [000] d.h1 719.642095: softirq_raise: vec=1
[action=TIMER]
is-cpu-isolated-1963 [000] d.h1 719.642099: softirq_raise: vec=9
[action=RCU]
is-cpu-isolated-1963 [000] d.h2 719.642104: sched_stat_runtime:
comm=trace-isolation pid=1963 runtime=348042 [ns] vruntime=7804506025
[ns]
is-cpu-isolated-1963 [000] d.h1 719.642111: hrtimer_expire_exit:
hrtimer=ee7b3740
is-cpu-isolated-1963 [000] d.h2 719.642115: hrtimer_start:
hrtimer=ee7b3740 function=tick_sched_timer expires=719640000000
softexpires=719640000000
is-cpu-isolated-1963 [000] d.h1 719.642121: irq_handler_exit:
irq=30 ret=handled
.. followed by softirq processing.
Another trace point with trace_hrtimer_spurious() might end up being useful :)
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists