All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] workqueue: Add basic tracepoints to track workqueue execution
@ 2010-08-21 20:14 Arjan van de Ven
  2010-08-22  3:21 ` Frederic Weisbecker
                   ` (2 more replies)
  0 siblings, 3 replies; 7+ messages in thread
From: Arjan van de Ven @ 2010-08-21 20:14 UTC (permalink / raw)
  To: tj; +Cc: linux-kernel, torvalds, fweisbec, rostedt


From: Arjan van de Ven <arjan@linux.intel.com>
Date: Sat, 21 Aug 2010 13:07:26 -0700
Subject: [PATCH] workqueue: Add basic tracepoints to track workqueue execution

With the introduction of the new unified work queue thread pools,
we lost one feature: It's no longer possible to know which worker
is causing the CPU to wake out of idle. The result is that PowerTOP
now reports a lot of "kworker/a:b" instead of more readable results.

This patch adds a pair of tracepoints to the new workqueue code,
similar in style to the timer/hrtimer tracepoints.

With this pair of tracepoints, the next PowerTOP can correctly
report which work item caused the wakeup (and how long it took):

Interrupt (43)            i915      time   3.51ms    wakeups 141
Work      ieee80211_iface_work      time   0.81ms    wakeups  29
Work              do_dbs_timer      time   0.55ms    wakeups  24
Process                   Xorg      time  21.36ms    wakeups   4
Timer    sched_rt_period_timer      time   0.01ms    wakeups   1

Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>
---
 include/trace/events/workqueue.h |   63 ++++++++++++++++++++++++++++++++++++++
 kernel/workqueue.c               |    9 +++++
 2 files changed, 72 insertions(+), 0 deletions(-)
 create mode 100644 include/trace/events/workqueue.h

diff --git a/include/trace/events/workqueue.h b/include/trace/events/workqueue.h
new file mode 100644
index 0000000..4fd2bd1
--- /dev/null
+++ b/include/trace/events/workqueue.h
@@ -0,0 +1,63 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM workqueue
+
+#if !defined(_TRACE_WORKQUEUE_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_WORKQUEUE_H
+
+#include <linux/tracepoint.h>
+#include <linux/workqueue.h>
+
+/**
+ * workqueue_execute_start - called immediately before the workqueue callback
+ * @work:	pointer to struct work_struct
+ *
+ * Allows to track workqueue execution.
+ */
+TRACE_EVENT(workqueue_execute_start,
+
+	TP_PROTO(struct work_struct *work),
+
+	TP_ARGS(work),
+
+	TP_STRUCT__entry(
+		__field( void *,	work	)
+		__field( void *,	function)
+	),
+
+	TP_fast_assign(
+		__entry->work		= work;
+		__entry->function	= work->func;
+	),
+
+	TP_printk("work struct %p: function %pf", __entry->work, __entry->function)
+);
+
+/**
+ * workqueue_execute_end - called immediately before the workqueue callback
+ * @work:	pointer to struct work_struct
+ *
+ * Allows to track workqueue execution.
+ */
+TRACE_EVENT(workqueue_execute_end,
+
+	TP_PROTO(struct work_struct *work),
+
+	TP_ARGS(work),
+
+	TP_STRUCT__entry(
+		__field( void *,	work	)
+	),
+
+	TP_fast_assign(
+		__entry->work		= work;
+	),
+
+	TP_printk("work struct %p", __entry->work)
+);
+
+
+#endif /*  _TRACE_WORKQUEUE_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
+
diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index 2994a0e..8bd600c 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -35,6 +35,9 @@
 #include <linux/lockdep.h>
 #include <linux/idr.h>
 
