Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757541Ab2J2CMr (ORCPT ); Sun, 28 Oct 2012 22:12:47 -0400 Received: from mga01.intel.com ([192.55.52.88]:29496 "EHLO mga01.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756205Ab2J2CMq (ORCPT ); Sun, 28 Oct 2012 22:12:46 -0400 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="4.80,668,1344236400"; d="scan'208";a="239615421" Subject: [PATCH] hrtimer: Printing timer info when hitting BUG_ON() From: Chuansheng Liu To: tglx@linutronix.de, mingo@kernel.org, a.p.zijlstra@chello.nl Cc: linux-kernel@vger.kernel.org, fei.li@intel.com, yanmin_zhang@linux.intel.com, chuansheng.liu@intel.com Content-Type: text/plain; charset="UTF-8" Date: Mon, 29 Oct 2012 19:02:31 +0800 Message-ID: <1351508551.15558.1428.camel@cliu38-desktop-build> Mime-Version: 1.0 X-Mailer: Evolution 2.28.3 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 2836 Lines: 86 We encounted one BUG_ON() issue at function __run_hrtimer(), but the panic info is not enough to find out which hrtimer users use the hrtimer wrongly. (in this BUG_ON case, it is callback running at the same time hrtimer_start() is executed on different context.) We can print basic timer info before BUG(), it is easy to find out which hrtimer user has fault, the output info is like below: <3>[ 41.118552] timer info: state/3, func/test_timer_cb <3>[ 41.118618] timer stats: pid/786(sh), site/hrtimer_start <0>[ 41.118670] ------------[ cut here ]------------ <2>[ 41.118691] kernel BUG at /root/r4_code/hardware/intel/linux-2.6/kernel/hrtimer.c:1260! <0>[ 41.118715] invalid opcode: 0000 [#1] PREEMPT SMP The infos of callback/state are very helpful for debugging this BUG_ON(). Signed-off-by: Li Fei Signed-off-by: liu chuansheng --- kernel/hrtimer.c | 34 +++++++++++++++++++++++++++++++++- 1 files changed, 33 insertions(+), 1 deletions(-) diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c index 6db7a5e..388e8b2 100644 --- a/kernel/hrtimer.c +++ b/kernel/hrtimer.c @@ -1204,6 +1204,35 @@ int hrtimer_get_res(const clockid_t which_clock, struct timespec *tp) } EXPORT_SYMBOL_GPL(hrtimer_get_res); +/* + * dump_hrtimer_callinfo - print hrtimer information including: + * state, callback function, pid and start_site. +*/ +static void dump_hrtimer_callinfo(struct hrtimer *timer) +{ + + char symname[KSYM_NAME_LEN]; + + if (lookup_symbol_name((unsigned long)(timer->function), symname) < 0) { + pr_err("timer info: state/%lx, func/%pK\n", + timer->state, timer->function); + } else { + pr_err("timer info: state/%lx, func/%s", + timer->state, symname); + } + +#ifdef CONFIG_TIMER_STATS + if (lookup_symbol_name((unsigned long)(timer->start_site), + symname) < 0) { + pr_err("timer stats: pid/%d(%s), site/%pK\n", + timer->start_pid, timer->start_comm, timer->start_site); + } else { + pr_err("timer stats: pid/%d(%s), site/%s\n", + timer->start_pid, timer->start_comm, symname); + } +#endif +} + static void __run_hrtimer(struct hrtimer *timer, ktime_t *now) { struct hrtimer_clock_base *base = timer->base; @@ -1235,7 +1264,10 @@ 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); + if (timer->state != HRTIMER_STATE_CALLBACK) { + dump_hrtimer_callinfo(timer); + BUG(); + } enqueue_hrtimer(timer, base); } -- 1.7.0.4 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/