linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
@ 2012-10-26  2:51 he, bo
  2012-10-26  8:51 ` Yanmin Zhang
  2012-10-26  9:55 ` Thomas Gleixner
  0 siblings, 2 replies; 6+ messages in thread
From: he, bo @ 2012-10-26  2:51 UTC (permalink / raw)
  To: Thomas Gleixner, linux-kernel, Peter Zijlstra, Ingo Molnar, yanmin_zhang
  Cc: yanmin.zhang

From: Yanmin Zhang <yanmin.zhang@intel.com>

We hit a kernel panic at __run_hrtimer=>BUG_ON(timer->state != HRTIMER_STATE_CALLBACK).
<2>[   10.226053, 3] kernel BUG at /home/android/xiaobing/ymz/r4/hardware/intel/linux-2.6/kernel/hrtimer.c:1228!
<0>[   10.235682, 3] invalid opcode: 0000 [#1] PREEMPT SMP
<4>[   10.240716, 3] Modules linked in: wl12xx_sdio wl12xx mac80211 cfg80211 compat btwilink rmi4(C) fmdrv_chr st_drv matrix(C)
<4>[   10.251651, 3]
<4>[   10.253391, 3] Pid: 68, comm: kworker/3:4 Tainted: G        WC  3.0.34-140430-g2af538d #45 Intel Corporation CloverTrail/FFRD
<4>[   10.264674, 3] EIP: 0060:[<c126c7ed>] EFLAGS: 00010002 CPU: 3
<4>[   10.270411, 3] EIP is at __run_hrtimer+0xbd/0x240
<4>[   10.275091, 3] EAX: 00000001 EBX: f67fb6b8 ECX: f57b4000 EDX: 00007301
<4>[   10.281602, 3] ESI: c1d614c0 EDI: f67fb680 EBP: f57b5dd8 ESP: f57b5da8
<4>[   10.288113, 3]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
<0>[   10.293754, 3] Process kworker/3:4 (pid: 68, ti=f57b4000 task=f57aa730 task.ti=f57b4000)
<0>[   10.301827, 3] Stack:
<4>[   10.304083, 3]  00000000 c1afef40 f57b5dd8 c167a6e0 f67fb680 20b366e3 f67fb6b8 f57b5e14
<4>[   10.312069, 3]  00000001 f67fb6b8 00000001 f67fb680 f57b5e28 c126d1e5 f57b5e08 c126f325
<4>[   10.320055, 3]  00000000 86b9868d 00000001 86b9868d 00000001 00000003 ffffffff 7fffffff
<0>[   10.328041, 3] Call Trace:
<4>[   10.330742, 3]  [<c167a6e0>] ? gburst_thread_stop.isra.25+0x40/0x40
<4>[   10.336988, 3]  [<c126d1e5>] hrtimer_interrupt+0xd5/0x250
<4>[   10.342368, 3]  [<c126f325>] ? sched_clock_cpu+0xe5/0x150
<4>[   10.347753, 3]  [<c1871d44>] smp_apic_timer_interrupt+0x54/0x88
<4>[   10.353654, 3]  [<c1496558>] ? trace_hardirqs_off_thunk+0xc/0x14
<4>[   10.359643, 3]  [<c186be9f>] apic_timer_interrupt+0x2f/0x34
<4>[   10.365199, 3]  [<c186e60f>] ? sub_preempt_count+0x1f/0x50
<4>[   10.370669, 3]  [<c149558a>] delay_tsc+0x3a/0xc0
<6>[   10.371589, 0] android_work: did not send uevent (0 0   (null))
<4>[   10.381171, 3]  [<c14954e3>] __const_udelay+0x23/0x30
<4>[   10.386207, 3]  [<c16d043a>] mdfld_dsi_send_dcs+0x12a/0x5d0
<4>[   10.391760, 3]  [<c186b6c6>] ? _raw_spin_unlock_irqrestore+0x26/0x50
<4>[   10.398101, 3]  [<c16af431>] ? ospm_power_using_hw_begin+0xa1/0x350
<4>[   10.399053, 3]  [<c186a49f>] ? __mutex_lock_slowpath+0x1ff/0x2f0
<4>[   10.399069, 3]  [<c16bd59e>] mdfld_dbi_update_panel+0x21e/0x2d0
<4>[   10.399085, 3]  [<c16b1ae1>] mdfld_te_handler_work+0x71/0x80
<4>[   10.399099, 3]  [<c12642be>] process_one_work+0xfe/0x3f0
<4>[   10.399114, 3]  [<c16b1a70>] ? mdfld_async_flip_te_handler+0xf0/0xf0

Basically, __run_hrtimer has a race with enqueue_hrtimer. When __run_hrtimer calls
the timer callback fn, another thread might call enqueue_hrtimer or hrtimer_start
to requeue it, and the timer->state is equal to HRTIMER_STATE_CALLBACK|HRTIMER_STATE_ENQUEUED,
which causes the BUG_ON(timer->state != HRTIMER_STATE_CALLBACK) checking fails.

The patch fixes it by checking only bit HRTIMER_STATE_CALLBACK.

Signed-off-by: Yanmin Zhang <yanmin.zhang@intel.com>
Reviewed-by: He, Bo <bo.he@intel.com>
---
 kernel/hrtimer.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
index 6db7a5e..6280184 100644
--- a/kernel/hrtimer.c
+++ b/kernel/hrtimer.c
@@ -1235,7 +1235,7 @@ static void __run_hrtimer(struct hrtimer *timer, ktime_t *now)
 	 * hrtimer_start_range_ns() or in hrtimer_interrupt()
 	 */
 	if (restart != HRTIMER_NORESTART) {
-		BUG_ON(timer->state != HRTIMER_STATE_CALLBACK);
+		BUG_ON(!(timer->state & HRTIMER_STATE_CALLBACK));
 		enqueue_hrtimer(timer, base);
 	}
 
-- 
1.7.6




^ permalink raw reply related	[flat|nested] 6+ messages in thread

* Re: [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
  2012-10-26  2:51 [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer he, bo
@ 2012-10-26  8:51 ` Yanmin Zhang
  2012-10-26  9:55 ` Thomas Gleixner
  1 sibling, 0 replies; 6+ messages in thread
From: Yanmin Zhang @ 2012-10-26  8:51 UTC (permalink / raw)
  To: he, bo
  Cc: Thomas Gleixner, linux-kernel, Peter Zijlstra, Ingo Molnar, yanmin.zhang

On Fri, 2012-10-26 at 10:51 +0800, he, bo wrote:
> From: Yanmin Zhang <yanmin.zhang@intel.com>
> 
> We hit a kernel panic at __run_hrtimer=>BUG_ON(timer->state != HRTIMER_STATE_CALLBACK).
> <2>[   10.226053, 3] kernel BUG at /home/android/xiaobing/ymz/r4/hardware/intel/linux-2.6/kernel/hrtimer.c:1228!
> <0>[   10.235682, 3] invalid opcode: 0000 [#1] PREEMPT SMP
> <4>[   10.240716, 3] Modules linked in: wl12xx_sdio wl12xx mac80211 cfg80211 compat btwilink rmi4(C) fmdrv_chr st_drv matrix(C)
> <4>[   10.251651, 3]
> <4>[   10.253391, 3] Pid: 68, comm: kworker/3:4 Tainted: G        WC  3.0.34-140430-g2af538d #45 Intel Corporation CloverTrail/FFRD
> <4>[   10.264674, 3] EIP: 0060:[<c126c7ed>] EFLAGS: 00010002 CPU: 3
> <4>[   10.270411, 3] EIP is at __run_hrtimer+0xbd/0x240
> <4>[   10.275091, 3] EAX: 00000001 EBX: f67fb6b8 ECX: f57b4000 EDX: 00007301
> <4>[   10.281602, 3] ESI: c1d614c0 EDI: f67fb680 EBP: f57b5dd8 ESP: f57b5da8
> <4>[   10.288113, 3]  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> <0>[   10.293754, 3] Process kworker/3:4 (pid: 68, ti=f57b4000 task=f57aa730 task.ti=f57b4000)
> <0>[   10.301827, 3] Stack:
> <4>[   10.304083, 3]  00000000 c1afef40 f57b5dd8 c167a6e0 f67fb680 20b366e3 f67fb6b8 f57b5e14
> <4>[   10.312069, 3]  00000001 f67fb6b8 00000001 f67fb680 f57b5e28 c126d1e5 f57b5e08 c126f325
> <4>[   10.320055, 3]  00000000 86b9868d 00000001 86b9868d 00000001 00000003 ffffffff 7fffffff
> <0>[   10.328041, 3] Call Trace:
> <4>[   10.330742, 3]  [<c167a6e0>] ? gburst_thread_stop.isra.25+0x40/0x40
> <4>[   10.336988, 3]  [<c126d1e5>] hrtimer_interrupt+0xd5/0x250
> <4>[   10.342368, 3]  [<c126f325>] ? sched_clock_cpu+0xe5/0x150
> <4>[   10.347753, 3]  [<c1871d44>] smp_apic_timer_interrupt+0x54/0x88
> <4>[   10.353654, 3]  [<c1496558>] ? trace_hardirqs_off_thunk+0xc/0x14
> <4>[   10.359643, 3]  [<c186be9f>] apic_timer_interrupt+0x2f/0x34
> <4>[   10.365199, 3]  [<c186e60f>] ? sub_preempt_count+0x1f/0x50
> <4>[   10.370669, 3]  [<c149558a>] delay_tsc+0x3a/0xc0
> <6>[   10.371589, 0] android_work: did not send uevent (0 0   (null))
> <4>[   10.381171, 3]  [<c14954e3>] __const_udelay+0x23/0x30
> <4>[   10.386207, 3]  [<c16d043a>] mdfld_dsi_send_dcs+0x12a/0x5d0
> <4>[   10.391760, 3]  [<c186b6c6>] ? _raw_spin_unlock_irqrestore+0x26/0x50
> <4>[   10.398101, 3]  [<c16af431>] ? ospm_power_using_hw_begin+0xa1/0x350
> <4>[   10.399053, 3]  [<c186a49f>] ? __mutex_lock_slowpath+0x1ff/0x2f0
> <4>[   10.399069, 3]  [<c16bd59e>] mdfld_dbi_update_panel+0x21e/0x2d0
> <4>[   10.399085, 3]  [<c16b1ae1>] mdfld_te_handler_work+0x71/0x80
> <4>[   10.399099, 3]  [<c12642be>] process_one_work+0xfe/0x3f0
> <4>[   10.399114, 3]  [<c16b1a70>] ? mdfld_async_flip_te_handler+0xf0/0xf0
> 
> Basically, __run_hrtimer has a race with enqueue_hrtimer. When __run_hrtimer calls
> the timer callback fn, another thread might call enqueue_hrtimer or hrtimer_start
> to requeue it, and the timer->state is equal to HRTIMER_STATE_CALLBACK|HRTIMER_STATE_ENQUEUED,
> which causes the BUG_ON(timer->state != HRTIMER_STATE_CALLBACK) checking fails.
> 
> The patch fixes it by checking only bit HRTIMER_STATE_CALLBACK.
The patch has an issue that enqueue_hrtimer doesn't check if the timer is queued.
I will send a new patch.



^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
  2012-10-26  2:51 [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer he, bo
  2012-10-26  8:51 ` Yanmin Zhang
@ 2012-10-26  9:55 ` Thomas Gleixner
  2012-10-26 11:38   ` Zhang, Yanmin
  1 sibling, 1 reply; 6+ messages in thread
From: Thomas Gleixner @ 2012-10-26  9:55 UTC (permalink / raw)
  To: he, bo
  Cc: linux-kernel, Peter Zijlstra, Ingo Molnar, yanmin_zhang, yanmin.zhang

On Fri, 26 Oct 2012, he, bo wrote:
> From: Yanmin Zhang <yanmin.zhang@intel.com>
> 
> We hit a kernel panic at __run_hrtimer=>BUG_ON(timer->state != HRTIMER_STATE_CALLBACK).
> <2>[   10.226053, 3] kernel BUG at /home/android/xiaobing/ymz/r4/hardware/intel/linux-2.6/kernel/hrtimer.c:1228!
> 
> Basically, __run_hrtimer has a race with enqueue_hrtimer. When
> __run_hrtimer calls the timer callback fn, another thread might call
> enqueue_hrtimer or hrtimer_start to requeue it, and the timer->state
> is equal to HRTIMER_STATE_CALLBACK|HRTIMER_STATE_ENQUEUED, which
> causes the BUG_ON(timer->state != HRTIMER_STATE_CALLBACK) checking
> fails.
>
> The patch fixes it by checking only bit HRTIMER_STATE_CALLBACK.

This does not fix it. It makes it worse.
 
> Signed-off-by: Yanmin Zhang <yanmin.zhang@intel.com>
> Reviewed-by: He, Bo <bo.he@intel.com>
> ---
>  kernel/hrtimer.c |    2 +-
>  1 files changed, 1 insertions(+), 1 deletions(-)
> 
> diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
> index 6db7a5e..6280184 100644
> --- a/kernel/hrtimer.c
> +++ b/kernel/hrtimer.c
> @@ -1235,7 +1235,7 @@ static void __run_hrtimer(struct hrtimer *timer, ktime_t *now)
>  	 * hrtimer_start_range_ns() or in hrtimer_interrupt()
>  	 */
>  	if (restart != HRTIMER_NORESTART) {
> -		BUG_ON(timer->state != HRTIMER_STATE_CALLBACK);
> +		BUG_ON(!(timer->state & HRTIMER_STATE_CALLBACK));
>  		enqueue_hrtimer(timer, base);
>  	}

What you are allowing here is enqueueing an already enqueued timer
again. I don't know why this does not explode elsewhere, but that's
probably pure luck. It's not allowed to double enqueue a timer.

So no, this is not a solution. The problem is not in the core timer
code, the problem is in the code which uses that timer.

Your code is returning HRTIMER_RESTART from the timer callback and at
the same time it starts the timer from some other context. That's what
needs to be fixed.

Thanks,

	tglx







^ permalink raw reply	[flat|nested] 6+ messages in thread

* RE: [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
  2012-10-26  9:55 ` Thomas Gleixner
@ 2012-10-26 11:38   ` Zhang, Yanmin
  2012-10-26 12:09     ` Thomas Gleixner
  0 siblings, 1 reply; 6+ messages in thread
From: Zhang, Yanmin @ 2012-10-26 11:38 UTC (permalink / raw)
  To: Thomas Gleixner, He, Bo
  Cc: linux-kernel, Peter Zijlstra, Ingo Molnar, yanmin_zhang

>-----Original Message-----
>From: Thomas Gleixner [mailto:tglx@linutronix.de]
>Sent: Friday, October 26, 2012 5:55 PM
>To: He, Bo
>Cc: linux-kernel@vger.kernel.org; Peter Zijlstra; Ingo Molnar;
>yanmin_zhang@linux.intel.com; Zhang, Yanmin
>Subject: Re: [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
>
>On Fri, 26 Oct 2012, he, bo wrote:
>> From: Yanmin Zhang <yanmin.zhang@intel.com>
>>
>> We hit a kernel panic at __run_hrtimer=>BUG_ON(timer->state !=
>HRTIMER_STATE_CALLBACK).
>> <2>[   10.226053, 3] kernel BUG at
>/home/android/xiaobing/ymz/r4/hardware/intel/linux-2.6/kernel/hrtimer.c:1228
>!
>>
>> Basically, __run_hrtimer has a race with enqueue_hrtimer. When
>> __run_hrtimer calls the timer callback fn, another thread might call
>> enqueue_hrtimer or hrtimer_start to requeue it, and the timer->state
>> is equal to HRTIMER_STATE_CALLBACK|HRTIMER_STATE_ENQUEUED, which
>> causes the BUG_ON(timer->state != HRTIMER_STATE_CALLBACK) checking
>> fails.
>>
>> The patch fixes it by checking only bit HRTIMER_STATE_CALLBACK.
>
>This does not fix it. It makes it worse.
Thanks for your kind comments. We found that and sent V2 at https://lkml.org/lkml/2012/10/26/172.

>
>> Signed-off-by: Yanmin Zhang <yanmin.zhang@intel.com>
>> Reviewed-by: He, Bo <bo.he@intel.com>
>> ---
>>  kernel/hrtimer.c |    2 +-
>>  1 files changed, 1 insertions(+), 1 deletions(-)
>>
>> diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
>> index 6db7a5e..6280184 100644
>> --- a/kernel/hrtimer.c
>> +++ b/kernel/hrtimer.c
>> @@ -1235,7 +1235,7 @@ static void __run_hrtimer(struct hrtimer *timer,
>ktime_t *now)
>>  	 * hrtimer_start_range_ns() or in hrtimer_interrupt()
>>  	 */
>>  	if (restart != HRTIMER_NORESTART) {
>> -		BUG_ON(timer->state != HRTIMER_STATE_CALLBACK);
>> +		BUG_ON(!(timer->state & HRTIMER_STATE_CALLBACK));
>>  		enqueue_hrtimer(timer, base);
>>  	}
>
>What you are allowing here is enqueueing an already enqueued timer
>again. I don't know why this does not explode elsewhere, but that's
>probably pure luck. It's not allowed to double enqueue a timer.
You are right.

>
>So no, this is not a solution. The problem is not in the core timer
>code, the problem is in the code which uses that timer.
>
>Your code is returning HRTIMER_RESTART from the timer callback and at
>the same time it starts the timer from some other context. That's what
>needs to be fixed.
The timer user should fix it. But could we also change hrtimer to make it more stable?
At least, instead of panic, could we print some information and go ahead to let kernel
continue?

Thanks,
Yanmin



^ permalink raw reply	[flat|nested] 6+ messages in thread

* RE: [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
  2012-10-26 11:38   ` Zhang, Yanmin
@ 2012-10-26 12:09     ` Thomas Gleixner
  2012-10-29  0:58       ` Yanmin Zhang
  0 siblings, 1 reply; 6+ messages in thread
From: Thomas Gleixner @ 2012-10-26 12:09 UTC (permalink / raw)
  To: Zhang, Yanmin
  Cc: He, Bo, linux-kernel, Peter Zijlstra, Ingo Molnar, yanmin_zhang

On Fri, 26 Oct 2012, Zhang, Yanmin wrote:
> >From: Thomas Gleixner [mailto:tglx@linutronix.de]
> >Your code is returning HRTIMER_RESTART from the timer callback and at
> >the same time it starts the timer from some other context. That's what
> >needs to be fixed.
> 
> The timer user should fix it. But could we also change hrtimer to
> make it more stable?  At least, instead of panic, could we print
> some information and go ahead to let kernel continue?

That's unfortunately not possible. At this point the timer might be
already corrupted.

CPU0				CPU 1

timer expires
  callback runs		
                                hrtimer_start()
				   expiry value is set
				   hrtimer_enqueue()

   hrtimer_forward()
      expiry value is set

  return HRTIMER_RESTART				

So while we can prevent the double enqueue, we have no way to deal
with the corrupted expiry value and the inconsistent RB tree. We can
give better debugging information, but we can't pretend that
everything is nice and cool.

If we really want to do something about it which keeps the machine
alive, then we need to 

       1) dequeue the timer
       2) run a consistency check over the rbtree
       3) enqueue the timer

Not sure if that's worth the trouble.

Thanks,

	tglx

^ permalink raw reply	[flat|nested] 6+ messages in thread

* RE: [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
  2012-10-26 12:09     ` Thomas Gleixner
@ 2012-10-29  0:58       ` Yanmin Zhang
  0 siblings, 0 replies; 6+ messages in thread
From: Yanmin Zhang @ 2012-10-29  0:58 UTC (permalink / raw)
  To: Thomas Gleixner
  Cc: Zhang, Yanmin, He, Bo, linux-kernel, Peter Zijlstra, Ingo Molnar

On Fri, 2012-10-26 at 14:09 +0200, Thomas Gleixner wrote:
> On Fri, 26 Oct 2012, Zhang, Yanmin wrote:
> > >From: Thomas Gleixner [mailto:tglx@linutronix.de]
> > >Your code is returning HRTIMER_RESTART from the timer callback and at
> > >the same time it starts the timer from some other context. That's what
> > >needs to be fixed.
> > 
> > The timer user should fix it. But could we also change hrtimer to
> > make it more stable?  At least, instead of panic, could we print
> > some information and go ahead to let kernel continue?
> 
> That's unfortunately not possible. At this point the timer might be
> already corrupted.
> 
> CPU0				CPU 1
> 
> timer expires
>   callback runs		
>                                 hrtimer_start()
> 				   expiry value is set
> 				   hrtimer_enqueue()
> 
>    hrtimer_forward()
>       expiry value is set
> 
>   return HRTIMER_RESTART				
> 
> So while we can prevent the double enqueue, we have no way to deal
> with the corrupted expiry value and the inconsistent RB tree. We can
> give better debugging information, but we can't pretend that
> everything is nice and cool.
> 
> If we really want to do something about it which keeps the machine
> alive, then we need to 
> 
>        1) dequeue the timer
>        2) run a consistency check over the rbtree
>        3) enqueue the timer
> 
> Not sure if that's worth the trouble.
I strongly agree with you. Such checking might cause more trouble than
what we could benefit from it.

Could we add more dumping, especially about the timer address and callback
function? Next time, developers could find the bad timer quickly.




^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2012-10-29 17:30 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-10-26  2:51 [PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer he, bo
2012-10-26  8:51 ` Yanmin Zhang
2012-10-26  9:55 ` Thomas Gleixner
2012-10-26 11:38   ` Zhang, Yanmin
2012-10-26 12:09     ` Thomas Gleixner
2012-10-29  0:58       ` Yanmin Zhang

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).