Re: ntp: BUG: spinlock lockup on CPU#1

[Thomas Gleixner]

On Thu, 15 Mar 2012, Sasha Levin wrote:

> Hi all,
> 
> I was doing some more fuzzing with trinity in a KVM tools guest, using
> today's linux-next, when I've experienced a complete system lockup
> (just in the guest ofcourse). After a bit I got the spew at the bottom
> of this mail.
> 
> >From what I can tell from the logs, there were several threads waiting
> on syscall results, and I suspect that the adjtimex() call on CPU3 is
> somehow responsible for this lockup.
> [   69.785019] Call Trace:
> [   69.785019]  [<ffffffff8110e41d>] clockevents_program_event+0x3d/0x100
> [   69.785019]  [<ffffffff8189babb>] ? debug_object_activate+0x11b/0x190
> [   69.785019]  [<ffffffff8111009f>] tick_program_event+0x1f/0x30
> [   69.785019]  [<ffffffff810da8d5>] hrtimer_reprogram.clone.21+0x95/0xe0
> [   69.785019]  [<ffffffff810dafe4>] __hrtimer_start_range_ns+0x2c4/0x3b0
> [   69.785019]  [<ffffffff810db103>] hrtimer_start+0x13/0x20
> [   69.785019]  [<ffffffff8110a001>] do_adjtimex+0x541/0x6d0
> [   69.785019]  [<ffffffff8119ee07>] ? might_fault+0x97/0xa0
> [   69.785019]  [<ffffffff810b895e>] sys_adjtimex+0x4e/0x90
> [   69.785019]  [<ffffffff8270b2bd>] system_call_fastpath+0x1a/0x1f

Indeed, that's a long standing bug. In mainline it's live locking due
to:

do_adjtimex()
  write_seqlock_irq(&xtime_lock);
    process_adjtimex_modes();
      process_adj_status();
        ntp_start_leap_timer();
          hrtimer_start();
             hrtimer_reprogram();
               tick_program_event()
                 clockevents_program_event()
		   ktime_get()
                     seq = req_seqbegin(xtime_lock);

-->     Live lock, because xtime lock is write locked.

This affects all other cpus as well as they call any of the xtime_lock
protected functions. Happy spinning for ever!

But in -next we have a separate ntp lock. So here the problem is more
subtle:

[   69.785020]  <IRQ>  [<ffffffff81899118>] spin_dump+0x78/0xc0
[   69.785020]  [<ffffffff818993b0>] do_raw_spin_lock+0x130/0x140
[   69.785020]  [<ffffffff81110500>] ? tick_nohz_handler+0x100/0x100
[   69.785020]  [<ffffffff82709a12>] _raw_spin_lock_irqsave+0x92/0xc0
[   69.785020]  [<ffffffff81109925>] ? ntp_tick_length+0x15/0x40
[   69.785020]  [<ffffffff8107bfe6>] ? kvm_clock_read+0x46/0x80
[   69.785020]  [<ffffffff81109925>] ntp_tick_length+0x15/0x40
[   69.785020]  [<ffffffff8110834c>] update_wall_time+0xbc/0x210
[   69.785020]  [<ffffffff811093c8>] do_timer+0x18/0x30
[   69.785020]  [<ffffffff811103a5>] tick_do_update_jiffies64+0x75/0xd0
[   69.785020]  [<ffffffff811105b0>] tick_sched_timer+0xb0/0xc0
[   69.785020]  [<ffffffff810daa71>] __run_hrtimer.clone.23+0x81/0x130
[   69.785020]  [<ffffffff810db537>] hrtimer_interrupt+0xe7/0x220
[   69.785020]  [<ffffffff810719e3>] smp_apic_timer_interrupt+0x63/0xa0
[   69.785020]  [<ffffffff8270bf6f>] apic_timer_interrupt+0x6f/0x80

CPU 0                                                    CPU 1
do_adjtimex()
  spin_lock_irq(&ntp_lock);
    process_adjtimex_modes();				 timer_interrupt()
      process_adj_status();                                do_timer()
        ntp_start_leap_timer();                             write_lock(&xtime_lock);
          hrtimer_start();                                  update_wall_time();
             hrtimer_reprogram();                            ntp_tick_length()
               tick_program_event()                            spin_lock(&ntp_lock);
                 clockevents_program_event()
		   ktime_get()
                     seq = req_seqbegin(xtime_lock);

So CPU0 waits for xtime seqence to become valid and CPU1 cant make
progress because it's stuck on ntp_lock.

That means we need two fixes. One for mainline/stable and one for the
new split lock version.

Thanks,

	tglx
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/