linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] perf db-export: Fix thread__exec_comm()
@ 2019-08-08  6:48 Adrian Hunter
  2019-08-08 13:20 ` Arnaldo Carvalho de Melo
  2019-08-08 20:17 ` [tip:perf/urgent] " tip-bot for Adrian Hunter
  0 siblings, 2 replies; 3+ messages in thread
From: Adrian Hunter @ 2019-08-08  6:48 UTC (permalink / raw)
  To: Arnaldo Carvalho de Melo; +Cc: Jiri Olsa, linux-kernel

Threads synthesized from /proc have comms with a start time of zero, and
not marked as "exec". Currently, there can be 2 such comms. The first is
created by processing a synthesized fork event and is set to the parent's
comm string, and the second by processing a synthesized comm event set to
the thread's current comm string.

In the absence of an "exec" comm, thread__exec_comm() picks the last
(oldest) comm, which, in the case above, is the parent's comm string. For a
main thread, that is very probably wrong. Use the second-to-last in that
case.

This affects only db-export because it is the only user of
thread__exec_comm().

Example:

 $ sudo perf record -a -o pt-a-sleep-1 -e intel_pt//u -- sleep 1
 $ sudo chown ahunter pt-a-sleep-1

 Before:

 $ perf script -i pt-a-sleep-1 --itrace=bep -s tools/perf/scripts/python/export-to-sqlite.py pt-a-sleep-1.db branches calls
 $ sqlite3 -header -column pt-a-sleep-1.db 'select * from comm_threads_view'
 comm_id     command     thread_id   pid         tid
 ----------  ----------  ----------  ----------  ----------
 1           swapper     1           0           0
 2           rcu_sched   2           10          10
 3           kthreadd    3           78          78
 5           sudo        4           15180       15180
 5           sudo        5           15180       15182
 7           kworker/4:  6           10335       10335
 8           kthreadd    7           55          55
 10          systemd     8           865         865
 10          systemd     9           865         875
 13          perf        10          15181       15181
 15          sleep       10          15181       15181
 16          kworker/3:  11          14179       14179
 17          kthreadd    12          29376       29376
 19          systemd     13          746         746
 21          systemd     14          401         401
 23          systemd     15          879         879
 23          systemd     16          879         945
 25          kthreadd    17          556         556
 27          kworker/u1  18          14136       14136
 28          kworker/u1  19          15021       15021
 29          kthreadd    20          509         509
 31          systemd     21          836         836
 31          systemd     22          836         967
 33          systemd     23          1148        1148
 33          systemd     24          1148        1163
 35          kworker/2:  25          17988       17988
 36          kworker/0:  26          13478       13478

 After:

 $ perf script -i pt-a-sleep-1 --itrace=bep -s tools/perf/scripts/python/export-to-sqlite.py pt-a-sleep-1b.db branches calls
 $ sqlite3 -header -column pt-a-sleep-1b.db 'select * from comm_threads_view'
 comm_id     command     thread_id   pid         tid
 ----------  ----------  ----------  ----------  ----------
 1           swapper     1           0           0
 2           rcu_sched   2           10          10
 3           kswapd0     3           78          78
 4           perf        4           15180       15180
 4           perf        5           15180       15182
 6           kworker/4:  6           10335       10335
 7           kcompactd0  7           55          55
 8           accounts-d  8           865         865
 8           accounts-d  9           865         875
 10          perf        10          15181       15181
 12          sleep       10          15181       15181
 13          kworker/3:  11          14179       14179
 14          kworker/1:  12          29376       29376
 15          haveged     13          746         746
 16          systemd-jo  14          401         401
 17          NetworkMan  15          879         879
 17          NetworkMan  16          879         945
 19          irq/131-iw  17          556         556
 20          kworker/u1  18          14136       14136
 21          kworker/u1  19          15021       15021
 22          kworker/u1  20          509         509
 23          thermald    21          836         836
 23          thermald    22          836         967
 25          unity-sett  23          1148        1148
 25          unity-sett  24          1148        1163
 27          kworker/2:  25          17988       17988
 28          kworker/0:  26          13478       13478

Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Fixes: 65de51f93ebf ("perf tools: Identify which comms are from exec")
Cc: stable@vger.kernel.org
---
 tools/perf/util/thread.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/thread.c b/tools/perf/util/thread.c
