Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-19 Thread Ingo Molnar

* Andrew Morton <[EMAIL PROTECTED]> wrote:

> > /proc/timer-list is useful for profiling applications doing 
> > excessive wakeups. With the move towards being tickless, this is 
> > more important than ever, and giving users the right tools to find 
> > these problems themselves is important.
> > 
> 
> oic.  Nobody ever tells me squat.  
> 
> Your explanation doesn't explain why we need this info in a sysrq 
> triggerable form.
> 
> And what about /proc/timer-stat?

/proc/timer_stats does timer profiling. You start it via:

echo 1 > /proc/timer_stats

and then the profile info gathers into /proc/timer_stats. Useful way to 
look at it is:

sort -n /proc/timer_stats

for example:

Timer Stats Version: v0.1
   1, 0 swapper  page_writeback_init (wb_timer_fn)
   1,  1898 modprobe neigh_table_init_no_netlink (neigh_periodic_timer)
   1, 1 init schedule_timeout (process_timeout)
   1, 1 swapper  neigh_table_init_no_netlink (neigh_periodic_timer)
   1,  2700 hald-addon-stor  do_nanosleep (hrtimer_wakeup)
   1, 6 softirq-timer/0  __netdev_watchdog_up (dev_watchdog)
   2, 1 swapper  queue_delayed_work_on (delayed_work_timer_fn)
   2, 1 swapper  queue_delayed_work_on (delayed_work_timer_fn)
   2,   480 IRQ 218  e1000_intr_msi (e1000_watchdog)
   3,  2652 yum-updatesd schedule_timeout (process_timeout)
   4,  2472 pcscddo_nanosleep (hrtimer_wakeup)
   4,  7824 sshd sk_reset_timer (tcp_write_timer)
  13,   428 insmod   usb_hcd_poll_rh_status (rh_timer_func)
  13,   428 insmod   usb_hcd_poll_rh_status (rh_timer_func)
  13,   437 insmod   usb_hcd_submit_urb (rh_timer_func)
  19,21 softirq-net-rx/  sk_reset_timer (tcp_delack_timer)
 164,  1868 kondemand/0  queue_delayed_work_on (delayed_work_timer_fn)
 164,  1869 kondemand/1  queue_delayed_work_on (delayed_work_timer_fn)
 282, 0 swapper  hrtimer_stop_sched_tick (hrtimer_sched_tick)
 321, 0 swapper  hrtimer_stop_sched_tick (hrtimer_sched_tick)
 335, 0 swapper  hrtimer_restart_sched_tick (hrtimer_sched_tick)
 408, 0 swapper  hrtimer_restart_sched_tick (hrtimer_sched_tick)
1755 total events, 585.534 events/sec

this shows us that the kondemand kernel threads are causing 90% of the 
timeout events on this system.

/proc/timer_list shows all currently pending timers, and all the state 
of the hardware timers. That is a bit different from timer_stat but 
still very useful: it gives us a snapshot into the current state of the 
(hr)timer subsystem. I needed it to debug a couple of high-res timers 
subsystem bugs. The SysRq trigger was useful for things like timer 
related boot hangs. (It's also useful to catch excessive waiters during 
bootup.)

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


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-19 Thread Ingo Molnar

* Andrew Morton [EMAIL PROTECTED] wrote:

  /proc/timer-list is useful for profiling applications doing 
  excessive wakeups. With the move towards being tickless, this is 
  more important than ever, and giving users the right tools to find 
  these problems themselves is important.
  
 
 oic.  Nobody ever tells me squat.  updates changelog
 
 Your explanation doesn't explain why we need this info in a sysrq 
 triggerable form.
 
 And what about /proc/timer-stat?

/proc/timer_stats does timer profiling. You start it via:

echo 1  /proc/timer_stats

and then the profile info gathers into /proc/timer_stats. Useful way to 
look at it is:

sort -n /proc/timer_stats

for example:

