LinuxLists.cc - [v3.10-rc1] WARNING: at kernel/rcutree.c:502

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On Sun, May 12, 2013 at 11:08:50AM +0200, Bj?rn Mork wrote:
> Hello,
>
> got the splat below when running powertop on plain v3.10-rc1
> (i.e. without my previously mentioned revert patch or any other extra
> patches). Config attached.

OK, it looks like you have context-tracking enabled, so you might be
hitting a bug that Steven Rostedt found a few days ago. Could you
please try out his fix below?

Thanx, Paul

------------------------------------------------------------------------

I started testing the new NOHZ_FULL in the kernel and had some issues,
so I started function tracing and this bug report came out:

[23446.458073] ------------[ cut here ]------------
[23446.461028] WARNING:
at /home/rostedt/work/git/linux-trace.git/kernel/rcutree.c:388
rcu_eqs_enter+0x4b/0x89()
[23446.466096] Modules linked in: ebtables ipt_MASQUERADE sunrpc bridge
stp llc ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter
ip6_tables ipv6 uinput snd_hda_codec_id
t snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm
kvm_intel snd_timer snd kvm soundcore shpchp snd_page_alloc microcode
i2c_i801 pata_acpi firewire_ohci firewi
re_core crc_itu_t ata_generic i915 drm_kms_helper drm i2c_algo_bit
i2c_core video
[23446.466096] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.9.0-test+ #11
[23446.466096] Hardware name: To Be Filled By O.E.M. To Be Filled By
O.E.M./To be filled by O.E.M., BIOS SDBLI944.86P 05/08/2007
[23446.466096] ffffffff814879f0 ffffffff81004fa6 ffffffff810337af
ffff88007d400000
[23446.466096] 0000000000000000 0000000000000000 ffff88007d40d900
ffffffff81a01f00
[23446.466096] ffffffff81acba00 ffff88007d6495c0 ffffffff810a1f36
0000000000000a28
[23446.466096] Call Trace:
[23446.466096] [<ffffffff814879f0>] ? dump_stack+0xd/0x17
[23446.466096] [<ffffffff81004fa6>] ? show_stack+0x5/0x3e
[23446.466096] [<ffffffff810337af>] ? warn_slowpath_common+0x64/0x7c
[23446.466096] [<ffffffff810a1f36>] ? rcu_eqs_enter+0x4b/0x89
[23446.466096] [<ffffffff810a1f8e>] ? rcu_idle_enter+0x1a/0x30
[23446.466096] [<ffffffff81491bc5>] ? ftrace_graph_caller+0x85/0x85
[23446.466096] [<ffffffff810707f3>] cpu_startup_entry+0xb3/0x11c
[23446.466096] [<ffffffff81ae9d2e>] ? start_kernel+0x41a/0x425
[23446.466096] [<ffffffff81ae972d>] ? repair_env_string+0x54/0x54
[23446.466096] ---[ end trace ddbb69ae2a0f6687 ]---
[23446.466096] ------------[ cut here ]------------

This is caused by an imbalance of rcu_eqs_enter() and rcu_eqs_exit().
Adding more tracing, I also discovered that there seemed to be an
imbalance in user_exit() and user_enter(). Specifically, I found that
user_enter() was called, and then a migration happened and user_exit()
was never called before the schedule. Then I had noticed this in my
trace:

run-isol-11546 1.N.. 37363.637641: function: schedule_user <-- retint_careful
run-isol-11546 1.N.. 37363.637641: function: __schedule <-- preempt_schedule

The funny part here is that schedule_user does not call
preempt_schedule. But then I also noticed the flags of the call to
schedule_user(): "1.N..". This shows that it was running on cpu 1 with
NEED_RESCHED set (N), but both interrupts and preemption are enabled. If
an interrupt came in here we can schedule out again, but that would call
preempt_schedule_irq, which has code to check if its in "user context
(according to dynamic_ticks)" and would do the user_exit() too. But
something didn't seem right here.

Then I realized that it was actually the function tracer itself, as for
every function it traces, it calls preempt_disable() and
preempt_enable() to record the data on a per_cpu buffer. That
preempt_enable() noticed the NEED_RESCHED set and since preemption is
enabled, it kindly called preempt_schedule() for us!

All this before schedule_user() was able to call user_exit() and take us
out of dynamic tick user context.

I then looked at the code in entry_64.S, and noticed that the calls to
SCHEDULE_USER were all encompassed with ENABLE_INTERRUPTS and
DISABLE_INTERRUPTS before calling schedule. And the SCHEDULE_USER macro
is different if we have CONTEXT_TRACKING enabled or not.

I created a new schedule_irq_disabled() which is similar to
schedule_preempt_disable() and works like preempt_schedule_irq(), where
it includes the exception_enter() and exit() routines that take care of
the accounting of dynamic ticks when interrupting user mode or not. It
also takes care of it before enabling interrupts, so we don't need to
worry about any preemption happening at the wrong time.

Now the code always calls schedule_irq_disabled() whether or not
CONTEXT_TRACKING is configured, which cleans up entry_64.S and removes
the need of the context_tracking.h header file in asm.

Signed-off-by: Steven Rostedt <[email protected]>

Index: linux-trace.git/arch/x86/include/asm/context_tracking.h
===================================================================
--- linux-trace.git.orig/arch/x86/include/asm/context_tracking.h
+++ /dev/null
@@ -1,10 +0,0 @@
-#ifndef _ASM_X86_CONTEXT_TRACKING_H
-#define _ASM_X86_CONTEXT_TRACKING_H
-
-#ifdef CONFIG_CONTEXT_TRACKING
-# define SCHEDULE_USER call schedule_user
-#else
-# define SCHEDULE_USER call schedule
-#endif
-
-#endif
Index: linux-trace.git/arch/x86/kernel/entry_64.S
===================================================================
--- linux-trace.git.orig/arch/x86/kernel/entry_64.S
+++ linux-trace.git/arch/x86/kernel/entry_64.S
@@ -56,7 +56,6 @@
#include <asm/ftrace.h>
#include <asm/percpu.h>
#include <asm/asm.h>
-#include <asm/context_tracking.h>
#include <asm/smap.h>
#include <linux/err.h>