index 873ab505ca80..590793cc5142 100644
--- a/tools/perf/util/thread.c
+++ b/tools/perf/util/thread.c
@@ -214,14 +214,24 @@ struct comm *thread__comm(const struct thread *thread)
 
 struct comm *thread__exec_comm(const struct thread *thread)
 {
-	struct comm *comm, *last = NULL;
+	struct comm *comm, *last = NULL, *second_last = NULL;
 
 	list_for_each_entry(comm, &thread->comm_list, list) {
 		if (comm->exec)
 			return comm;
+		second_last = last;
 		last = comm;
 	}
 
+	/*
+	 * 'last' with no start time might be the parent's comm of a synthesized
+	 * thread (created by processing a synthesized fork event). For a main
+	 * thread, that is very probably wrong. Prefer a later comm to avoid
+	 * that case.
+	 */
+	if (second_last && !last->start && thread->pid_ == thread->tid)
+		return second_last;
+
 	return last;
 }
 
-- 
2.17.1


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

* Re: [PATCH] perf db-export: Fix thread__exec_comm()
  2019-08-08  6:48 [PATCH] perf db-export: Fix thread__exec_comm() Adrian Hunter
@ 2019-08-08 13:20 ` Arnaldo Carvalho de Melo
  2019-08-08 20:17 ` [tip:perf/urgent] " tip-bot for Adrian Hunter
  1 sibling, 0 replies; 3+ messages in thread
From: Arnaldo Carvalho de Melo @ 2019-08-08 13:20 UTC (permalink / raw)
  To: Adrian Hunter; +Cc: Jiri Olsa, linux-kernel

Em Thu, Aug 08, 2019 at 09:48:23AM +0300, Adrian Hunter escreveu:
> Threads synthesized from /proc have comms with a start time of zero, and
> not marked as "exec". Currently, there can be 2 such comms. The first is
> created by processing a synthesized fork event and is set to the parent's
> comm string, and the second by processing a synthesized comm event set to
> the thread's current comm string.
> 
> In the absence of an "exec" comm, thread__exec_comm() picks the last
> (oldest) comm, which, in the case above, is the parent's comm string. For a
> main thread, that is very probably wrong. Use the second-to-last in that
> case.

Thanks, applied.

- Arnaldo
 
