Hi,
This patch add max execution time mesurement for per worklet.
It is useful for driver-developer and system administrator to
know which worklet runs how many time.
It need applied on top of patchset of:
workqueue_tracepoint: Add worklet tracepoints for worklet lifecycle tracing
Output is like:
# CPU INSERTED EXECUTED M_EXECus TASKNAME:PID
# | | | | `-WORKFUNC
# | | | | |
0 905 973 events/0:5
0 1 1 37 |-reg_todo+0x0/0x41f
0 13 12 2033 |-rt_worker_func+0x0/0x219
0 49 48 3157 |-mce_work_fn+0x0/0x31
0 14 13 939 |-check_corruption+0x0/0x2a
0 707 706 3826 |-vmstat_update+0x0/0x33
0 1 1 1846 |-power_supply_changed_work+0x0/0x3c
0 11 11 2879 |-console_callback+0x0/0xe1
0 30 29 1579 |-do_cache_clean+0x0/0x37
0 74 74 2841 |-test_work+0x0/0x53
0 3 2 252 |-rekey_seq_generator+0x0/0x5a
0 1 1 21 |-grace_ender+0x0/0x14
0 1 1 3701 `-flush_to_ldisc+0x0/0x15d
0 0 0 cpuset:6
0 658 658 khelper:7
0 658 658 5735 `-__call_usermodehelper+0x0/0x77
0 0 0 netns:11
...
Thanks
Zhaolei
struct workfunc_stats is belong to per_cpu struct of cpu_workqueue_stats,
which means we only need to serialize its accessing from one cpu.
And because trace_workqueue_insertion() is already inside a section
protected by the cpu workqueue lock, we can safely convert it into an
unsigned int.
[ Impact: cleanup ]
Reported-by: Oleg Nesterov <[email protected]>
Signed-off-by: Zhao Lei <[email protected]>
---
kernel/trace/trace_workqueue.c | 13 +++++--------
1 files changed, 5 insertions(+), 8 deletions(-)
diff --git a/kernel/trace/trace_workqueue.c b/kernel/trace/trace_workqueue.c
index 69ae4aa..7a07d17 100644
--- a/kernel/trace/trace_workqueue.c
+++ b/kernel/trace/trace_workqueue.c
@@ -20,12 +20,9 @@ struct workfunc_stats {
/* Addr of worklet's callback function */
work_func_t func;
- /* Can be inserted on different workqueues, need to be atomic */
- atomic_t inserted;
- /*
- * Don't need to be atomic, works are serialized in a single workqueue
- * thread on a single CPU.
- */
+
+ /* Protected by cpu workqueue lock */
+ unsigned int inserted;
unsigned int executed;
};
@@ -80,7 +77,7 @@ int do_worklet_enqueue(struct cpu_workqueue_stats *cws,
list_add_tail(&wfstat->list, &cws->workfunclist);
found:
- atomic_inc(&wfstat->inserted);
+ wfstat->inserted++;
return 0;
}
@@ -331,7 +328,7 @@ static int workqueue_stat_show(struct seq_file *s, void *p)
int lastwf = list_is_last(&wfstat->list, &cws->workfunclist);
seq_printf(s, "%3d %6d %6u %c-%pF\n",
cws->cpu,
- atomic_read(&wfstat->inserted),
+ wfstat->inserted,
wfstat->executed,
lastwf ? '`' : '|',
wfstat->func);
--
1.5.5.3
Workqueue task maybe destroyed when read stat file.
We should avoid getting information from task_struct this time.
Signed-off-by: Zhao Lei <[email protected]>
Reported-by: Oleg Nesterov <[email protected]>
---
kernel/trace/trace_workqueue.c | 50 ++++++++++++++++++++--------------------
1 files changed, 25 insertions(+), 25 deletions(-)
diff --git a/kernel/trace/trace_workqueue.c b/kernel/trace/trace_workqueue.c
index 7a07d17..51ed57e 100644
--- a/kernel/trace/trace_workqueue.c
+++ b/kernel/trace/trace_workqueue.c
@@ -28,14 +28,22 @@ struct workfunc_stats {
/* A cpu workqueue thread */
struct cpu_workqueue_stats {
- struct list_head list;
- int cpu;
- pid_t pid;
+ struct list_head list;
+ int cpu;
+
/* Protected by cpu workqueue lock */
- unsigned int inserted;
- unsigned int executed;
+ unsigned int inserted;
+ unsigned int executed;
/* list of struct workfunc_stats in this workqueue */
- struct list_head workfunclist;
+ struct list_head workfunclist;
+
+ /*
+ * the task maybe destroyed when we read stat file
+ * we define it to void * because we only use it as a identifier
+ */
+ void *task;
+ int pid;
+ char comm[TASK_COMM_LEN];
};
/* List of workqueue threads on one cpu */
@@ -93,7 +101,7 @@ probe_worklet_enqueue(struct task_struct *wq_thread, struct work_struct *work,
spin_lock_irqsave(&workqueue_cpu_stat(wqcpu)->lock, flags);
list_for_each_entry(node, &workqueue_cpu_stat(wqcpu)->list, list) {
- if (node->pid == wq_thread->pid) {
+ if (node->task == wq_thread) {
/* we ignore error of do_worklet_insertion */
do_worklet_enqueue(node, work);
goto found;
@@ -124,7 +132,7 @@ probe_worklet_execute(struct task_struct *wq_thread, struct work_struct *work)
spin_lock_irqsave(&workqueue_cpu_stat(cpu)->lock, flags);
list_for_each_entry(node, &workqueue_cpu_stat(cpu)->list, list)
- if (node->pid == wq_thread->pid) {
+ if (node->task == wq_thread) {
node->executed++;
goto found_wq;
}
@@ -163,7 +171,9 @@ static void probe_workqueue_creation(struct task_struct *wq_thread, int cpu)
INIT_LIST_HEAD(&cws->list);
cws->cpu = cpu;
+ cws->task = wq_thread;
cws->pid = wq_thread->pid;
+ strncpy(cws->comm, wq_thread->comm, TASK_COMM_LEN);
INIT_LIST_HEAD(&cws->workfunclist);
/*
@@ -204,7 +214,7 @@ static void probe_workqueue_destruction(struct task_struct *wq_thread)
list) {
struct workfunc_stats *wfstat, *wfstatnext;
- if (node->pid != wq_thread->pid)
+ if (node->task != wq_thread)
continue;
list_for_each_entry_safe(wfstat, wfstatnext,
@@ -304,25 +314,15 @@ static int workqueue_stat_show(struct seq_file *s, void *p)
{
struct workfunc_stats *wfstat = p;
struct cpu_workqueue_stats *cws = wfstat->parent;
- struct pid *pid;
- struct task_struct *tsk;
if (!wfstat->func) {
/* It is first dummy node, need to print workqueue info */
- pid = find_get_pid(cws->pid);
- if (pid) {
- tsk = get_pid_task(pid, PIDTYPE_PID);
- if (tsk) {
- seq_printf(s, "%3d %6d %6u %s:%d\n",
- cws->cpu,
- cws->inserted,
- cws->executed,
- tsk->comm,
- cws->pid);
- put_task_struct(tsk);
- }
- put_pid(pid);
- }
+ seq_printf(s, "%3d %6d %6u %s:%d\n",
+ cws->cpu,
+ cws->inserted,
+ cws->executed,
+ cws->comm,
+ cws->pid);
} else {
/* It is effect node, need to print workfunc info */
int lastwf = list_is_last(&wfstat->list, &cws->workfunclist);
--
1.5.5.3
No need to use list_for_each_entry_safe() because we just remove one list node
which is first found in list iteration.
(we don't continue list iteration after remove list node)
Signed-off-by: Zhao Lei <[email protected]>
---
kernel/trace/trace_workqueue.c | 5 ++---
1 files changed, 2 insertions(+), 3 deletions(-)
diff --git a/kernel/trace/trace_workqueue.c b/kernel/trace/trace_workqueue.c
index 51ed57e..b995bc0 100644
--- a/kernel/trace/trace_workqueue.c
+++ b/kernel/trace/trace_workqueue.c
@@ -206,12 +206,11 @@ static void probe_workqueue_destruction(struct task_struct *wq_thread)
{
/* Workqueue only execute on one cpu */
int cpu = cpumask_first(&wq_thread->cpus_allowed);
- struct cpu_workqueue_stats *node, *next;
+ struct cpu_workqueue_stats *node;
unsigned long flags;
spin_lock_irqsave(&workqueue_cpu_stat(cpu)->lock, flags);
- list_for_each_entry_safe(node, next, &workqueue_cpu_stat(cpu)->list,
- list) {
+ list_for_each_entry(node, &workqueue_cpu_stat(cpu)->list, list) {
struct workfunc_stats *wfstat, *wfstatnext;
if (node->task != wq_thread)
--
1.5.5.3
From: KOSAKI Motohiro <[email protected]>
It is useful for driver-developer and system administrator to
know which worklet runs how many time.
Change Log:
v1: KOSAKI Motohiro <[email protected]>
add max execution time mesurement for per workqueue
v2: Zhao Lei <[email protected]>
add max execution time mesurement for per worklet instead of workqueue
Output is like:
# CPU INSERTED EXECUTED M_EXECus TASKNAME:PID
# | | | | `-WORKFUNC
# | | | | |
0 905 973 events/0:5
0 1 1 37 |-reg_todo+0x0/0x41f
0 13 12 2033 |-rt_worker_func+0x0/0x219
0 49 48 3157 |-mce_work_fn+0x0/0x31
0 14 13 939 |-check_corruption+0x0/0x2a
0 707 706 3826 |-vmstat_update+0x0/0x33
0 1 1 1846 |-power_supply_changed_work+0x0/0x3c
0 11 11 2879 |-console_callback+0x0/0xe1
0 30 29 1579 |-do_cache_clean+0x0/0x37
0 74 74 2841 |-test_work+0x0/0x53
0 3 2 252 |-rekey_seq_generator+0x0/0x5a
0 1 1 21 |-grace_ender+0x0/0x14
0 1 1 3701 `-flush_to_ldisc+0x0/0x15d
0 0 0 cpuset:6
0 658 658 khelper:7
0 658 658 5735 `-__call_usermodehelper+0x0/0x77
0 0 0 netns:11
...
Signed-off-by: Zhao Lei <[email protected]>
Signed-off-by: KOSAKI Motohiro <[email protected]>
---
kernel/trace/trace_workqueue.c | 83 +++++++++++++++++++++++++++++++++------
1 files changed, 70 insertions(+), 13 deletions(-)
diff --git a/kernel/trace/trace_workqueue.c b/kernel/trace/trace_workqueue.c
index b995bc0..30b0075 100644
--- a/kernel/trace/trace_workqueue.c
+++ b/kernel/trace/trace_workqueue.c
@@ -24,6 +24,17 @@ struct workfunc_stats {
/* Protected by cpu workqueue lock */
unsigned int inserted;
unsigned int executed;
+
+ /*
+ * save latest work_struct's pointer to use as identifier in
+ * probe_worklet_complete, because we can't use work_struct->...
+ * after worklet got executed
+ */
+ void *work;
+
+ /* save execution time temporarily for calculate executed time */
+ u64 start_time;
+ u64 max_executed_time;
};
/* A cpu workqueue thread */
@@ -143,6 +154,8 @@ found_wq:
list_for_each_entry(wfnode, &node->workfunclist, list)
if (wfnode->func == work->func) {
wfnode->executed++;
+ wfnode->start_time = trace_clock_global();
+ wfnode->work = work;
goto found_wf;
}
pr_debug("trace_workqueue: worklet not found\n");
@@ -153,6 +166,43 @@ end:
spin_unlock_irqrestore(&workqueue_cpu_stat(cpu)->lock, flags);
}
+/* Complete of a work */
+static void
+probe_worklet_complete(struct task_struct *wq_thread, void *work)
+{
+ int cpu = cpumask_first(&wq_thread->cpus_allowed);
+ struct cpu_workqueue_stats *node;
+ struct workfunc_stats *wfnode;
+ unsigned long flags;
+
+ spin_lock_irqsave(&workqueue_cpu_stat(cpu)->lock, flags);
+
+ list_for_each_entry(node, &workqueue_cpu_stat(cpu)->list, list)
+ if (node->task == wq_thread)
+ goto found_wq;
+ pr_debug("trace_workqueue: workqueue not found\n");
+ goto end;
+
+found_wq:
+ list_for_each_entry(wfnode, &node->workfunclist, list) {
+ u64 executed_time;
+
+ if (wfnode->work != work)
+ continue;
+
+ executed_time = trace_clock_global() - wfnode->start_time;
+ if (executed_time > wfnode->max_executed_time)
+ wfnode->max_executed_time = executed_time;
+ goto found_wf;
+ }
+ pr_debug("trace_workqueue: worklet not found\n");
+ goto end;
+
+found_wf:
+end:
+ spin_unlock_irqrestore(&workqueue_cpu_stat(cpu)->lock, flags);
+}
+
/* Creation of a cpu workqueue thread */
static void probe_workqueue_creation(struct task_struct *wq_thread, int cpu)
{
@@ -316,7 +366,7 @@ static int workqueue_stat_show(struct seq_file *s, void *p)
if (!wfstat->func) {
/* It is first dummy node, need to print workqueue info */
- seq_printf(s, "%3d %6d %6u %s:%d\n",
+ seq_printf(s, " %3d %6d %6u %s:%d\n",
cws->cpu,
cws->inserted,
cws->executed,
@@ -325,10 +375,11 @@ static int workqueue_stat_show(struct seq_file *s, void *p)
} else {
/* It is effect node, need to print workfunc info */
int lastwf = list_is_last(&wfstat->list, &cws->workfunclist);
- seq_printf(s, "%3d %6d %6u %c-%pF\n",
+ seq_printf(s, " %3d %6d %6u %6llu %c-%pF\n",
cws->cpu,
wfstat->inserted,
wfstat->executed,
+ ns2usecs(wfstat->max_executed_time),
lastwf ? '`' : '|',
wfstat->func);
}
@@ -338,9 +389,9 @@ static int workqueue_stat_show(struct seq_file *s, void *p)
static int workqueue_stat_headers(struct seq_file *s)
{
- seq_printf(s, "# CPU INSERTED EXECUTED TASKNAME:PID\n");
- seq_printf(s, "# | | | `-WORKFUNC\n");
- seq_printf(s, "# | | | |\n");
+ seq_printf(s, "# CPU INSERTED EXECUTED M_EXECus TASKNAME:PID\n");
+ seq_printf(s, "# | | | | `-WORKFUNC\n");
+ seq_printf(s, "# | | | | |\n");
return 0;
}
@@ -379,19 +430,23 @@ int __init trace_workqueue_early_init(void)
ret = register_trace_worklet_enqueue_delayed(
probe_worklet_enqueue_delayed);
if (ret)
- goto no_enqueue;
+ goto out_worklet_enqueue;
ret = register_trace_worklet_execute(probe_worklet_execute);
if (ret)
- goto no_enqueue_delayed;
+ goto out_worklet_enqueue_delayed;
+
+ ret = register_trace_worklet_complete(probe_worklet_complete);
+ if (ret)
+ goto out_worklet_execute;
ret = register_trace_workqueue_creation(probe_workqueue_creation);
if (ret)
- goto no_handler_entry;
+ goto out_worklet_complete;
ret = register_trace_workqueue_destruction(probe_workqueue_destruction);
if (ret)
- goto no_creation;
+ goto out_workqueue_creation;
for_each_possible_cpu(cpu) {
spin_lock_init(&workqueue_cpu_stat(cpu)->lock);
@@ -400,13 +455,15 @@ int __init trace_workqueue_early_init(void)
return 0;
-no_creation:
+out_workqueue_creation:
unregister_trace_workqueue_creation(probe_workqueue_creation);
-no_handler_entry:
+out_worklet_complete:
+ unregister_trace_worklet_complete(probe_worklet_complete);
+out_worklet_execute:
unregister_trace_worklet_execute(probe_worklet_execute);
-no_enqueue_delayed:
+out_worklet_enqueue_delayed:
unregister_trace_worklet_enqueue_delayed(probe_worklet_enqueue_delayed);
-no_enqueue:
+out_worklet_enqueue:
unregister_trace_worklet_enqueue(probe_worklet_enqueue);
out:
pr_warning("trace_workqueue: unable to trace workqueues\n");
--
1.5.5.3
I have no idea how the code actually looks with these patches applied,
so please don't take my words seriously, but
On 04/28, Zhaolei wrote:
>
> @@ -24,6 +24,17 @@ struct workfunc_stats {
> /* Protected by cpu workqueue lock */
> unsigned int inserted;
> unsigned int executed;
> +
> + /*
> + * save latest work_struct's pointer to use as identifier in
> + * probe_worklet_complete, because we can't use work_struct->...
> + * after worklet got executed
> + */
> + void *work;
Do we really need it ?
> @@ -143,6 +154,8 @@ found_wq:
> list_for_each_entry(wfnode, &node->workfunclist, list)
> if (wfnode->func == work->func) {
> wfnode->executed++;
> + wfnode->start_time = trace_clock_global();
> + wfnode->work = work;
> goto found_wf;
> }
> pr_debug("trace_workqueue: worklet not found\n");
> @@ -153,6 +166,43 @@ end:
> spin_unlock_irqrestore(&workqueue_cpu_stat(cpu)->lock, flags);
> }
>
> +/* Complete of a work */
> +static void
> +probe_worklet_complete(struct task_struct *wq_thread, void *work)
> +{
> + int cpu = cpumask_first(&wq_thread->cpus_allowed);
> + struct cpu_workqueue_stats *node;
> + struct workfunc_stats *wfnode;
> + unsigned long flags;
> +
> + spin_lock_irqsave(&workqueue_cpu_stat(cpu)->lock, flags);
> +
> + list_for_each_entry(node, &workqueue_cpu_stat(cpu)->list, list)
> + if (node->task == wq_thread)
> + goto found_wq;
> + pr_debug("trace_workqueue: workqueue not found\n");
> + goto end;
> +
> +found_wq:
> + list_for_each_entry(wfnode, &node->workfunclist, list) {
> + u64 executed_time;
> +
> + if (wfnode->work != work)
> + continue;
Perhaps we can add node->last_work (or whatever) instead? It should be
recorded by the "entry" handler. In this case probe_worklet_complete()
doesn't need to search for this work (and it doesn't need the argument).
We know that wfnode == node->last_work.
Oleg.
On Tue, Apr 28, 2009 at 06:51:33PM +0800, Zhaolei wrote:
> Hi,
>
> This patch add max execution time mesurement for per worklet.
> It is useful for driver-developer and system administrator to
> know which worklet runs how many time.
>
> It need applied on top of patchset of:
> workqueue_tracepoint: Add worklet tracepoints for worklet lifecycle tracing
>
> Output is like:
> # CPU INSERTED EXECUTED M_EXECus TASKNAME:PID
> # | | | | `-WORKFUNC
> # | | | | |
> 0 905 973 events/0:5
> 0 1 1 37 |-reg_todo+0x0/0x41f
> 0 13 12 2033 |-rt_worker_func+0x0/0x219
> 0 49 48 3157 |-mce_work_fn+0x0/0x31
> 0 14 13 939 |-check_corruption+0x0/0x2a
> 0 707 706 3826 |-vmstat_update+0x0/0x33
> 0 1 1 1846 |-power_supply_changed_work+0x0/0x3c
> 0 11 11 2879 |-console_callback+0x0/0xe1
> 0 30 29 1579 |-do_cache_clean+0x0/0x37
> 0 74 74 2841 |-test_work+0x0/0x53
> 0 3 2 252 |-rekey_seq_generator+0x0/0x5a
> 0 1 1 21 |-grace_ender+0x0/0x14
> 0 1 1 3701 `-flush_to_ldisc+0x0/0x15d
> 0 0 0 cpuset:6
> 0 658 658 khelper:7
> 0 658 658 5735 `-__call_usermodehelper+0x0/0x77
> 0 0 0 netns:11
> ...
>
> Thanks
> Zhaolei
>
Thanks Zhaolei,
I've applied this series and the previous one to
git://git.kernel.org/pub/scm/linux/kernel/git/frederic/random-tracing.git
tracing/workqueue
On Tue, 28 Apr 2009 18:51:33 +0800 Zhaolei <[email protected]> wrote:
> Hi,
>
> This patch add max execution time mesurement for per worklet.
> It is useful for driver-developer and system administrator to
> know which worklet runs how many time.
This seems more useful than the previous feature.
> It need applied on top of patchset of:
> workqueue_tracepoint: Add worklet tracepoints for worklet lifecycle tracing
>
> Output is like:
> # CPU INSERTED EXECUTED M_EXECus TASKNAME:PID
> # | | | | `-WORKFUNC
> # | | | | |
> 0 905 973 events/0:5
> 0 1 1 37 |-reg_todo+0x0/0x41f
> 0 13 12 2033 |-rt_worker_func+0x0/0x219
> 0 49 48 3157 |-mce_work_fn+0x0/0x31
> 0 14 13 939 |-check_corruption+0x0/0x2a
> 0 707 706 3826 |-vmstat_update+0x0/0x33
> 0 1 1 1846 |-power_supply_changed_work+0x0/0x3c
> 0 11 11 2879 |-console_callback+0x0/0xe1
> 0 30 29 1579 |-do_cache_clean+0x0/0x37
> 0 74 74 2841 |-test_work+0x0/0x53
> 0 3 2 252 |-rekey_seq_generator+0x0/0x5a
> 0 1 1 21 |-grace_ender+0x0/0x14
> 0 1 1 3701 `-flush_to_ldisc+0x0/0x15d
> 0 0 0 cpuset:6
> 0 658 658 khelper:7
> 0 658 658 5735 `-__call_usermodehelper+0x0/0x77
> 0 0 0 netns:11
What is the meaning of M_EXECus? Mean execution time in microseconds,
I assume? I wonder if that is sufficiently high resolution nowadays.
You'll note that all the functions are reported as "foo+0x0/0xN".
There is a way of suppressing the unneeded and unuseful "+0x0/0xN",
but I forget what it is and the comments over lib/vsprintf.c:pointer()
didn't help. I think it's %pS.
The patchset adds no user documentation for the feature and should not
(IMO) be merged in such a state. Please.
On Wed, Apr 29, 2009 at 12:06:16AM -0700, Andrew Morton wrote:
> What is the meaning of M_EXECus? Mean execution time in microseconds,
> I assume? I wonder if that is sufficiently high resolution nowadays.
It's the maximum execution time encountered for a given worklet.
I also have a small patch, about ready, to get the average.
> You'll note that all the functions are reported as "foo+0x0/0xN".
> There is a way of suppressing the unneeded and unuseful "+0x0/0xN",
> but I forget what it is and the comments over lib/vsprintf.c:pointer()
> didn't help. I think it's %pS.
I don't know any way to perform this.
%pF and %pS will act pretty much the same, except:
Extract from lib/vsprintf.c:
* Note: The difference between 'S' and 'F' is that on ia64 and ppc64
* function pointers are really function descriptors, which contain a
* pointer to the real address.
But the output formatting is the same: address, offset, size, modname.
I found it a bit annoying, so I proposed the following patch recently:
http://lkml.org/lkml/2009/4/15/310
And someone came with a better idea, IMO:
http://lkml.org/lkml/2009/4/17/105
>
> The patchset adds no user documentation for the feature and should not
> (IMO) be merged in such a state. Please.
>
Ok, I will try something today about the documentation.
Thanks!
On Wed, 29 Apr 2009, Frederic Weisbecker wrote:
> On Wed, Apr 29, 2009 at 12:06:16AM -0700, Andrew Morton wrote:
> > What is the meaning of M_EXECus? Mean execution time in microseconds,
> > I assume? I wonder if that is sufficiently high resolution nowadays.
>
>
> It's the maximum execution time encountered for a given worklet.
> I also have a small patch, about ready, to get the average.
>
>
> > You'll note that all the functions are reported as "foo+0x0/0xN".
> > There is a way of suppressing the unneeded and unuseful "+0x0/0xN",
> > but I forget what it is and the comments over lib/vsprintf.c:pointer()
> > didn't help. I think it's %pS.
>
>
> I don't know any way to perform this.
> %pF and %pS will act pretty much the same, except:
>
> Extract from lib/vsprintf.c:
>
> * Note: The difference between 'S' and 'F' is that on ia64 and ppc64
> * function pointers are really function descriptors, which contain a
> * pointer to the real address.
>
> But the output formatting is the same: address, offset, size, modname.
I could not find any way to remove it, thus I wrote my own version of %pF
to get rid of the +0x0/0xN notations in the output for ftrace.
-- Steve
On Wed, 29 Apr 2009, Frederic Weisbecker wrote:
> * pointer to the real address.
>
> But the output formatting is the same: address, offset, size, modname.
>
> I found it a bit annoying, so I proposed the following patch recently:
>
> http://lkml.org/lkml/2009/4/15/310
>
> And someone came with a better idea, IMO:
>
> http://lkml.org/lkml/2009/4/17/105
Note,
If these ever do get merged, I would be happy to convert ftrace to use
them to replace my version.
-- Steve
On Wed, 29 Apr 2009 09:45:28 -0400 (EDT) Steven Rostedt <[email protected]> wrote:
>
> On Wed, 29 Apr 2009, Frederic Weisbecker wrote:
> > * pointer to the real address.
> >
> > But the output formatting is the same: address, offset, size, modname.
> >
> > I found it a bit annoying, so I proposed the following patch recently:
> >
> > http://lkml.org/lkml/2009/4/15/310
This looks OK. I'd assumed it was merged. Was there a problem with it?
> > And someone came with a better idea, IMO:
> >
> > http://lkml.org/lkml/2009/4/17/105
>
> Note,
>
> If these ever do get merged, I would be happy to convert ftrace to use
> them to replace my version.
I spose I could use magic powers to sneak it into .30?
On Wed, Apr 29, 2009 at 08:36:54AM -0700, Andrew Morton wrote:
> On Wed, 29 Apr 2009 09:45:28 -0400 (EDT) Steven Rostedt <[email protected]> wrote:
>
> >
> > On Wed, 29 Apr 2009, Frederic Weisbecker wrote:
> > > * pointer to the real address.
> > >
> > > But the output formatting is the same: address, offset, size, modname.
> > >
> > > I found it a bit annoying, so I proposed the following patch recently:
> > >
> > > http://lkml.org/lkml/2009/4/15/310
>
> This looks OK. I'd assumed it was merged. Was there a problem with it?
No, I tested it without problem.
> > > And someone came with a better idea, IMO:
> > >
> > > http://lkml.org/lkml/2009/4/17/105
> >
> > Note,
> >
> > If these ever do get merged, I would be happy to convert ftrace to use
> > them to replace my version.
>
> I spose I could use magic powers to sneak it into .30?
Thanks :)
* Frederic Weisbecker <[email protected]> wrote:
> > > > And someone came with a better idea, IMO:
> > > >
> > > > http://lkml.org/lkml/2009/4/17/105
> > >
> > > Note,
> > >
> > > If these ever do get merged, I would be happy to convert ftrace to use
> > > them to replace my version.
> >
> > I spose I could use magic powers to sneak it into .30?
>
> Thanks :)
Andrew: if you do that then please pick up the commit i queued up in
tip:core/printk.
Ingo
Oleg Nesterov wrote:
> I have no idea how the code actually looks with these patches applied,
> so please don't take my words seriously, but
>
> On 04/28, Zhaolei wrote:
>> @@ -24,6 +24,17 @@ struct workfunc_stats {
>> /* Protected by cpu workqueue lock */
>> unsigned int inserted;
>> unsigned int executed;
>> +
>> + /*
>> + * save latest work_struct's pointer to use as identifier in
>> + * probe_worklet_complete, because we can't use work_struct->...
>> + * after worklet got executed
>> + */
>> + void *work;
>
> Do we really need it ?
>
>> @@ -143,6 +154,8 @@ found_wq:
>> list_for_each_entry(wfnode, &node->workfunclist, list)
>> if (wfnode->func == work->func) {
>> wfnode->executed++;
>> + wfnode->start_time = trace_clock_global();
>> + wfnode->work = work;
>> goto found_wf;
>> }
>> pr_debug("trace_workqueue: worklet not found\n");
>> @@ -153,6 +166,43 @@ end:
>> spin_unlock_irqrestore(&workqueue_cpu_stat(cpu)->lock, flags);
>> }
>>
>> +/* Complete of a work */
>> +static void
>> +probe_worklet_complete(struct task_struct *wq_thread, void *work)
>> +{
>> + int cpu = cpumask_first(&wq_thread->cpus_allowed);
>> + struct cpu_workqueue_stats *node;
>> + struct workfunc_stats *wfnode;
>> + unsigned long flags;
>> +
>> + spin_lock_irqsave(&workqueue_cpu_stat(cpu)->lock, flags);
>> +
>> + list_for_each_entry(node, &workqueue_cpu_stat(cpu)->list, list)
>> + if (node->task == wq_thread)
>> + goto found_wq;
>> + pr_debug("trace_workqueue: workqueue not found\n");
>> + goto end;
>> +
>> +found_wq:
>> + list_for_each_entry(wfnode, &node->workfunclist, list) {
>> + u64 executed_time;
>> +
>> + if (wfnode->work != work)
>> + continue;
>
> Perhaps we can add node->last_work (or whatever) instead? It should be
> recorded by the "entry" handler. In this case probe_worklet_complete()
> doesn't need to search for this work (and it doesn't need the argument).
> We know that wfnode == node->last_work.
Hello, Oleg
Sorry for reply late.
Thanks for review of this patch.
This is indeed a good idea, I will change to this way
Thanks
Zhaolei
>
> Oleg.
>
>