@@ -654,6 +653,7 @@ sysret_check:
LOCKDEP_SYS_EXIT
DISABLE_INTERRUPTS(CLBR_NONE)
TRACE_IRQS_OFF
+sysret_check_irqsoff:
movl TI_flags+THREAD_INFO(%rsp,RIP-ARGOFFSET),%edx
andl %edi,%edx
jnz sysret_careful
@@ -675,12 +675,10 @@ sysret_check:
sysret_careful:
bt $TIF_NEED_RESCHED,%edx
jnc sysret_signal
- TRACE_IRQS_ON
- ENABLE_INTERRUPTS(CLBR_NONE)
pushq_cfi %rdi
- SCHEDULE_USER
+ call schedule_irq_disabled
popq_cfi %rdi
- jmp sysret_check
+ jmp sysret_check_irqsoff

/* Handle a signal */
sysret_signal:
@@ -788,13 +786,9 @@ GLOBAL(int_with_check)
int_careful:
bt $TIF_NEED_RESCHED,%edx
jnc int_very_careful
- TRACE_IRQS_ON
- ENABLE_INTERRUPTS(CLBR_NONE)
pushq_cfi %rdi
- SCHEDULE_USER
+ call schedule_irq_disabled
popq_cfi %rdi
- DISABLE_INTERRUPTS(CLBR_NONE)
- TRACE_IRQS_OFF
jmp int_with_check

/* handle signals and tracing -- both require a full stack frame */
@@ -1088,14 +1082,10 @@ retint_careful:
CFI_RESTORE_STATE
bt $TIF_NEED_RESCHED,%edx
jnc retint_signal
- TRACE_IRQS_ON
- ENABLE_INTERRUPTS(CLBR_NONE)
pushq_cfi %rdi
- SCHEDULE_USER
+ call schedule_irq_disabled
popq_cfi %rdi
GET_THREAD_INFO(%rcx)
- DISABLE_INTERRUPTS(CLBR_NONE)
- TRACE_IRQS_OFF
jmp retint_check

retint_signal:
@@ -1534,11 +1524,7 @@ paranoid_userspace:
TRACE_IRQS_OFF
jmp paranoid_userspace
paranoid_schedule:
- TRACE_IRQS_ON
- ENABLE_INTERRUPTS(CLBR_ANY)
- SCHEDULE_USER
- DISABLE_INTERRUPTS(CLBR_ANY)
- TRACE_IRQS_OFF
+ call schedule_irq_disabled
jmp paranoid_userspace
CFI_ENDPROC
END(paranoid_exit)
Index: linux-trace.git/kernel/sched/core.c
===================================================================
--- linux-trace.git.orig/kernel/sched/core.c
+++ linux-trace.git/kernel/sched/core.c
@@ -3034,21 +3034,6 @@ asmlinkage void __sched schedule(void)
}
EXPORT_SYMBOL(schedule);

-#ifdef CONFIG_CONTEXT_TRACKING
-asmlinkage void __sched schedule_user(void)
-{
- /*
- * If we come here after a random call to set_need_resched(),
- * or we have been woken up remotely but the IPI has not yet arrived,
- * we haven't yet exited the RCU idle mode. Do it here manually until
- * we find a better solution.
- */
- user_exit();
- schedule();
- user_enter();
-}
-#endif
-
/**
* schedule_preempt_disabled - called with preemption disabled
*
@@ -3127,6 +3112,24 @@ asmlinkage void __sched preempt_schedule

#endif /* CONFIG_PREEMPT */