+#define CREATE_TRACE_POINTS
+#include <trace/events/workqueue.h>
+
 #include "workqueue_sched.h"
 
 enum {
@@ -1790,7 +1793,13 @@ static void process_one_work(struct worker *worker, struct work_struct *work)
 	work_clear_pending(work);
 	lock_map_acquire(&cwq->wq->lockdep_map);
 	lock_map_acquire(&lockdep_map);
+	trace_workqueue_execute_start(work);
 	f(work);
+	/*
+	 * While we must be careful to not use "work" after this, the trace
+	 * point will only record its address.
+	 */
+	trace_workqueue_execute_end(work);
 	lock_map_release(&lockdep_map);
 	lock_map_release(&cwq->wq->lockdep_map);
 
-- 
1.7.1.1



-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

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

* Re: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
  2010-08-21 20:14 [PATCH] workqueue: Add basic tracepoints to track workqueue execution Arjan van de Ven
@ 2010-08-22  3:21 ` Frederic Weisbecker
  2010-08-22  4:01 ` Frederic Weisbecker
  2010-08-26 14:35 ` Jason Baron
  2 siblings, 0 replies; 7+ messages in thread
From: Frederic Weisbecker @ 2010-08-22  3:21 UTC (permalink / raw)
  To: Arjan van de Ven, Ingo Molnar; +Cc: tj, linux-kernel, torvalds, rostedt

On Sat, Aug 21, 2010 at 01:14:02PM -0700, Arjan van de Ven wrote:
> 
> From: Arjan van de Ven <arjan@linux.intel.com>
> Date: Sat, 21 Aug 2010 13:07:26 -0700
> Subject: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
> 
> With the introduction of the new unified work queue thread pools,
> we lost one feature: It's no longer possible to know which worker
> is causing the CPU to wake out of idle. The result is that PowerTOP
> now reports a lot of "kworker/a:b" instead of more readable results.
> 
> This patch adds a pair of tracepoints to the new workqueue code,
> similar in style to the timer/hrtimer tracepoints.
> 
> With this pair of tracepoints, the next PowerTOP can correctly
> report which work item caused the wakeup (and how long it took):
> 
> Interrupt (43)            i915      time   3.51ms    wakeups 141
> Work      ieee80211_iface_work      time   0.81ms    wakeups  29
> Work              do_dbs_timer      time   0.55ms    wakeups  24
> Process                   Xorg      time  21.36ms    wakeups   4
> Timer    sched_rt_period_timer      time   0.01ms    wakeups   1
> 
> Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>



Acked-by: Frederic Weisbecker <fweisbec@gmail.com>


If that broke a userspace tool, should that perhaps go to .36 ?
I know it's a big patch, but in fact it's more a semi-revert of
the workqueue tracepoints removal.

It's my bad in fact: I suggested Tejun not to bother with workqueue
tracepoints yet and to drop the previous ones for now. The previous ones were
placed to observe problems specific to the purely serialized design they
had. I thought cmwq would need other tracepoints.

In fact I thought no tools were using these tracepoints. Bad assumption...


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

* Re: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
  2010-08-21 20:14 [PATCH] workqueue: Add basic tracepoints to track workqueue execution Arjan van de Ven
  2010-08-22  3:21 ` Frederic Weisbecker
@ 2010-08-22  4:01 ` Frederic Weisbecker
  2010-08-23  9:46   ` Tejun Heo
  2010-08-26 14:35 ` Jason Baron
  2 siblings, 1 reply; 7+ messages in thread
From: Frederic Weisbecker @ 2010-08-22  4:01 UTC (permalink / raw)
  To: Arjan van de Ven; +Cc: tj, linux-kernel, torvalds, rostedt

On Sat, Aug 21, 2010 at 01:14:02PM -0700, Arjan van de Ven wrote:
> 
> From: Arjan van de Ven <arjan@linux.intel.com>
> Date: Sat, 21 Aug 2010 13:07:26 -0700
> Subject: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
> 
> With the introduction of the new unified work queue thread pools,
> we lost one feature: It's no longer possible to know which worker
> is causing the CPU to wake out of idle. The result is that PowerTOP
> now reports a lot of "kworker/a:b" instead of more readable results.
> 
> This patch adds a pair of tracepoints to the new workqueue code,
> similar in style to the timer/hrtimer tracepoints.
> 
> With this pair of tracepoints, the next PowerTOP can correctly
> report which work item caused the wakeup (and how long it took):
> 
> Interrupt (43)            i915      time   3.51ms    wakeups 141
> Work      ieee80211_iface_work      time   0.81ms    wakeups  29
> Work              do_dbs_timer      time   0.55ms    wakeups  24
> Process                   Xorg      time  21.36ms    wakeups   4
> Timer    sched_rt_period_timer      time   0.01ms    wakeups   1
> 
> Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>



Ok, Linus applied it. That answers my doubts about the
route for this patch :)


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

* Re: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
  2010-08-22  4:01 ` Frederic Weisbecker
@ 2010-08-23  9:46   ` Tejun Heo
  2010-08-27 13:14     ` Frederic Weisbecker
  0 siblings, 1 reply; 7+ messages in thread
From: Tejun Heo @ 2010-08-23  9:46 UTC (permalink / raw)
  To: Frederic Weisbecker; +Cc: Arjan van de Ven, linux-kernel, torvalds, rostedt

Hello,

On 08/22/2010 06:01 AM, Frederic Weisbecker wrote:
> On Sat, Aug 21, 2010 at 01:14:02PM -0700, Arjan van de Ven wrote:
>>
>> From: Arjan van de Ven <arjan@linux.intel.com>
>> Date: Sat, 21 Aug 2010 13:07:26 -0700
>> Subject: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
>>
>> With the introduction of the new unified work queue thread pools,
>> we lost one feature: It's no longer possible to know which worker
>> is causing the CPU to wake out of idle. The result is that PowerTOP
>> now reports a lot of "kworker/a:b" instead of more readable results.
>>
>> This patch adds a pair of tracepoints to the new workqueue code,
>> similar in style to the timer/hrtimer tracepoints.
>>
>> With this pair of tracepoints, the next PowerTOP can correctly
>> report which work item caused the wakeup (and how long it took):
>>
>> Interrupt (43)            i915      time   3.51ms    wakeups 141
>> Work      ieee80211_iface_work      time   0.81ms    wakeups  29
>> Work              do_dbs_timer      time   0.55ms    wakeups  24
>> Process                   Xorg      time  21.36ms    wakeups   4
>> Timer    sched_rt_period_timer      time   0.01ms    wakeups   1
>>
>> Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>
> 
> Ok, Linus applied it. That answers my doubts about the
> route for this patch :)