> This affects only db-export because it is the only user of
> thread__exec_comm().
> 
> Example:
> 
>  $ sudo perf record -a -o pt-a-sleep-1 -e intel_pt//u -- sleep 1
>  $ sudo chown ahunter pt-a-sleep-1
> 
>  Before:
> 
>  $ perf script -i pt-a-sleep-1 --itrace=bep -s tools/perf/scripts/python/export-to-sqlite.py pt-a-sleep-1.db branches calls
>  $ sqlite3 -header -column pt-a-sleep-1.db 'select * from comm_threads_view'
>  comm_id     command     thread_id   pid         tid
>  ----------  ----------  ----------  ----------  ----------
>  1           swapper     1           0           0
>  2           rcu_sched   2           10          10
>  3           kthreadd    3           78          78
>  5           sudo        4           15180       15180
>  5           sudo        5           15180       15182
>  7           kworker/4:  6           10335       10335
>  8           kthreadd    7           55          55
>  10          systemd     8           865         865
>  10          systemd     9           865         875
>  13          perf        10          15181       15181
>  15          sleep       10          15181       15181
>  16          kworker/3:  11          14179       14179
>  17          kthreadd    12          29376       29376
>  19          systemd     13          746         746
>  21          systemd     14          401         401
>  23          systemd     15          879         879
>  23          systemd     16          879         945
>  25          kthreadd    17          556         556
>  27          kworker/u1  18          14136       14136
>  28          kworker/u1  19          15021       15021
>  29          kthreadd    20          509         509
>  31          systemd     21          836         836
>  31          systemd     22          836         967
>  33          systemd     23          1148        1148
>  33          systemd     24          1148        1163
>  35          kworker/2:  25          17988       17988
>  36          kworker/0:  26          13478       13478
> 
>  After:
> 
>  $ perf script -i pt-a-sleep-1 --itrace=bep -s tools/perf/scripts/python/export-to-sqlite.py pt-a-sleep-1b.db branches calls
>  $ sqlite3 -header -column pt-a-sleep-1b.db 'select * from comm_threads_view'
>  comm_id     command     thread_id   pid         tid
>  ----------  ----------  ----------  ----------  ----------
>  1           swapper     1           0           0
>  2           rcu_sched   2           10          10
>  3           kswapd0     3           78          78
>  4           perf        4           15180       15180
>  4           perf        5           15180       15182
>  6           kworker/4:  6           10335       10335
>  7           kcompactd0  7           55          55
>  8           accounts-d  8           865         865
>  8           accounts-d  9           865         875
>  10          perf        10          15181       15181
>  12          sleep       10          15181       15181
>  13          kworker/3:  11          14179       14179
>  14          kworker/1:  12          29376       29376
>  15          haveged     13          746         746
>  16          systemd-jo  14          401         401
>  17          NetworkMan  15          879         879
>  17          NetworkMan  16          879         945
>  19          irq/131-iw  17          556         556
>  20          kworker/u1  18          14136       14136
>  21          kworker/u1  19          15021       15021
>  22          kworker/u1  20          509         509
>  23          thermald    21          836         836
>  23          thermald    22          836         967
>  25          unity-sett  23          1148        1148
>  25          unity-sett  24          1148        1163
>  27          kworker/2:  25          17988       17988
>  28          kworker/0:  26          13478       13478
> 
> Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
> Fixes: 65de51f93ebf ("perf tools: Identify which comms are from exec")
> Cc: stable@vger.kernel.org
> ---
>  tools/perf/util/thread.c | 12 +++++++++++-
>  1 file changed, 11 insertions(+), 1 deletion(-)
> 
> diff --git a/tools/perf/util/thread.c b/tools/perf/util/thread.c
> index 873ab505ca80..590793cc5142 100644
> --- a/tools/perf/util/thread.c
> +++ b/tools/perf/util/thread.c
> @@ -214,14 +214,24 @@ struct comm *thread__comm(const struct thread *thread)
>  
>  struct comm *thread__exec_comm(const struct thread *thread)
>  {
> -	struct comm *comm, *last = NULL;
> +	struct comm *comm, *last = NULL, *second_last = NULL;
>  
>  	list_for_each_entry(comm, &thread->comm_list, list) {
>  		if (comm->exec)
>  			return comm;
> +		second_last = last;
>  		last = comm;
>  	}
>  
> +	/*
> +	 * 'last' with no start time might be the parent's comm of a synthesized
> +	 * thread (created by processing a synthesized fork event). For a main
> +	 * thread, that is very probably wrong. Prefer a later comm to avoid
> +	 * that case.
> +	 */
> +	if (second_last && !last->start && thread->pid_ == thread->tid)
> +		return second_last;
> +
>  	return last;
>  }
>  
> -- 
> 2.17.1

-- 

- Arnaldo

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

* [tip:perf/urgent] perf db-export: Fix thread__exec_comm()
  2019-08-08  6:48 [PATCH] perf db-export: Fix thread__exec_comm() Adrian Hunter
  2019-08-08 13:20 ` Arnaldo Carvalho de Melo
@ 2019-08-08 20:17 ` tip-bot for Adrian Hunter
  1 sibling, 0 replies; 3+ messages in thread
From: tip-bot for Adrian Hunter @ 2019-08-08 20:17 UTC (permalink / raw)
  To: linux-tip-commits
  Cc: jolsa, acme, linux-kernel, adrian.hunter, mingo, hpa, tglx

Commit-ID:  3de7ae0b2a1d86dbb23d0cb135150534fdb2e836
Gitweb:     https://git.kernel.org/tip/3de7ae0b2a1d86dbb23d0cb135150534fdb2e836
Author:     Adrian Hunter <adrian.hunter@intel.com>
AuthorDate: Thu, 8 Aug 2019 09:48:23 +0300
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Thu, 8 Aug 2019 15:41:10 -0300

perf db-export: Fix thread__exec_comm()

Threads synthesized from /proc have comms with a start time of zero, and
not marked as "exec". Currently, there can be 2 such comms. The first is
created by processing a synthesized fork event and is set to the
parent's comm string, and the second by processing a synthesized comm
event set to the thread's current comm string.

In the absence of an "exec" comm, thread__exec_comm() picks the last
(oldest) comm, which, in the case above, is the parent's comm string.
For a main thread, that is very probably wrong. Use the second-to-last
in that case.

This affects only db-export because it is the only user of
thread__exec_comm().

Example:

  $ sudo perf record -a -o pt-a-sleep-1 -e intel_pt//u -- sleep 1
  $ sudo chown ahunter pt-a-sleep-1