Timer Stats Version: v0.1
   1, 0 swapper  page_writeback_init (wb_timer_fn)
   1,  1898 modprobe neigh_table_init_no_netlink (neigh_periodic_timer)
   1, 1 init schedule_timeout (process_timeout)
   1, 1 swapper  neigh_table_init_no_netlink (neigh_periodic_timer)
   1,  2700 hald-addon-stor  do_nanosleep (hrtimer_wakeup)
   1, 6 softirq-timer/0  __netdev_watchdog_up (dev_watchdog)
   2, 1 swapper  queue_delayed_work_on (delayed_work_timer_fn)
   2, 1 swapper  queue_delayed_work_on (delayed_work_timer_fn)
   2,   480 IRQ 218  e1000_intr_msi (e1000_watchdog)
   3,  2652 yum-updatesd schedule_timeout (process_timeout)
   4,  2472 pcscddo_nanosleep (hrtimer_wakeup)
   4,  7824 sshd sk_reset_timer (tcp_write_timer)
  13,   428 insmod   usb_hcd_poll_rh_status (rh_timer_func)
  13,   428 insmod   usb_hcd_poll_rh_status (rh_timer_func)
  13,   437 insmod   usb_hcd_submit_urb (rh_timer_func)
  19,21 softirq-net-rx/  sk_reset_timer (tcp_delack_timer)
 164,  1868 kondemand/0  queue_delayed_work_on (delayed_work_timer_fn)
 164,  1869 kondemand/1  queue_delayed_work_on (delayed_work_timer_fn)
 282, 0 swapper  hrtimer_stop_sched_tick (hrtimer_sched_tick)
 321, 0 swapper  hrtimer_stop_sched_tick (hrtimer_sched_tick)
 335, 0 swapper  hrtimer_restart_sched_tick (hrtimer_sched_tick)
 408, 0 swapper  hrtimer_restart_sched_tick (hrtimer_sched_tick)
1755 total events, 585.534 events/sec

this shows us that the kondemand kernel threads are causing 90% of the 
timeout events on this system.

/proc/timer_list shows all currently pending timers, and all the state 
of the hardware timers. That is a bit different from timer_stat but 
still very useful: it gives us a snapshot into the current state of the 
(hr)timer subsystem. I needed it to debug a couple of high-res timers 
subsystem bugs. The SysRq trigger was useful for things like timer 
related boot hangs. (It's also useful to catch excessive waiters during 
bootup.)

Ingo
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-18 Thread Andrew Morton
On Mon, 18 Dec 2006 18:45:49 -0500
Dave Jones <[EMAIL PROTECTED]> wrote:

> On Mon, Dec 18, 2006 at 03:31:03PM -0800, Andrew Morton wrote:
>  > On Sat, 16 Dec 2006 08:56:58 +0100
>  > Ingo Molnar <[EMAIL PROTECTED]> wrote:
>  > 
>  > > ----->
>  > > Subject: [patch] debugging feature: SysRq-Q to print timers
>  > > From: Ingo Molnar <[EMAIL PROTECTED]>
>  > > 
>  > > add SysRq-Q to print pending timers and other timer info.
>  > 
>  > I must say that I've never needed this feature or /proc/timer-list, and I
>  > don't recall ever having seen anyone request it, nor get themselves into a
>  > situation where they needed it.
> 
> /proc/timer-list is useful for profiling applications doing excessive wakeups.
> With the move towards being tickless, this is more important than ever,
> and giving users the right tools to find these problems themselves is 
> important.
> 

oic.  Nobody ever tells me squat.  

Your explanation doesn't explain why we need this info in a sysrq
triggerable form.

And what about /proc/timer-stat?


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


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-18 Thread Dave Jones
On Mon, Dec 18, 2006 at 03:31:03PM -0800, Andrew Morton wrote:
 > On Sat, 16 Dec 2006 08:56:58 +0100
 > Ingo Molnar <[EMAIL PROTECTED]> wrote:
 > 
 > > ->
 > > Subject: [patch] debugging feature: SysRq-Q to print timers
 > > From: Ingo Molnar <[EMAIL PROTECTED]>
 > > 
 > > add SysRq-Q to print pending timers and other timer info.
 > 
 > I must say that I've never needed this feature or /proc/timer-list, and I
 > don't recall ever having seen anyone request it, nor get themselves into a
 > situation where they needed it.

/proc/timer-list is useful for profiling applications doing excessive wakeups.
With the move towards being tickless, this is more important than ever,
and giving users the right tools to find these problems themselves is important.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-18 Thread Andrew Morton
On Sat, 16 Dec 2006 08:56:58 +0100
Ingo Molnar <[EMAIL PROTECTED]> wrote:

> ->
> Subject: [patch] debugging feature: SysRq-Q to print timers
> From: Ingo Molnar <[EMAIL PROTECTED]>
> 
> add SysRq-Q to print pending timers and other timer info.

I must say that I've never needed this feature or /proc/timer-list, and I
don't recall ever having seen anyone request it, nor get themselves into a
situation where they needed it.

Do we really need to include this?
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-18 Thread Andrew Morton
On Sat, 16 Dec 2006 08:56:58 +0100
Ingo Molnar [EMAIL PROTECTED] wrote:

 -
 Subject: [patch] debugging feature: SysRq-Q to print timers
 From: Ingo Molnar [EMAIL PROTECTED]
 
 add SysRq-Q to print pending timers and other timer info.

I must say that I've never needed this feature or /proc/timer-list, and I
don't recall ever having seen anyone request it, nor get themselves into a
situation where they needed it.

Do we really need to include this?
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-18 Thread Dave Jones
On Mon, Dec 18, 2006 at 03:31:03PM -0800, Andrew Morton wrote:
  On Sat, 16 Dec 2006 08:56:58 +0100
  Ingo Molnar [EMAIL PROTECTED] wrote:
  
   -
   Subject: [patch] debugging feature: SysRq-Q to print timers
   From: Ingo Molnar [EMAIL PROTECTED]
   
   add SysRq-Q to print pending timers and other timer info.
  
  I must say that I've never needed this feature or /proc/timer-list, and I
  don't recall ever having seen anyone request it, nor get themselves into a
  situation where they needed it.

/proc/timer-list is useful for profiling applications doing excessive wakeups.
With the move towards being tickless, this is more important than ever,
and giving users the right tools to find these problems themselves is important.

Dave

-- 
http://www.codemonkey.org.uk
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


Re: [patch] debugging feature: SysRq-Q to print timers

2006-12-18 Thread Andrew Morton
On Mon, 18 Dec 2006 18:45:49 -0500
Dave Jones [EMAIL PROTECTED] wrote:

 On Mon, Dec 18, 2006 at 03:31:03PM -0800, Andrew Morton wrote:
   On Sat, 16 Dec 2006 08:56:58 +0100
   Ingo Molnar [EMAIL PROTECTED] wrote:
   
-
Subject: [patch] debugging feature: SysRq-Q to print timers
From: Ingo Molnar [EMAIL PROTECTED]

add SysRq-Q to print pending timers and other timer info.
   
   I must say that I've never needed this feature or /proc/timer-list, and I
   don't recall ever having seen anyone request it, nor get themselves into a
   situation where they needed it.
 
 /proc/timer-list is useful for profiling applications doing excessive wakeups.
 With the move towards being tickless, this is more important than ever,
 and giving users the right tools to find these problems themselves is 
 important.
 

oic.  Nobody ever tells me squat.  updates changelog

Your explanation doesn't explain why we need this info in a sysrq
triggerable form.

And what about /proc/timer-stat?


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


[patch] debugging feature: SysRq-Q to print timers

2006-12-16 Thread Ingo Molnar

* Adrian Bunk <[EMAIL PROTECTED]> wrote:

> On Thu, Dec 14, 2006 at 10:59:13PM -0800, Andrew Morton wrote:
> >...
> > Changes since 2.6.19-mm1:
> >...
> > +debugging-feature-proc-timer_list.patch
> > 
> >  Refreshed, refactored dynticks/hrtimer queue.
> >...
> 
> I'd assume sysrq_timer_list_show() wasn't intended to be unused?

correct, there's a sysrq side of it, but i forgot to send the patch to 
Andrew. Find it below.

    Ingo

--------->
Subject: [patch] debugging feature: SysRq-Q to print timers
From: Ingo Molnar <[EMAIL PROTECTED]>

add SysRq-Q to print pending timers and other timer info.

Signed-off-by: Ingo Molnar <[EMAIL PROTECTED]>
---
 drivers/char/sysrq.c|   14 +-
 include/linux/hrtimer.h |3 +++
 2 files changed, 16 insertions(+), 1 deletion(-)

Index: linux/drivers/char/sysrq.c
===
--- linux.orig/drivers/char/sysrq.c
+++ linux/drivers/char/sysrq.c
@@ -36,6 +36,7 @@
 #include 
 #include 
 #include 
+#include 
 
 #include 
 #include 