I was planning to work on wq tracing in this devel cycle but yeah
Arjan's patch seems like a good starting place.

We definitely need more tracing points tho.  Also, David was wondering
whether it would be possible to have simple file based interface to
monitor the current status of workers.  That's doable w/ tracing API,
right?

Thanks.

-- 
tejun

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

* Re: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
  2010-08-21 20:14 [PATCH] workqueue: Add basic tracepoints to track workqueue execution Arjan van de Ven
  2010-08-22  3:21 ` Frederic Weisbecker
  2010-08-22  4:01 ` Frederic Weisbecker
@ 2010-08-26 14:35 ` Jason Baron
  2010-08-27 10:29   ` [PATCH] workqueue: Add a workqueue chapter to the tracepoint docbook Tejun Heo
  2 siblings, 1 reply; 7+ messages in thread
From: Jason Baron @ 2010-08-26 14:35 UTC (permalink / raw)
  To: Arjan van de Ven; +Cc: tj, linux-kernel, torvalds, fweisbec, rostedt

On Sat, Aug 21, 2010 at 01:14:02PM -0700, Arjan van de Ven wrote:
> With the introduction of the new unified work queue thread pools,
> we lost one feature: It's no longer possible to know which worker
> is causing the CPU to wake out of idle. The result is that PowerTOP
> now reports a lot of "kworker/a:b" instead of more readable results.
> 
> This patch adds a pair of tracepoints to the new workqueue code,
> similar in style to the timer/hrtimer tracepoints.
> 

Hi,

it might also be nice to add a workqueue chapter to the traceopint docbook.
Since you've already included kernel-doc style comments, the below is all that
we need.

current book is at: http://www.kernel.org/doc/htmldocs/tracepoint/

thanks,

-Jason


Add a workqueue chapter to the tracepoint docbook

Signed-off-by: Jason Baron <jbaron@redhat.com>

---
 Documentation/DocBook/tracepoint.tmpl |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)

diff --git a/Documentation/DocBook/tracepoint.tmpl b/Documentation/DocBook/tracepoint.tmpl
index e8473ea..b57a9ed 100644
--- a/Documentation/DocBook/tracepoint.tmpl
+++ b/Documentation/DocBook/tracepoint.tmpl
@@ -104,4 +104,9 @@
    <title>Block IO</title>
 !Iinclude/trace/events/block.h
   </chapter>
+
+  <chapter id="workqueue">
+   <title>Workqueue</title>
+!Iinclude/trace/events/workqueue.h
+  </chapter>
 </book>
-- 
1.6.0.6


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

* [PATCH] workqueue: Add a workqueue chapter to the tracepoint docbook
  2010-08-26 14:35 ` Jason Baron
@ 2010-08-27 10:29   ` Tejun Heo
  0 siblings, 0 replies; 7+ messages in thread
From: Tejun Heo @ 2010-08-27 10:29 UTC (permalink / raw)
  To: Jason Baron; +Cc: Arjan van de Ven, linux-kernel, torvalds, fweisbec, rostedt

From: Jason Baron <jbaron@redhat.com>

Add a workqueue chapter to the traceopint docbook.

