lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:	Tue, 14 Apr 2009 13:03:35 +0900 (JST)
From:	KOSAKI Motohiro <kosaki.motohiro@...fujitsu.com>
To:	Zhaolei <zhaolei@...fujitsu.com>,
	Steven Rostedt <rostedt@...dmis.org>,
	Frederic Weisbecker <fweisbec@...il.com>,
	Tom Zanussi <tzanussi@...il.com>, Ingo Molnar <mingo@...e.hu>,
	linux-kernel@...r.kernel.org, Oleg Nesterov <oleg@...hat.com>,
	Andrew Morton <akpm@...ux-foundation.org>
Cc:	kosaki.motohiro@...fujitsu.com
Subject: [PATCH v2 5/4] ftrace, workqueuetrace: display work name


Frederic, What do you think this patch?
===============

Currently, event-tracer only display function name. it is enough useful.
but some driver share work-function between multiple work_struct.
then, work name displaying is better.

example output
------------------------------
# tracer: nop
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
          <idle>-0     [003]  1540.844960: workqueue_insertion: thread=events/3:30 func=e1000_watchdog_task+0x0/0x6ae [e1000e] work=&adapter->watchdog_task
          <idle>-0     [003]  1540.844964: workqueue_insertion: thread=events/3:30 func=vmstat_update+0x0/0x3f work=vmstat_work
           <...>-30    [003]  1540.844969: workqueue_handler_entry: thread=events/3:30 latency=0ms func=e1000_watchdog_task+0x0/0x6ae [e1000e] work=&adapter-
>watchdog_task
           <...>-30    [003]  1540.845003: workqueue_handler_exit: thread=events/3:30 func=e1000_watchdog_task+0x0/0x6ae [e1000e] work=&adapter->watchdog_tas
k
           <...>-30    [003]  1540.845004: workqueue_handler_entry: thread=events/3:30 latency=0ms func=vmstat_update+0x0/0x3f work=vmstat_work
           <...>-30    [003]  1540.845007: workqueue_handler_exit: thread=events/3:30 func=vmstat_update+0x0/0x3f work=vmstat_work

This patch increase kernel-size for work name string table.
But actually, lockdep already have work name string table. then if you already use lockdep,
you don't get kernel-size increasing by this patch.


Signed-off-by: KOSAKI Motohiro <kosaki.motohiro@...fujitsu.com>
Cc: Zhaolei <zhaolei@...fujitsu.com>
Cc: Steven Rostedt <rostedt@...dmis.org>
Cc: Frederic Weisbecker <fweisbec@...il.com>
Cc: Tom Zanussi <tzanussi@...il.com>
Cc: Ingo Molnar <mingo@...e.hu>
---
 include/linux/workqueue.h             |   34 +++++++++++++++++++++++++++++++++-
 include/trace/workqueue_event_types.h |   23 ++++++++++++++++-------
 kernel/workqueue.c                    |    2 +-
 3 files changed, 50 insertions(+), 9 deletions(-)

