| 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
| ||
|
Message-ID: <20090414211620.GB5968@nowhere>
Date: Tue, 14 Apr 2009 23:16:22 +0200
From: Frederic Weisbecker <fweisbec@...il.com>
To: KOSAKI Motohiro <kosaki.motohiro@...fujitsu.com>
Cc: Zhaolei <zhaolei@...fujitsu.com>,
Steven Rostedt <rostedt@...dmis.org>,
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>
Subject: Re: [PATCH v2 5/4] ftrace, workqueuetrace: display work name
On Tue, Apr 14, 2009 at 01:03:35PM +0900, KOSAKI Motohiro wrote:
>
> 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>
> ---
I don't know. Does it happen that frequently for a function to be used
by several works?
If so, this feature may be indeed interesting.
Thanks,
Frederic Weisbecker.
> 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