@@ -159,6 +160,17 @@ static struct sysrq_key_op sysrq_sync_op
.enable_mask= SYSRQ_ENABLE_SYNC,
 };
 
+static void sysrq_handle_show_timers(int key, struct tty_struct *tty)
+{
+   sysrq_timer_list_show();
+}
+
+static struct sysrq_key_op sysrq_show_timers_op = {
+   .handler= sysrq_handle_show_timers,
+   .help_msg   = "show-all-timers(Q)",
+   .action_msg = "Show Pending Timers",
+};
+
 static void sysrq_handle_mountro(int key, struct tty_struct *tty)
 {
emergency_remount();
@@ -339,7 +351,7 @@ static struct sysrq_key_op *sysrq_key_ta
/* This will often be registered as 'Off' at init time */
NULL,   /* o */
_showregs_op, /* p */
-   NULL,   /* q */
+   _show_timers_op,  /* q */
_unraw_op,/* r */
_sync_op, /* s */
_showstate_op,/* t */
Index: linux/include/linux/hrtimer.h
===
--- linux.orig/include/linux/hrtimer.h
+++ linux/include/linux/hrtimer.h
@@ -364,6 +364,9 @@ static inline void show_no_hz_stats(stru
 /* Bootup initialization: */
 extern void __init hrtimers_init(void);
 
+/* Show pending timers: */
+extern void sysrq_timer_list_show(void);
+
 /*
  * Timer-statistics info:
  */
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


[patch] debugging feature: SysRq-Q to print timers

2006-12-16 Thread Ingo Molnar

* Adrian Bunk [EMAIL PROTECTED] wrote:

 On Thu, Dec 14, 2006 at 10:59:13PM -0800, Andrew Morton wrote:
 ...
  Changes since 2.6.19-mm1:
 ...
  +debugging-feature-proc-timer_list.patch
  
   Refreshed, refactored dynticks/hrtimer queue.
 ...
 
 I'd assume sysrq_timer_list_show() wasn't intended to be unused?

correct, there's a sysrq side of it, but i forgot to send the patch to 
Andrew. Find it below.

Ingo

-
Subject: [patch] debugging feature: SysRq-Q to print timers
From: Ingo Molnar [EMAIL PROTECTED]

add SysRq-Q to print pending timers and other timer info.

Signed-off-by: Ingo Molnar [EMAIL PROTECTED]
---
 drivers/char/sysrq.c|   14 +-
 include/linux/hrtimer.h |3 +++
 2 files changed, 16 insertions(+), 1 deletion(-)

Index: linux/drivers/char/sysrq.c
===
--- linux.orig/drivers/char/sysrq.c
+++ linux/drivers/char/sysrq.c
@@ -36,6 +36,7 @@
 #include linux/workqueue.h
 #include linux/kexec.h
 #include linux/irq.h
+#include linux/hrtimer.h
 
 #include asm/ptrace.h
 #include asm/irq_regs.h
@@ -159,6 +160,17 @@ static struct sysrq_key_op sysrq_sync_op
.enable_mask= SYSRQ_ENABLE_SYNC,
 };
 
+static void sysrq_handle_show_timers(int key, struct tty_struct *tty)
+{
+   sysrq_timer_list_show();
+}
+
+static struct sysrq_key_op sysrq_show_timers_op = {
+   .handler= sysrq_handle_show_timers,
+   .help_msg   = show-all-timers(Q),
+   .action_msg = Show Pending Timers,
+};
+
 static void sysrq_handle_mountro(int key, struct tty_struct *tty)
 {
emergency_remount();
@@ -339,7 +351,7 @@ static struct sysrq_key_op *sysrq_key_ta
/* This will often be registered as 'Off' at init time */
NULL,   /* o */
sysrq_showregs_op, /* p */
-   NULL,   /* q */
+   sysrq_show_timers_op,  /* q */
sysrq_unraw_op,/* r */
sysrq_sync_op, /* s */
sysrq_showstate_op,/* t */
Index: linux/include/linux/hrtimer.h
===
--- linux.orig/include/linux/hrtimer.h
+++ linux/include/linux/hrtimer.h
@@ -364,6 +364,9 @@ static inline void show_no_hz_stats(stru
 /* Bootup initialization: */
 extern void __init hrtimers_init(void);
 
+/* Show pending timers: */
+extern void sysrq_timer_list_show(void);
+
 /*
  * Timer-statistics info:
  */
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/