+/*
+ * this is the entry point to schedule() from kernel irq off context.
+ * Note, that this is called and return with irqs disabled. This will
+ * protect us against recursive calling from irq.
+ */
+asmlinkage void __sched schedule_irq_disabled(void)
+{
+ enum ctx_state prev_state;
+
+ prev_state = exception_enter();
+
+ local_irq_enable();
+ __schedule();
+ local_irq_disable();
+
+ exception_exit(prev_state);
+}
+
int default_wake_function(wait_queue_t *curr, unsigned mode, int wake_flags,
void *key)
{

2013-05-12 15:55:15

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

"Paul E. McKenney" <[email protected]> writes:
> On Sun, May 12, 2013 at 11:08:50AM +0200, Bjørn Mork wrote:
>> Hello,
>>
>> got the splat below when running powertop on plain v3.10-rc1
>> (i.e. without my previously mentioned revert patch or any other extra
>> patches). Config attached.
>
> OK, it looks like you have context-tracking enabled, so you might be
> hitting a bug that Steven Rostedt found a few days ago. Could you
> please try out his fix below?

Thanks for the quick reply, but I'm afraid that patch had no effect on
the warning I got. It's still there.

Bjørn

2013-05-12 17:21:42

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On Sun, May 12, 2013 at 05:55:00PM +0200, Bj?rn Mork wrote:
> "Paul E. McKenney" <[email protected]> writes:
> > On Sun, May 12, 2013 at 11:08:50AM +0200, Bj?rn Mork wrote:
> >> Hello,
> >>
> >> got the splat below when running powertop on plain v3.10-rc1
> >> (i.e. without my previously mentioned revert patch or any other extra
> >> patches). Config attached.
> >
> > OK, it looks like you have context-tracking enabled, so you might be
> > hitting a bug that Steven Rostedt found a few days ago. Could you
> > please try out his fix below?
>
> Thanks for the quick reply, but I'm afraid that patch had no effect on
> the warning I got. It's still there.

Other than wondering whether powertop has issues similar to the bug
Steven Rostedt located, I must confess myself clueless. Here are some
diagnostics I can suggest:

1. Run in 32-bit mode. This disables some of the new adaptive-ticks
functionality, so might give a probabilistic indication of where
the bug lies.

2. The standard fallback of bisection.

Would you be willing to do either of these?

Thanx, Paul

2013-05-12 18:19:48

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

"Paul E. McKenney" <[email protected]> writes:
> On Sun, May 12, 2013 at 05:55:00PM +0200, Bjørn Mork wrote:
>> "Paul E. McKenney" <[email protected]> writes:
>> > On Sun, May 12, 2013 at 11:08:50AM +0200, Bjørn Mork wrote:
>> >> Hello,
>> >>
>> >> got the splat below when running powertop on plain v3.10-rc1
>> >> (i.e. without my previously mentioned revert patch or any other extra
>> >> patches). Config attached.
>> >
>> > OK, it looks like you have context-tracking enabled, so you might be
>> > hitting a bug that Steven Rostedt found a few days ago. Could you
>> > please try out his fix below?
>>
>> Thanks for the quick reply, but I'm afraid that patch had no effect on
>> the warning I got. It's still there.
>
> Other than wondering whether powertop has issues similar to the bug
> Steven Rostedt located, I must confess myself clueless. Here are some
> diagnostics I can suggest:
>
> 1. Run in 32-bit mode. This disables some of the new adaptive-ticks
> functionality, so might give a probabilistic indication of where
> the bug lies.
>
> 2. The standard fallback of bisection.
>
> Would you be willing to do either of these?

Willing, yes. But it will take some time before I am able to do either
unless I can recreate the problem in a virtual machine. I assume that
you by " 32-bit mode" mean a 32bit kernel? I'm not exactly set up to
run that on my laptop. Bisection will be less work.

To be honest, I don't even know how old this thing is. It could be
totally unrelated to your recent changes for all I know. Running
powertop is something I do once every 6 kernel releases or something
like that...

I'll see what I can come up with. Thanks for your attention.

Bjørn

2013-05-12 20:58:47

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On Sun, May 12, 2013 at 08:19:34PM +0200, Bj?rn Mork wrote:
> "Paul E. McKenney" <[email protected]> writes:
> > On Sun, May 12, 2013 at 05:55:00PM +0200, Bj?rn Mork wrote:
> >> "Paul E. McKenney" <[email protected]> writes:
> >> > On Sun, May 12, 2013 at 11:08:50AM +0200, Bj?rn Mork wrote:
> >> >> Hello,
> >> >>
> >> >> got the splat below when running powertop on plain v3.10-rc1
> >> >> (i.e. without my previously mentioned revert patch or any other extra
> >> >> patches). Config attached.
> >> >
> >> > OK, it looks like you have context-tracking enabled, so you might be
> >> > hitting a bug that Steven Rostedt found a few days ago. Could you
> >> > please try out his fix below?
> >>
> >> Thanks for the quick reply, but I'm afraid that patch had no effect on
> >> the warning I got. It's still there.
> >
> > Other than wondering whether powertop has issues similar to the bug
> > Steven Rostedt located, I must confess myself clueless. Here are some
> > diagnostics I can suggest:
> >
> > 1. Run in 32-bit mode. This disables some of the new adaptive-ticks
> > functionality, so might give a probabilistic indication of where
> > the bug lies.
> >
> > 2. The standard fallback of bisection.
> >
> > Would you be willing to do either of these?
>
> Willing, yes. But it will take some time before I am able to do either
> unless I can recreate the problem in a virtual machine. I assume that
> you by " 32-bit mode" mean a 32bit kernel? I'm not exactly set up to
> run that on my laptop. Bisection will be less work.
>
> To be honest, I don't even know how old this thing is. It could be
> totally unrelated to your recent changes for all I know. Running
> powertop is something I do once every 6 kernel releases or something
> like that...
>
> I'll see what I can come up with. Thanks for your attention.

And thank you for the testing and information!

Thanx, Paul

2013-05-12 23:37:09

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

Bjørn Mork <[email protected]> writes:
> "Paul E. McKenney" <[email protected]> writes:
>
>> Other than wondering whether powertop has issues similar to the bug
>> Steven Rostedt located, I must confess myself clueless. Here are some
>> diagnostics I can suggest:
>>
>> 1. Run in 32-bit mode. This disables some of the new adaptive-ticks
>> functionality, so might give a probabilistic indication of where
>> the bug lies.
>>
>> 2. The standard fallback of bisection.
>>
>> Would you be willing to do either of these?
>
> Willing, yes. But it will take some time before I am able to do either
> unless I can recreate the problem in a virtual machine. I assume that
> you by " 32-bit mode" mean a 32bit kernel? I'm not exactly set up to
> run that on my laptop. Bisection will be less work.
>
> To be honest, I don't even know how old this thing is. It could be
> totally unrelated to your recent changes for all I know. Running
> powertop is something I do once every 6 kernel releases or something
> like that...
>
> I'll see what I can come up with. Thanks for your attention.

I was unable to recreate the problem in a virtual machine, which is
slightly suspicious. And bisecting it ended up pointing to a merge
commit:

commit ab86e974f04b1cd827a9c7c35273834ebcd9ab38
Merge: 8700c95 6f7a05d
Author: Linus Torvalds <[email protected]>
Date: Tue Apr 30 08:15:40 2013 -0700

Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
..

which I don't think makes much sense at all. The bisect log leading to
this was:

bjorn@canardo:/usr/local/src/build-tmp/linux$ git bisect log
# bad: [f722406faae2d073cc1d01063d1123c35425939e] Linux 3.10-rc1
# good: [c1be5a5b1b355d40e6cf79cc979eb66dafa24ad1] Linux 3.9
git bisect start 'v3.10-rc1' 'v3.9'
# bad: [73287a43cc79ca06629a88d1a199cd283f42456a] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next
git bisect bad 73287a43cc79ca06629a88d1a199cd283f42456a
# bad: [5d434fcb255dec99189f1c58a06e4f56e12bf77d] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jikos/trivial
git bisect bad 5d434fcb255dec99189f1c58a06e4f56e12bf77d
# good: [507ffe4f3840ac24890a8123c702cf1b7fe4d33c] Merge tag 'tty-3.10-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty
git bisect good 507ffe4f3840ac24890a8123c702cf1b7fe4d33c
# good: [4a7b4d2360175f67ab2c58effeeb8362a3057c25] x86: pageattr-test: remove srandom32 call
git bisect good 4a7b4d2360175f67ab2c58effeeb8362a3057c25
# good: [46d9be3e5eb01f71fc02653755d970247174b400] Merge branch 'for-3.10' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq
git bisect good 46d9be3e5eb01f71fc02653755d970247174b400
# good: [e0972916e8fe943f342b0dd1c9d43dbf5bc261c2] Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good e0972916e8fe943f342b0dd1c9d43dbf5bc261c2
# bad: [ab86e974f04b1cd827a9c7c35273834ebcd9ab38] Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad ab86e974f04b1cd827a9c7c35273834ebcd9ab38
# good: [8700c95adb033843fc163d112b9d21d4fda78018] Merge branch 'smp-hotplug-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 8700c95adb033843fc163d112b9d21d4fda78018
# good: [0ed2aef9b3bffe598045b62a31a50d912eee92d8] Merge branch 'fortglx/3.10/time' of git://git.linaro.org/people/jstultz/linux into timers/core
git bisect good 0ed2aef9b3bffe598045b62a31a50d912eee92d8
# good: [8f294b5a139ee4b75e890ad5b443c93d1e558a8b] hrtimer: Add expiry time overflow check in hrtimer_interrupt
git bisect good 8f294b5a139ee4b75e890ad5b443c93d1e558a8b
# good: [60cf7ea849e77c8782dee147cfb8c38d1984236e] timer_list: Split timer_list_show_tickdevices
git bisect good 60cf7ea849e77c8782dee147cfb8c38d1984236e
# good: [d2054b2c11682495fca41e9d4092e654df63b517] posix-timers: Remove unused variable
git bisect good d2054b2c11682495fca41e9d4092e654df63b517
# good: [6402c7dc2a19c19bd8cdc7d80878b850da418942] Merge branch 'linus' into timers/core Reason: Get upstream fixes before adding conflicting code.
git bisect good 6402c7dc2a19c19bd8cdc7d80878b850da418942
# good: [6f7a05d7018de222e40ca003721037a530979974] clockevents: Set dummy handler on CPU_DEAD shutdown
git bisect good 6f7a05d7018de222e40ca003721037a530979974

So there it stands. I have no clue and I don't think I'm able to
provide any clue for anyone else either. Given that the problem seems
to be very consistently reproducible on my laptop, I am a bit puzzled as
to how the bisect would fail like that.

Bjørn

2013-05-13 14:41:21

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

Bjørn Mork <[email protected]> writes:

> I was unable to recreate the problem in a virtual machine, which is
> slightly suspicious. And bisecting it ended up pointing to a merge
> commit:
>
> commit ab86e974f04b1cd827a9c7c35273834ebcd9ab38
> Merge: 8700c95 6f7a05d
> Author: Linus Torvalds <[email protected]>
> Date: Tue Apr 30 08:15:40 2013 -0700
>
> Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> ..
>
>
> which I don't think makes much sense at all. The bisect log leading to
> this was:
>
> bjorn@canardo:/usr/local/src/build-tmp/linux$ git bisect log
> # bad: [f722406faae2d073cc1d01063d1123c35425939e] Linux 3.10-rc1
> # good: [c1be5a5b1b355d40e6cf79cc979eb66dafa24ad1] Linux 3.9
> git bisect start 'v3.10-rc1' 'v3.9'
> # bad: [73287a43cc79ca06629a88d1a199cd283f42456a] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next
> git bisect bad 73287a43cc79ca06629a88d1a199cd283f42456a
> # bad: [5d434fcb255dec99189f1c58a06e4f56e12bf77d] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jikos/trivial
> git bisect bad 5d434fcb255dec99189f1c58a06e4f56e12bf77d
> # good: [507ffe4f3840ac24890a8123c702cf1b7fe4d33c] Merge tag 'tty-3.10-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty
> git bisect good 507ffe4f3840ac24890a8123c702cf1b7fe4d33c
> # good: [4a7b4d2360175f67ab2c58effeeb8362a3057c25] x86: pageattr-test: remove srandom32 call
> git bisect good 4a7b4d2360175f67ab2c58effeeb8362a3057c25
> # good: [46d9be3e5eb01f71fc02653755d970247174b400] Merge branch 'for-3.10' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq
> git bisect good 46d9be3e5eb01f71fc02653755d970247174b400
> # good: [e0972916e8fe943f342b0dd1c9d43dbf5bc261c2] Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect good e0972916e8fe943f342b0dd1c9d43dbf5bc261c2
> # bad: [ab86e974f04b1cd827a9c7c35273834ebcd9ab38] Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect bad ab86e974f04b1cd827a9c7c35273834ebcd9ab38
> # good: [8700c95adb033843fc163d112b9d21d4fda78018] Merge branch 'smp-hotplug-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect good 8700c95adb033843fc163d112b9d21d4fda78018
> # good: [0ed2aef9b3bffe598045b62a31a50d912eee92d8] Merge branch 'fortglx/3.10/time' of git://git.linaro.org/people/jstultz/linux into timers/core
> git bisect good 0ed2aef9b3bffe598045b62a31a50d912eee92d8
> # good: [8f294b5a139ee4b75e890ad5b443c93d1e558a8b] hrtimer: Add expiry time overflow check in hrtimer_interrupt
> git bisect good 8f294b5a139ee4b75e890ad5b443c93d1e558a8b
> # good: [60cf7ea849e77c8782dee147cfb8c38d1984236e] timer_list: Split timer_list_show_tickdevices
> git bisect good 60cf7ea849e77c8782dee147cfb8c38d1984236e
> # good: [d2054b2c11682495fca41e9d4092e654df63b517] posix-timers: Remove unused variable
> git bisect good d2054b2c11682495fca41e9d4092e654df63b517
> # good: [6402c7dc2a19c19bd8cdc7d80878b850da418942] Merge branch 'linus' into timers/core Reason: Get upstream fixes before adding conflicting code.
> git bisect good 6402c7dc2a19c19bd8cdc7d80878b850da418942
> # good: [6f7a05d7018de222e40ca003721037a530979974] clockevents: Set dummy handler on CPU_DEAD shutdown
> git bisect good 6f7a05d7018de222e40ca003721037a530979974
>
>
> So there it stands. I have no clue and I don't think I'm able to
> provide any clue for anyone else either. Given that the problem seems
> to be very consistently reproducible on my laptop, I am a bit puzzled as
> to how the bisect would fail like that.

Hey, hey, hey. Turns out this wasn't that wrong after all. That merge
includes a oneline diff in kernel/cpu/idle.c and it *is* actually this
diff which trigger the problem for me. Reverting it, using the attached
patch, makes the warning go away. Which means that it had nothing to do
with your RCU changes.

But I haven't the faintest idea how this is supposed to work, or even
how to explain the patch properly, so I think I need some help from
Thomas here. Unless this makes you understand the real issue?

Thomas, why does powertop trigger the

WARNING: at kernel/rcutree.c:502 rcu_eqs_exit_common.isra.48+0x3d/0x125()

without the attached patch? And what is the proper resolution?

Bjørn

Attachments:

0001-idle-prevent-rcu_eqs_exit_common-warning.patch (3.36 kB)

2013-05-13 22:34:37

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On 05/13/2013 08:09 PM, Bjørn Mork wrote:
> Bjørn Mork <[email protected]> writes:
>
>> I was unable to recreate the problem in a virtual machine, which is
>> slightly suspicious. And bisecting it ended up pointing to a merge
>> commit:
>>
>> commit ab86e974f04b1cd827a9c7c35273834ebcd9ab38
>> Merge: 8700c95 6f7a05d
>> Author: Linus Torvalds <[email protected]>
>> Date: Tue Apr 30 08:15:40 2013 -0700
>>
>> Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> ..
>>
>>
>> which I don't think makes much sense at all. The bisect log leading to
>> this was:
>>
>> bjorn@canardo:/usr/local/src/build-tmp/linux$ git bisect log
>> # bad: [f722406faae2d073cc1d01063d1123c35425939e] Linux 3.10-rc1
>> # good: [c1be5a5b1b355d40e6cf79cc979eb66dafa24ad1] Linux 3.9
>> git bisect start 'v3.10-rc1' 'v3.9'
>> # bad: [73287a43cc79ca06629a88d1a199cd283f42456a] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next
>> git bisect bad 73287a43cc79ca06629a88d1a199cd283f42456a
>> # bad: [5d434fcb255dec99189f1c58a06e4f56e12bf77d] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jikos/trivial
>> git bisect bad 5d434fcb255dec99189f1c58a06e4f56e12bf77d
>> # good: [507ffe4f3840ac24890a8123c702cf1b7fe4d33c] Merge tag 'tty-3.10-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty
>> git bisect good 507ffe4f3840ac24890a8123c702cf1b7fe4d33c
>> # good: [4a7b4d2360175f67ab2c58effeeb8362a3057c25] x86: pageattr-test: remove srandom32 call
>> git bisect good 4a7b4d2360175f67ab2c58effeeb8362a3057c25
>> # good: [46d9be3e5eb01f71fc02653755d970247174b400] Merge branch 'for-3.10' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq
>> git bisect good 46d9be3e5eb01f71fc02653755d970247174b400
>> # good: [e0972916e8fe943f342b0dd1c9d43dbf5bc261c2] Merge branch 'perf-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect good e0972916e8fe943f342b0dd1c9d43dbf5bc261c2
>> # bad: [ab86e974f04b1cd827a9c7c35273834ebcd9ab38] Merge branch 'timers-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect bad ab86e974f04b1cd827a9c7c35273834ebcd9ab38
>> # good: [8700c95adb033843fc163d112b9d21d4fda78018] Merge branch 'smp-hotplug-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect good 8700c95adb033843fc163d112b9d21d4fda78018
>> # good: [0ed2aef9b3bffe598045b62a31a50d912eee92d8] Merge branch 'fortglx/3.10/time' of git://git.linaro.org/people/jstultz/linux into timers/core
>> git bisect good 0ed2aef9b3bffe598045b62a31a50d912eee92d8
>> # good: [8f294b5a139ee4b75e890ad5b443c93d1e558a8b] hrtimer: Add expiry time overflow check in hrtimer_interrupt
>> git bisect good 8f294b5a139ee4b75e890ad5b443c93d1e558a8b
>> # good: [60cf7ea849e77c8782dee147cfb8c38d1984236e] timer_list: Split timer_list_show_tickdevices
>> git bisect good 60cf7ea849e77c8782dee147cfb8c38d1984236e
>> # good: [d2054b2c11682495fca41e9d4092e654df63b517] posix-timers: Remove unused variable
>> git bisect good d2054b2c11682495fca41e9d4092e654df63b517
>> # good: [6402c7dc2a19c19bd8cdc7d80878b850da418942] Merge branch 'linus' into timers/core Reason: Get upstream fixes before adding conflicting code.
>> git bisect good 6402c7dc2a19c19bd8cdc7d80878b850da418942
>> # good: [6f7a05d7018de222e40ca003721037a530979974] clockevents: Set dummy handler on CPU_DEAD shutdown
>> git bisect good 6f7a05d7018de222e40ca003721037a530979974
>>
>>
>> So there it stands. I have no clue and I don't think I'm able to
>> provide any clue for anyone else either. Given that the problem seems
>> to be very consistently reproducible on my laptop, I am a bit puzzled as
>> to how the bisect would fail like that.
>
> Hey, hey, hey. Turns out this wasn't that wrong after all. That merge
> includes a oneline diff in kernel/cpu/idle.c and it *is* actually this
> diff which trigger the problem for me. Reverting it, using the attached
> patch, makes the warning go away. Which means that it had nothing to do
> with your RCU changes.
>
> But I haven't the faintest idea how this is supposed to work, or even
> how to explain the patch properly, so I think I need some help from
> Thomas here. Unless this makes you understand the real issue?
>
> Thomas, why does powertop trigger the
>
> WARNING: at kernel/rcutree.c:502 rcu_eqs_exit_common.isra.48+0x3d/0x125()
>
> without the attached patch? And what is the proper resolution?
>

The problem appears to be in the cpu idle poll implementation. You can trigger
this problem by passing idle=poll in the kernel cmd-line as well, right?

I think I understand what is going on here. Can you please try the fix below?
(It is only compile-tested since its very late here and I really need to get
some sleep!).

Regards,
Srivatsa S. Bhat

----------------------------------------------------------------------->

From: Srivatsa S. Bhat <[email protected]>
Subject: [PATCH] rcu/idle: Wrap cpu-idle poll mode within rcu_idle_enter/exit

Bjørn Mork reported the following warning when running powertop.

[ 49.289034] ------------[ cut here ]------------
[ 49.289055] WARNING: at kernel/rcutree.c:502 rcu_eqs_exit_common.isra.48+0x3d/0x125()
[ 49.289059] Modules linked in: msr cpufreq_stats xt_multiport iptable_filter ip_tables rfcomm bnep xt_hl binfmt_misc ip6table_filter ip6_tables x_tables nfsd nfs_acl nfs lockd fscache sunrpc 8021q garp stp llc tun cdc_mbim cdc_ncm cdc_wdm usbnet mii loop fuse btusb bluetooth iTCO_wdt iTCO_vendor_support snd_hda_codec_conexant arc4 iwldvm mac80211 thinkpad_acpi nvram snd_seq_midi snd_seq_midi_event snd_rawmidi snd_hda_intel snd_seq snd_hda_codec snd_hwdep snd_pcm_oss snd_mixer_oss iwlwifi snd_pcm coretemp kvm_intel kvm snd_seq_device evdev psmouse serio_raw lpc_ich mfd_core cfg80211 snd_page_alloc i2c_i801 snd_timer snd soundcore rfkill battery ac acpi_cpufreq mperf i915 wmi video i2c_algo_bit drm_kms_helper button drm i2c_core processor ext4 crc16 jbd2 mbcache nbd sg sr_mod cdrom sd_mod crc_t10dif ahci libahci libata microcode scsi_mod ehci_pci uhci_hcd ehci_hcd usbcore usb_common thermal thermal_sys e1000e ptp pps_core
[ 49.289244] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.10.0-bisect-rcu-warn+ #107
[ 49.289247] Hardware name: LENOVO 2776LEG/2776LEG, BIOS 6EET55WW (3.15 ) 12/19/2011
[ 49.289251] ffffffff8157d8c8 ffffffff81801e28 ffffffff8137e4e3 ffffffff81801e68
[ 49.289260] ffffffff8103094f ffffffff81801e68 0000000000000000 ffff88023afcd9b0
[ 49.289268] 0000000000000000 0140000000000000 ffff88023bee7700 ffffffff81801e78
[ 49.289276] Call Trace:
[ 49.289285] [<ffffffff8137e4e3>] dump_stack+0x19/0x1b
[ 49.289293] [<ffffffff8103094f>] warn_slowpath_common+0x62/0x7b
[ 49.289300] [<ffffffff8103097d>] warn_slowpath_null+0x15/0x17
[ 49.289306] [<ffffffff810a9006>] rcu_eqs_exit_common.isra.48+0x3d/0x125
[ 49.289314] [<ffffffff81079b49>] ? trace_hardirqs_off_caller+0x37/0xa6
[ 49.289320] [<ffffffff810a9692>] rcu_idle_exit+0x85/0xa8
[ 49.289327] [<ffffffff8107076e>] trace_cpu_idle_rcuidle+0xae/0xff
[ 49.289334] [<ffffffff810708b1>] cpu_startup_entry+0x72/0x115
[ 49.289341] [<ffffffff813689e5>] rest_init+0x149/0x150
[ 49.289347] [<ffffffff8136889c>] ? csum_partial_copy_generic+0x16c/0x16c
[ 49.289355] [<ffffffff81a82d34>] start_kernel+0x3f0/0x3fd
[ 49.289362] [<ffffffff81a8274c>] ? repair_env_string+0x5a/0x5a
[ 49.289368] [<ffffffff81a82481>] x86_64_start_reservations+0x2a/0x2c
[ 49.289375] [<ffffffff81a82550>] x86_64_start_kernel+0xcd/0xd1
[ 49.289379] ---[ end trace 07a1cc95e29e9036 ]---

The warning is that 'rdtp->dynticks' has an unexpected value, which roughly
translates to - the calls to rcu_idle_enter() and rcu_idle_exit() were not
made in the correct order, or otherwise messed up.

And Bjørn's painstaking debugging indicated that this happens when the idle
loop enters the poll mode. Looking at the poll function cpu_idle_poll(), and
the implementation of trace_cpu_idle_rcuidle(), the problem becomes very clear:
cpu_idle_poll() lacks calls to rcu_idle_enter/exit(), and trace_cpu_idle_rcuidle()
calls them in the reverse order - first rcu_idle_exit(), and then rcu_idle_enter().
Hence the even/odd alternative sequencing of rdtp->dynticks goes for a toss.

And powertop readily triggers this because powertop uses the idle-tracing
infrastructure extensively.

So, to fix this, wrap the code in cpu_idle_poll() within rcu_idle_enter/exit(),
so that it blends properly with the calls inside trace_cpu_idle_rcuidle() and
thus get the function ordering right.

Reported-by: Bjørn Mork <[email protected]>
Cc: Thomas Gleixner <[email protected]>
Cc: Paul McKenney <[email protected]>
Cc: Steven Rostedt <[email protected]>
Signed-off-by: Srivatsa S. Bhat <[email protected]>
---

kernel/cpu/idle.c | 2 ++
1 file changed, 2 insertions(+)

diff --git a/kernel/cpu/idle.c b/kernel/cpu/idle.c
index 8b86c0c..d5585f5 100644
--- a/kernel/cpu/idle.c
+++ b/kernel/cpu/idle.c
@@ -40,11 +40,13 @@ __setup("hlt", cpu_idle_nopoll_setup);

static inline int cpu_idle_poll(void)
{
+ rcu_idle_enter();
trace_cpu_idle_rcuidle(0, smp_processor_id());
local_irq_enable();
while (!need_resched())
cpu_relax();
trace_cpu_idle_rcuidle(PWR_EVENT_EXIT, smp_processor_id());
+ rcu_idle_exit();
return 1;
}

2013-05-14 07:39:50

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

"Srivatsa S. Bhat" <[email protected]> writes:
> On 05/13/2013 08:09 PM, Bjørn Mork wrote:
>
>> Hey, hey, hey. Turns out this wasn't that wrong after all. That merge
>> includes a oneline diff in kernel/cpu/idle.c and it *is* actually this
>> diff which trigger the problem for me. Reverting it, using the attached
>> patch, makes the warning go away. Which means that it had nothing to do
>> with your RCU changes.
>>
>> But I haven't the faintest idea how this is supposed to work, or even
>> how to explain the patch properly, so I think I need some help from
>> Thomas here. Unless this makes you understand the real issue?
>>
>> Thomas, why does powertop trigger the
>>
>> WARNING: at kernel/rcutree.c:502 rcu_eqs_exit_common.isra.48+0x3d/0x125()
>>
>> without the attached patch? And what is the proper resolution?
>>
>
> The problem appears to be in the cpu idle poll implementation. You can trigger
> this problem by passing idle=poll in the kernel cmd-line as well, right?

That sounded so obvious that it made me think "Doh, why didn't I just
test that before?" But unfortunately there must be some other factor
involved. No warnings observed during normal use when running with
idle=poll:

bjorn@nemi:~$ dmesg|grep polling
[ 0.000000] process: using polling idle threads

I expected a flood of warnings here, but there is none until I start
powertop (to confirm that the original issue is still there). So it's
more than just entering cpu_idle_poll().

> I think I understand what is going on here. Can you please try the fix below?
> (It is only compile-tested since its very late here and I really need to get
> some sleep!).

Works perfect. Thanks. I assume this is the correct fix even if the
problem isn't completely understood?

Bjørn

2013-05-14 07:49:57

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On 05/14/2013 01:08 PM, Bjørn Mork wrote:
> "Srivatsa S. Bhat" <[email protected]> writes:
>> On 05/13/2013 08:09 PM, Bjørn Mork wrote:
>>
>>> Hey, hey, hey. Turns out this wasn't that wrong after all. That merge
>>> includes a oneline diff in kernel/cpu/idle.c and it *is* actually this
>>> diff which trigger the problem for me. Reverting it, using the attached
>>> patch, makes the warning go away. Which means that it had nothing to do
>>> with your RCU changes.
>>>
>>> But I haven't the faintest idea how this is supposed to work, or even
>>> how to explain the patch properly, so I think I need some help from
>>> Thomas here. Unless this makes you understand the real issue?
>>>
>>> Thomas, why does powertop trigger the
>>>
>>> WARNING: at kernel/rcutree.c:502 rcu_eqs_exit_common.isra.48+0x3d/0x125()
>>>
>>> without the attached patch? And what is the proper resolution?
>>>
>>
>> The problem appears to be in the cpu idle poll implementation. You can trigger
>> this problem by passing idle=poll in the kernel cmd-line as well, right?
>
> That sounded so obvious that it made me think "Doh, why didn't I just
> test that before?" But unfortunately there must be some other factor
> involved. No warnings observed during normal use when running with
> idle=poll:
>

I didn't expect warnings with normal use.

> bjorn@nemi:~$ dmesg|grep polling
> [ 0.000000] process: using polling idle threads
>
>
> I expected a flood of warnings here, but there is none until I start
> powertop (to confirm that the original issue is still there). So it's
> more than just entering cpu_idle_poll().
>

Yeah, of course it is :-) The warning triggers only when you enable the tracepoint
in the idle code. And in your case, powertop does that. That's why it only
triggers when you run powertop. Alternatively, if you enable the tracepoint
yourself manually, I bet you'll see the warnings, even without using powertop.