Current book is at: http://www.kernel.org/doc/htmldocs/tracepoint/

Signed-off-by: Jason Baron <jbaron@redhat.com>
Signed-off-by: Tejun Heo <tj@kernel.org>
---
Applied w/ patch description update.  Thanks.

 Documentation/DocBook/tracepoint.tmpl |    5 +++++
 1 files changed, 5 insertions(+), 0 deletions(-)

diff --git a/Documentation/DocBook/tracepoint.tmpl b/Documentation/DocBook/tracepoint.tmpl
index e8473ea..b57a9ed 100644
--- a/Documentation/DocBook/tracepoint.tmpl
+++ b/Documentation/DocBook/tracepoint.tmpl
@@ -104,4 +104,9 @@
    <title>Block IO</title>
 !Iinclude/trace/events/block.h
   </chapter>
+
+  <chapter id="workqueue">
+   <title>Workqueue</title>
+!Iinclude/trace/events/workqueue.h
+  </chapter>
 </book>
-- 
1.7.1


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

* Re: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
  2010-08-23  9:46   ` Tejun Heo
@ 2010-08-27 13:14     ` Frederic Weisbecker
  0 siblings, 0 replies; 7+ messages in thread
From: Frederic Weisbecker @ 2010-08-27 13:14 UTC (permalink / raw)
  To: Tejun Heo; +Cc: Arjan van de Ven, linux-kernel, torvalds, rostedt

On Mon, Aug 23, 2010 at 11:46:18AM +0200, Tejun Heo wrote:
> Hello,
> 
> On 08/22/2010 06:01 AM, Frederic Weisbecker wrote:
> > On Sat, Aug 21, 2010 at 01:14:02PM -0700, Arjan van de Ven wrote:
> >>
> >> From: Arjan van de Ven <arjan@linux.intel.com>
> >> Date: Sat, 21 Aug 2010 13:07:26 -0700
> >> Subject: [PATCH] workqueue: Add basic tracepoints to track workqueue execution
> >>
> >> With the introduction of the new unified work queue thread pools,
> >> we lost one feature: It's no longer possible to know which worker
> >> is causing the CPU to wake out of idle. The result is that PowerTOP
> >> now reports a lot of "kworker/a:b" instead of more readable results.
> >>
> >> This patch adds a pair of tracepoints to the new workqueue code,
> >> similar in style to the timer/hrtimer tracepoints.
> >>
> >> With this pair of tracepoints, the next PowerTOP can correctly
> >> report which work item caused the wakeup (and how long it took):
> >>
> >> Interrupt (43)            i915      time   3.51ms    wakeups 141
> >> Work      ieee80211_iface_work      time   0.81ms    wakeups  29
> >> Work              do_dbs_timer      time   0.55ms    wakeups  24
> >> Process                   Xorg      time  21.36ms    wakeups   4
> >> Timer    sched_rt_period_timer      time   0.01ms    wakeups   1
> >>
> >> Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>
> > 
> > Ok, Linus applied it. That answers my doubts about the
> > route for this patch :)
> 
> I was planning to work on wq tracing in this devel cycle but yeah
> Arjan's patch seems like a good starting place.
> 
> We definitely need more tracing points tho.  Also, David was wondering
> whether it would be possible to have simple file based interface to
> monitor the current status of workers.  That's doable w/ tracing API,
> right?



Yeah but the ftrace API that handles statistics is a very basic thing.
It works well for measuring entities that won't be freed, like
for branch and function profiling for example.
But once you deal with entities that can disappear (like workqueue threads),
you need to handle all the locking by yourself.

You can have a look at kernel/trace/trace_workqueue.c. It's broken
as we have removed some workqueue tracepoints, so I planned to
remove it. It's a basic thing but perhaps you can restart from there.

I think there was also a race between reader and writer. A stat node
probably need to be read under rcu (and freed after a grace period).


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

end of thread, other threads:[~2010-08-27 13:14 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2010-08-21 20:14 [PATCH] workqueue: Add basic tracepoints to track workqueue execution Arjan van de Ven
2010-08-22  3:21 ` Frederic Weisbecker
2010-08-22  4:01 ` Frederic Weisbecker
2010-08-23  9:46   ` Tejun Heo
2010-08-27 13:14     ` Frederic Weisbecker
2010-08-26 14:35 ` Jason Baron
2010-08-27 10:29   ` [PATCH] workqueue: Add a workqueue chapter to the tracepoint docbook Tejun Heo

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.