Before:

  $ perf script -i pt-a-sleep-1 --itrace=bep -s tools/perf/scripts/python/export-to-sqlite.py pt-a-sleep-1.db branches calls
  $ sqlite3 -header -column pt-a-sleep-1.db 'select * from comm_threads_view'
  comm_id     command     thread_id   pid         tid
  ----------  ----------  ----------  ----------  ----------
  1           swapper     1           0           0
  2           rcu_sched   2           10          10
  3           kthreadd    3           78          78
  5           sudo        4           15180       15180
  5           sudo        5           15180       15182
  7           kworker/4:  6           10335       10335
  8           kthreadd    7           55          55
  10          systemd     8           865         865
  10          systemd     9           865         875
  13          perf        10          15181       15181
  15          sleep       10          15181       15181
  16          kworker/3:  11          14179       14179
  17          kthreadd    12          29376       29376
  19          systemd     13          746         746
  21          systemd     14          401         401
  23          systemd     15          879         879
  23          systemd     16          879         945
  25          kthreadd    17          556         556
  27          kworker/u1  18          14136       14136
  28          kworker/u1  19          15021       15021
  29          kthreadd    20          509         509
  31          systemd     21          836         836
  31          systemd     22          836         967
  33          systemd     23          1148        1148
  33          systemd     24          1148        1163
  35          kworker/2:  25          17988       17988
  36          kworker/0:  26          13478       13478

After:

  $ perf script -i pt-a-sleep-1 --itrace=bep -s tools/perf/scripts/python/export-to-sqlite.py pt-a-sleep-1b.db branches calls
  $ sqlite3 -header -column pt-a-sleep-1b.db 'select * from comm_threads_view'
  comm_id     command     thread_id   pid         tid
  ----------  ----------  ----------  ----------  ----------
  1           swapper     1           0           0
  2           rcu_sched   2           10          10
  3           kswapd0     3           78          78
  4           perf        4           15180       15180
  4           perf        5           15180       15182
  6           kworker/4:  6           10335       10335
  7           kcompactd0  7           55          55
  8           accounts-d  8           865         865
  8           accounts-d  9           865         875
  10          perf        10          15181       15181
  12          sleep       10          15181       15181
  13          kworker/3:  11          14179       14179
  14          kworker/1:  12          29376       29376
  15          haveged     13          746         746
  16          systemd-jo  14          401         401
  17          NetworkMan  15          879         879
  17          NetworkMan  16          879         945
  19          irq/131-iw  17          556         556
  20          kworker/u1  18          14136       14136
  21          kworker/u1  19          15021       15021
  22          kworker/u1  20          509         509
  23          thermald    21          836         836
  23          thermald    22          836         967
  25          unity-sett  23          1148        1148
  25          unity-sett  24          1148        1163
  27          kworker/2:  25          17988       17988
  28          kworker/0:  26          13478       13478

Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: stable@vger.kernel.org
Fixes: 65de51f93ebf ("perf tools: Identify which comms are from exec")
Link: http://lkml.kernel.org/r/20190808064823.14846-1-adrian.hunter@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/thread.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/thread.c b/tools/perf/util/thread.c
index 873ab505ca80..590793cc5142 100644
--- a/tools/perf/util/thread.c
+++ b/tools/perf/util/thread.c
@@ -214,14 +214,24 @@ struct comm *thread__comm(const struct thread *thread)
 
 struct comm *thread__exec_comm(const struct thread *thread)
 {
-	struct comm *comm, *last = NULL;
+	struct comm *comm, *last = NULL, *second_last = NULL;
 
 	list_for_each_entry(comm, &thread->comm_list, list) {
 		if (comm->exec)
 			return comm;
+		second_last = last;
 		last = comm;
 	}
 
+	/*
+	 * 'last' with no start time might be the parent's comm of a synthesized
+	 * thread (created by processing a synthesized fork event). For a main
+	 * thread, that is very probably wrong. Prefer a later comm to avoid
+	 * that case.
+	 */
+	if (second_last && !last->start && thread->pid_ == thread->tid)
+		return second_last;
+
 	return last;
 }
 

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

end of thread, other threads:[~2019-08-08 20:17 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-08-08  6:48 [PATCH] perf db-export: Fix thread__exec_comm() Adrian Hunter
2019-08-08 13:20 ` Arnaldo Carvalho de Melo
2019-08-08 20:17 ` [tip:perf/urgent] " tip-bot for Adrian Hunter

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).