>> I think I understand what is going on here. Can you please try the fix below?
>> (It is only compile-tested since its very late here and I really need to get
>> some sleep!).
>
> Works perfect. Thanks.

Thanks for your testing!

> I assume this is the correct fix even if the
> problem isn't completely understood?
>

Hmm? Why do you say the problem isn't completely understood? I thought I
explained the problem in my changelog. Did I miss something?

Regards,
Srivatsa S. Bhat

2013-05-14 07:54:17

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On 05/14/2013 01:16 PM, Srivatsa S. Bhat wrote:
> On 05/14/2013 01:08 PM, Bjørn Mork wrote:
>> "Srivatsa S. Bhat" <[email protected]> writes:
>>> On 05/13/2013 08:09 PM, Bjørn Mork wrote:
>>>
>>>> Hey, hey, hey. Turns out this wasn't that wrong after all. That merge
>>>> includes a oneline diff in kernel/cpu/idle.c and it *is* actually this
>>>> diff which trigger the problem for me. Reverting it, using the attached
>>>> patch, makes the warning go away. Which means that it had nothing to do
>>>> with your RCU changes.
>>>>
>>>> But I haven't the faintest idea how this is supposed to work, or even
>>>> how to explain the patch properly, so I think I need some help from
>>>> Thomas here. Unless this makes you understand the real issue?
>>>>
>>>> Thomas, why does powertop trigger the
>>>>
>>>> WARNING: at kernel/rcutree.c:502 rcu_eqs_exit_common.isra.48+0x3d/0x125()
>>>>
>>>> without the attached patch? And what is the proper resolution?
>>>>
>>>
>>> The problem appears to be in the cpu idle poll implementation. You can trigger
>>> this problem by passing idle=poll in the kernel cmd-line as well, right?
>>
>> That sounded so obvious that it made me think "Doh, why didn't I just
>> test that before?" But unfortunately there must be some other factor
>> involved. No warnings observed during normal use when running with
>> idle=poll:
>>
>
> I didn't expect warnings with normal use.
>
>> bjorn@nemi:~$ dmesg|grep polling
>> [ 0.000000] process: using polling idle threads
>>
>>
>> I expected a flood of warnings here, but there is none until I start
>> powertop (to confirm that the original issue is still there). So it's
>> more than just entering cpu_idle_poll().
>>
>
> Yeah, of course it is :-) The warning triggers only when you enable the tracepoint
> in the idle code. And in your case, powertop does that. That's why it only
> triggers when you run powertop. Alternatively, if you enable the tracepoint
> yourself manually, I bet you'll see the warnings, even without using powertop.
>

