首页 > kgdb抓虫日记 > kgdb抓虫日记 – kgdb 与 sched_clock[softlockup]

kgdb抓虫日记 – kgdb 与 sched_clock[softlockup]

2010年6月28日 发表评论 阅读评论

A: BUG现象

intel_mpcbl0040-standard-glibc_small has the simillar problem
# BUG: soft lockup - CPU#3 stuck for 78s! [swapper:0]
Modules linked in: kgdboe ipv6 [last unloaded: kgdboe]
 
Pid: 0, comm: swapper Not tainted (2.6.27.23-WR3.0ae_standard #1)
EIP: 0060:[<c0394844>] EFLAGS: 00000283 CPU: 3
EIP is at _spin_unlock_irq+0xb/0x28
EAX: 00000001 EBX: 0000007d ECX: 000a9a7e EDX: f78603f4
ESI: f7860000 EDI: 00000102 EBP: f7867e98 ESP: f7867e98
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 4c42b6e0 CR3: 004c0000 CR4: 000006d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c012e30f>] run_timer_softirq+0x142/0x1b4
 [<c0135113>] ? delayed_work_timer_fn+0x0/0x32
 [<c012a667>] __do_softirq+0xb6/0x19c
 [<c012a78c>] do_softirq+0x3f/0x45
 [<c013b55e>] ? hrtimer_interrupt+0x0/0x1bc
 [<c012a942>] irq_exit+0x48/0x55
 [<c0111e8c>] smp_apic_timer_interrupt+0xdf/0x129
 [<c0103cd8>] apic_timer_interrupt+0x28/0x30
 [<c0109452>] ? mwait_idle+0x32/0x37
 [<c01021ab>] cpu_idle+0x95/0x11a
 [<c0390263>] start_secondary+0x156/0x1c3
 =======================
BUG: soft lockup - CPU#0 stuck for 78s! [swapper:0]
Modules linked in: kgdboe ipv6 [last unloaded: kgdboe]
 
Pid: 0, comm: swapper Not tainted (2.6.27.23-WR3.0ae_standard #1)
EIP: 0060:[<c0109452>] EFLAGS: 00000246 CPU: 0
EIP is at mwait_idle+0x32/0x37
EAX: 00000000 EBX: 00000004 ECX: 00000000 EDX: 00000000
ESI: 00000000 EDI: c04bf300 EBP: c0475fa4 ESP: c0475fa4
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b80e62a8 CR3: 004c0000 CR4: 000006d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c01021ab>] cpu_idle+0x95/0x11a
 [<c0384f32>] rest_init+0x62/0x70
 =======================

B: BUG重现步骤&现场分析

When CONFIG_HAVE_UNSTABLE_SCHED_CLOCK is set sched_clock() gets the
time from hardware, such as from TSC. In this configuration kgdb will
report a softlock warning messages on resuming or detaching from a
debug session.

Sequence of events in the problem case:
 
1) "cpu sched clock" and "hardware time" are at 100 sec prior
   to a call to kgdb_handle_exception()
 
2) Debugger waits in kgdb_handle_exception() for 80 seconds and on
   exit the following is called
    ...
    touch_softlockup_watchdog()
       --> __raw_get_cpu_var(touch_timestamp) = 0;
 
3) "cpu sched clock" = 100s (it was not updated, because the interrupt
   was disabled in kgdb) but the "hardware time" = 180 sec
 
4) The first timer interrupt after resuming from kgdb_handle_exception
   updates the watchdog from the "cpu sched clock"
 
update_process_times()
{
    ...
    run_local_timers()
          --> softlockup_tick()
              --> check (touch_timestamp == 0)
                (it is "YES" here, we have set "touch_timestamp = 0"
                at kgdb)
                --> __touch_softlockup_watchdog()
              ***(A)--> reset "touch_timestamp" to "get_timestamp()"
                     (Here, the "touch_timestamp" will still be set to
                      100s.)
    ...
 
    scheduler_tick()
      ***(B)--> sched_clock_tick()
               (update "cpu sched clock" to "hardware time" = 180s)
    ...
}
 
 
5) The Second timer interrupt handler appears to have a large jump and
   trips the softlockup warning.
 
update_process_times()
{
    ...
    run_local_timers()
        --> softlockup_tick()
           --> "cpu sched clock" - "touch_timestamp" = 180s-100s > 60s
           --> printk "soft lockup error messages"
    ...
}
note: ***(A) reset "touch_timestamp" to "get_timestamp(this_cpu)"
 
Why "touch_timestamp" is 100 sec, instead of 180 sec?
 
With the CONFIG_HAVE_UNSTABLE_SCHED_CLOCK" set the call trace of
get_timestamp() is:
 
get_timestamp(this_cpu)
      -->cpu_clock(this_cpu)
         -->sched_clock_cpu(this_cpu)
            -->__update_sched_clock(sched_clock_data, now)

C: BUG触发原因

The __update_sched_clock() function uses the GTOD tick value to create
a window to normalize the “now” values. So if “now” values is too big
for sched_clock_data, it will be ignored.

D: BUG解决方法

The fix is to invoke sched_clock_tick() to update “cpu sched clock” in
order to recover from this state. This is done by introducing the
function touch_softlockup_watchdog_sync(), which allows kgdb to
request that the sched clock is updated when the watchdog thread runs
the first time after a resume from kgdb.

[PATCH] softlockup: Add sched_clock_tick() to avoid kernel warning on kgdb resume

E: BUG简要总结

这里的软锁警告并不是由真正的软锁产生的,从使用角度来说可以忽略,但由于是kgdb引起的,对于kgdb来讲,所以还是有责任去解决的.
这个问题是因kgdb关闭了所有中断,导致sched_clock_data存储的时间没有与硬件时间同步造成的.
所以解决方法就是在kgdb退出后立刻更新sched_clock_data.

本文地址:
http://www.kgdb.info/kgdb-bugs-kgdb-and-softlockup/
版权所有 © 转载时必须以链接形式注明作者和原始出处!

  1. 本文目前尚无任何评论.
  1. 2010年10月27日21:47 | #1