Index: b/include/linux/workqueue.h
===================================================================
--- a/include/linux/workqueue.h	2009-04-14 11:57:05.000000000 +0900
+++ b/include/linux/workqueue.h	2009-04-14 12:53:57.000000000 +0900
@@ -22,6 +22,11 @@ typedef void (*work_func_t)(struct work_
  */
 #define work_data_bits(work) ((unsigned long *)(&(work)->data))
 
+#if defined(CONFIG_WORKQUEUE_TRACER) || defined(CONFIG_EVENT_TRACING)
+#define HAVE_WORK_TRACE 1
+#endif
+
+
 struct work_struct {
 	atomic_long_t data;
 #define WORK_STRUCT_PENDING 0		/* T if work item pending execution */
@@ -32,8 +37,9 @@ struct work_struct {
 #ifdef CONFIG_LOCKDEP
 	struct lockdep_map lockdep_map;
 #endif
-#ifdef CONFIG_WORKQUEUE_TRACER
+#ifdef HAVE_WORK_TRACE
 	unsigned long expected_time;
+	char *name;
 #endif
 };
 
@@ -65,11 +71,19 @@ struct execute_work {
 #define __WORK_INIT_LOCKDEP_MAP(n, k)
 #endif
 
+#ifdef HAVE_WORK_TRACE
+#define __WORK_INIT_NAME(_work, _name)				\
+	.name = _name,
+#else
+#define __WORK_INIT_NAME(_work, _name)
+#endif
+
 #define __WORK_INITIALIZER(n, f) {				\
 	.data = WORK_DATA_INIT(),				\
 	.entry	= { &(n).entry, &(n).entry },			\
 	.func = (f),						\
 	__WORK_INIT_LOCKDEP_MAP(#n, &(n))			\
+	__WORK_INIT_NAME(&n, #n)				\
 	}
 
 #define __DELAYED_WORK_INITIALIZER(n, f) {			\
@@ -94,6 +108,18 @@ struct execute_work {
 #define PREPARE_DELAYED_WORK(_work, _func)			\
 	PREPARE_WORK(&(_work)->work, (_func))
 
+#ifdef HAVE_WORK_TRACE
+#define SET_WORK_NAME(_work, _name)				\
+	do {							\
+		(_work)->name = (_name);			\
+	} while (0)
+
+#else /*!HAVE_WORK_TRACE*/
+#define SET_WORK_NAME(_work, name)
+#endif /*!HAVE_WORK_TRACE*/
+
+
+
 /*
  * initialize all of a work item in one go
  *
@@ -110,6 +136,7 @@ struct execute_work {
 		lockdep_init_map(&(_work)->lockdep_map, #_work, &__key, 0);\
 		INIT_LIST_HEAD(&(_work)->entry);			\
 		PREPARE_WORK((_work), (_func));				\
+		SET_WORK_NAME((_work), #_work);				\
 	} while (0)
 #else
 #define INIT_WORK(_work, _func)						\
@@ -117,6 +144,7 @@ struct execute_work {
 		(_work)->data = (atomic_long_t) WORK_DATA_INIT();	\
 		INIT_LIST_HEAD(&(_work)->entry);			\
 		PREPARE_WORK((_work), (_func));				\
+		SET_WORK_NAME((_work), #_work);				\
 	} while (0)
 #endif
 
@@ -124,24 +152,28 @@ struct execute_work {
 	do {							\
 		INIT_WORK(&(_work)->work, (_func));		\
 		init_timer(&(_work)->timer);			\
+		SET_WORK_NAME(&(_work)->work, #_work);		\
 	} while (0)
 
 #define INIT_DELAYED_WORK_ON_STACK(_work, _func)		\
 	do {							\
 		INIT_WORK(&(_work)->work, (_func));		\
 		init_timer_on_stack(&(_work)->timer);		\
+		SET_WORK_NAME(&(_work)->work, #_work);		\
 	} while (0)
 
 #define INIT_DELAYED_WORK_DEFERRABLE(_work, _func)			\
 	do {							\
 		INIT_WORK(&(_work)->work, (_func));		\
 		init_timer_deferrable(&(_work)->timer);		\
+		SET_WORK_NAME(&(_work)->work, #_work);		\
 	} while (0)
 
 #define INIT_DELAYED_WORK_ON_STACK(_work, _func)		\
 	do {							\
 		INIT_WORK(&(_work)->work, (_func));		\
 		init_timer_on_stack(&(_work)->timer);		\
+		SET_WORK_NAME(&(_work)->work, #_work);		\
 	} while (0)
 
 /**
Index: b/include/trace/workqueue_event_types.h
===================================================================
--- a/include/trace/workqueue_event_types.h	2009-04-14 11:57:05.000000000 +0900
+++ b/include/trace/workqueue_event_types.h	2009-04-14 12:15:26.000000000 +0900
@@ -19,6 +19,7 @@ TRACE_EVENT(workqueue_insertion,
 		__field(pid_t,			thread_pid)
 		__field(struct work_struct *,	work)
 		__field(work_func_t,		func)
+		__field(char*,			workname)
 	),
 
 	TP_fast_assign(
@@ -26,10 +27,12 @@ TRACE_EVENT(workqueue_insertion,
 		__entry->thread_pid	= wq_thread->pid;
 		__entry->work		= work;
 		__entry->func		= work->func;
+		__entry->workname	= work->name;
 	),
 
-	TP_printk("thread=%s:%d func=%pF", __entry->thread_comm,
-		__entry->thread_pid, __entry->func)
+	TP_printk("thread=%s:%d func=%pF work=%s",
+		  __entry->thread_comm, __entry->thread_pid,
+		  __entry->func, __entry->workname)
 );
 
 TRACE_EVENT(workqueue_handler_entry,
@@ -45,6 +48,7 @@ TRACE_EVENT(workqueue_handler_entry,
 		__field(work_func_t,		func)
 		__field(unsigned long,		expected_time)
 		__field(unsigned long,		actual_time)
+		__field(char*,			workname)
 	),
 
 	TP_fast_assign(
@@ -54,12 +58,14 @@ TRACE_EVENT(workqueue_handler_entry,
 		__entry->func		= work->func;
 		__entry->expected_time	= work->expected_time;
 		__entry->actual_time	= jiffies;
+		__entry->workname	= work->name;
 	),
 
-	TP_printk("thread=%s:%d latency=%lums func=%pF", __entry->thread_comm,
-		  __entry->thread_pid,
+	TP_printk("thread=%s:%d latency=%lums func=%pF work=%s",
+		  __entry->thread_comm, __entry->thread_pid,
 		  jiffies_to_msecs(__entry->actual_time-__entry->expected_time),
-		  __entry->func)
+		  __entry->func,
+		  __entry->workname)
 );
 
 TRACE_EVENT(workqueue_handler_exit,
@@ -72,6 +78,7 @@ TRACE_EVENT(workqueue_handler_exit,
 		__field(pid_t,			thread_pid)
 		__field(struct work_struct *,	work)
 		__field(work_func_t,		func)
+		__field(char*,			workname)
 	),
 
 	TP_fast_assign(
@@ -79,10 +86,12 @@ TRACE_EVENT(workqueue_handler_exit,
 		__entry->thread_pid	= wq_thread->pid;
 		__entry->work		= work;
 		__entry->func		= work->func;
+		__entry->workname	= work->name;
 	),
 
-	TP_printk("thread=%s:%d func=%pF", __entry->thread_comm,
-		  __entry->thread_pid, __entry->func)
+	TP_printk("thread=%s:%d func=%pF work=%s",
+		  __entry->thread_comm, __entry->thread_pid,
+		  __entry->func, __entry->workname)
 );
 
 /* Trace the creation of one workqueue thread on a cpu */
Index: b/kernel/workqueue.c
===================================================================
--- a/kernel/workqueue.c	2009-04-14 11:57:05.000000000 +0900
+++ b/kernel/workqueue.c	2009-04-14 11:59:52.000000000 +0900
@@ -82,7 +82,7 @@ static const struct cpumask *cpu_singlet
  */
 static cpumask_var_t cpu_populated_map __read_mostly;
 
-#ifdef CONFIG_WORKQUEUE_TRACER
+#if HAVE_WORK_TRACE
 static void set_expected_time(struct work_struct *work,
 			      unsigned long expected_jiffies)
 {


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

Powered by blists - more mailing lists