IOW, what I wanted to confirm with you was my theory that this problem has got
nothing to do with the tick_check_broadcast_expired() check. That check only increases
the probability of entering the buggy polling code during normal use (since nobody
uses idle=poll in the kernel cmdline usually). That's why I requested you to try
running powertop by using idle=poll, to rule out the tick_check_broadcast_expired()
check from the equation.

But now that you confirmed it, everything fits perfectly! Thanks a lot!

Regards,
Srivatsa S. Bhat

2013-05-14 08:21:16

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

"Srivatsa S. Bhat" <[email protected]> writes:
> On 05/14/2013 01:08 PM, Bjørn Mork wrote:
>> "Srivatsa S. Bhat" <[email protected]> writes:
>>
>>> The problem appears to be in the cpu idle poll implementation. You can trigger
>>> this problem by passing idle=poll in the kernel cmd-line as well, right?
>>
>> That sounded so obvious that it made me think "Doh, why didn't I just
>> test that before?" But unfortunately there must be some other factor
>> involved. No warnings observed during normal use when running with
>> idle=poll:
>>
>
> I didn't expect warnings with normal use.
>
>> bjorn@nemi:~$ dmesg|grep polling
>> [ 0.000000] process: using polling idle threads
>>
>>
>> I expected a flood of warnings here, but there is none until I start
>> powertop (to confirm that the original issue is still there). So it's
>> more than just entering cpu_idle_poll().
>>
>
> Yeah, of course it is :-) The warning triggers only when you enable the tracepoint
> in the idle code. And in your case, powertop does that. That's why it only
> triggers when you run powertop. Alternatively, if you enable the tracepoint
> yourself manually, I bet you'll see the warnings, even without using powertop.

Ah, right. That sounds so obvious I have to go "Doh!" again:)

>>> I think I understand what is going on here. Can you please try the fix below?
>>> (It is only compile-tested since its very late here and I really need to get
>>> some sleep!).
>>
>> Works perfect. Thanks.
>
> Thanks for your testing!
>
>> I assume this is the correct fix even if the
>> problem isn't completely understood?
>>
>
> Hmm? Why do you say the problem isn't completely understood? I thought I
> explained the problem in my changelog. Did I miss something?

No, I did. I didn't understand the tracepoint part of this. But it is
all perfectly clear to me too now, after your excellent explanation
above.

Thanks,
Bjørn

2013-05-14 08:24:19

[permalink] [raw]

Subject: Re: [v3.10-rc1] WARNING: at kernel/rcutree.c:502

On 05/14/2013 01:50 PM, Bjørn Mork wrote:
> "Srivatsa S. Bhat" <[email protected]> writes:
>> On 05/14/2013 01:08 PM, Bjørn Mork wrote:
>>> "Srivatsa S. Bhat" <[email protected]> writes:
>>>
>>>> The problem appears to be in the cpu idle poll implementation. You can trigger
>>>> this problem by passing idle=poll in the kernel cmd-line as well, right?
>>>
>>> That sounded so obvious that it made me think "Doh, why didn't I just
>>> test that before?" But unfortunately there must be some other factor
>>> involved. No warnings observed during normal use when running with
>>> idle=poll:
>>>
>>
>> I didn't expect warnings with normal use.
>>
>>> bjorn@nemi:~$ dmesg|grep polling
>>> [ 0.000000] process: using polling idle threads
>>>
>>>
>>> I expected a flood of warnings here, but there is none until I start
>>> powertop (to confirm that the original issue is still there). So it's
>>> more than just entering cpu_idle_poll().
>>>
>>
>> Yeah, of course it is :-) The warning triggers only when you enable the tracepoint
>> in the idle code. And in your case, powertop does that. That's why it only
>> triggers when you run powertop. Alternatively, if you enable the tracepoint
>> yourself manually, I bet you'll see the warnings, even without using powertop.
>
> Ah, right. That sounds so obvious I have to go "Doh!" again:)
>

:-)

>>>> I think I understand what is going on here. Can you please try the fix below?
>>>> (It is only compile-tested since its very late here and I really need to get
>>>> some sleep!).
>>>
>>> Works perfect. Thanks.
>>
>> Thanks for your testing!
>>
>>> I assume this is the correct fix even if the
>>> problem isn't completely understood?
>>>
>>
>> Hmm? Why do you say the problem isn't completely understood? I thought I
>> explained the problem in my changelog. Did I miss something?
>
> No, I did. I didn't understand the tracepoint part of this. But it is
> all perfectly clear to me too now, after your excellent explanation
> above.
>

Great! Thanks :)

Regards,
Srivatsa S. Bhat

2013-05-14 10:25:05