perf tip: fails to convert comm

perf tip: fails to convert comm

[David Ahern]

Hi Namhyung and Frederic:

If you recall I mentioned noting a problem with the callchain series 
showing comm's. Well, it fails on acme's perf/core. git bisect points to:

$ git bisect bad
4dfced359fbc719a35527416f1b4b3999647f68b is the first bad commit
commit 4dfced359fbc719a35527416f1b4b3999647f68b
Author: Namhyung Kim <namhyung.kim@lge.com>
Date:   Fri Sep 13 16:28:57 2013 +0900

     perf tools: Get current comm instead of last one

     At insert time, a hist entry should reference comm at the time 
otherwise
     it'll get the last comm anyway.


How to re-create:

Start point is tools/perf directory for 3.12 (Linus tree):
   $ perf sched record -o /tmp/perf.data -g -- make -j 16
   $ perf script -i /tmp/perf.data > /tmp/1

cd to Arnaldo's tree, make perf and use it to create /tmp/2:
   $ perf script -i /tmp/perf.data > /tmp/1
   $ diff -U3 /tmp/1 /tmp/2 | less

You'll see a number of comm's showing as :<pid> instead of make, etc.

David

Re: perf tip: fails to convert comm

[Frederic Weisbecker]

On Tue, Nov 12, 2013 at 09:58:29PM -0700, David Ahern wrote:
> Hi Namhyung and Frederic:
> 
> If you recall I mentioned noting a problem with the callchain series
> showing comm's. Well, it fails on acme's perf/core. git bisect
> points to:
> 
> $ git bisect bad
> 4dfced359fbc719a35527416f1b4b3999647f68b is the first bad commit
> commit 4dfced359fbc719a35527416f1b4b3999647f68b
> Author: Namhyung Kim <namhyung.kim@lge.com>
> Date:   Fri Sep 13 16:28:57 2013 +0900
> 
>     perf tools: Get current comm instead of last one
> 
>     At insert time, a hist entry should reference comm at the time
> otherwise
>     it'll get the last comm anyway.
> 
> 
> How to re-create:
> 
> Start point is tools/perf directory for 3.12 (Linus tree):
>   $ perf sched record -o /tmp/perf.data -g -- make -j 16
>   $ perf script -i /tmp/perf.data > /tmp/1
> 
> cd to Arnaldo's tree, make perf and use it to create /tmp/2:
>   $ perf script -i /tmp/perf.data > /tmp/1
>   $ diff -U3 /tmp/1 /tmp/2 | less
> 
> You'll see a number of comm's showing as :<pid> instead of make, etc.

I see. I can reproduce, I'll check and see what happens. It would be nice if
we could have an option to dump internal perf events like comm events as well
in the perf script stream.

Re: perf tip: fails to convert comm

[David Ahern]

On 11/13/13, 11:03 AM, Frederic Weisbecker wrote:
> I see. I can reproduce, I'll check and see what happens. It would be nice if
> we could have an option to dump internal perf events like comm events as well
> in the perf script stream.

I've been thinking about moving the event dumping code from perf-script 
to perf-dump. In the process could add an argument to dump events -- 
similar to -D option for report/script, but more inline with the output 
that perf-script shows now.

David

Re: perf tip: fails to convert comm

[Frederic Weisbecker]

On Wed, Nov 13, 2013 at 11:06:11AM -0700, David Ahern wrote:
> On 11/13/13, 11:03 AM, Frederic Weisbecker wrote:
> >I see. I can reproduce, I'll check and see what happens. It would be nice if
> >we could have an option to dump internal perf events like comm events as well
> >in the perf script stream.
> 
> I've been thinking about moving the event dumping code from
> perf-script to perf-dump. In the process could add an argument to
> dump events -- similar to -D option for report/script, but more
> inline with the output that perf-script shows now.

Yeah indeed,sounds good!

Re: perf tip: fails to convert comm

[Arnaldo Carvalho de Melo]

Em Wed, Nov 13, 2013 at 07:03:47PM +0100, Frederic Weisbecker escreveu:
> On Tue, Nov 12, 2013 at 09:58:29PM -0700, David Ahern wrote:
> > Hi Namhyung and Frederic:
> > 
> > If you recall I mentioned noting a problem with the callchain series
> > showing comm's. Well, it fails on acme's perf/core. git bisect
> > points to:
> > 
> > $ git bisect bad
> > 4dfced359fbc719a35527416f1b4b3999647f68b is the first bad commit
> > commit 4dfced359fbc719a35527416f1b4b3999647f68b
> > Author: Namhyung Kim <namhyung.kim@lge.com>
> > Date:   Fri Sep 13 16:28:57 2013 +0900
> > 
> >     perf tools: Get current comm instead of last one
> > 
> >     At insert time, a hist entry should reference comm at the time
> > otherwise
> >     it'll get the last comm anyway.
> > 
> > 
> > How to re-create:
> > 
> > Start point is tools/perf directory for 3.12 (Linus tree):
> >   $ perf sched record -o /tmp/perf.data -g -- make -j 16
> >   $ perf script -i /tmp/perf.data > /tmp/1
> > 
> > cd to Arnaldo's tree, make perf and use it to create /tmp/2:
> >   $ perf script -i /tmp/perf.data > /tmp/1
> >   $ diff -U3 /tmp/1 /tmp/2 | less
> > 
> > You'll see a number of comm's showing as :<pid> instead of make, etc.
> 
> I see. I can reproduce, I'll check and see what happens. It would be nice if
> we could have an option to dump internal perf events like comm events as well
> in the perf script stream.

'perf record -D' not enough?

- Arnaldo

Re: perf tip: fails to convert comm

[Frederic Weisbecker]

On Wed, Nov 13, 2013 at 03:07:46PM -0300, Arnaldo Carvalho de Melo wrote:
> Em Wed, Nov 13, 2013 at 07:03:47PM +0100, Frederic Weisbecker escreveu:
> > On Tue, Nov 12, 2013 at 09:58:29PM -0700, David Ahern wrote:
> > > Hi Namhyung and Frederic:
> > > 
> > > If you recall I mentioned noting a problem with the callchain series
> > > showing comm's. Well, it fails on acme's perf/core. git bisect
> > > points to:
> > > 
> > > $ git bisect bad
> > > 4dfced359fbc719a35527416f1b4b3999647f68b is the first bad commit
> > > commit 4dfced359fbc719a35527416f1b4b3999647f68b
> > > Author: Namhyung Kim <namhyung.kim@lge.com>
> > > Date:   Fri Sep 13 16:28:57 2013 +0900
> > > 
> > >     perf tools: Get current comm instead of last one
> > > 
> > >     At insert time, a hist entry should reference comm at the time
> > > otherwise
> > >     it'll get the last comm anyway.
> > > 
> > > 
> > > How to re-create:
> > > 
> > > Start point is tools/perf directory for 3.12 (Linus tree):
> > >   $ perf sched record -o /tmp/perf.data -g -- make -j 16
> > >   $ perf script -i /tmp/perf.data > /tmp/1
> > > 
> > > cd to Arnaldo's tree, make perf and use it to create /tmp/2:
> > >   $ perf script -i /tmp/perf.data > /tmp/1
> > >   $ diff -U3 /tmp/1 /tmp/2 | less
> > > 
> > > You'll see a number of comm's showing as :<pid> instead of make, etc.
> > 
> > I see. I can reproduce, I'll check and see what happens. It would be nice if
> > we could have an option to dump internal perf events like comm events as well
> > in the perf script stream.
> 
> 'perf record -D' not enough?

No because it's not easy to correlate with perf script event output. Although it could
be if we simply dump the time the same way in both.

Re: perf tip: fails to convert comm

[David Ahern]

HI Frederic:

On 11/13/13, 11:03 AM, Frederic Weisbecker wrote:
>
> I see. I can reproduce, I'll check and see what happens. It would be nice if
> we could have an option to dump internal perf events like comm events as well
> in the perf script stream.

Any progress on a solution? This is a regression in 3.13.

David

Re: perf tip: fails to convert comm

[Frederic Weisbecker]

On Fri, Nov 15, 2013 at 09:29:51AM -0700, David Ahern wrote:
> HI Frederic:
> 
> On 11/13/13, 11:03 AM, Frederic Weisbecker wrote:
> >
> >I see. I can reproduce, I'll check and see what happens. It would be nice if
> >we could have an option to dump internal perf events like comm events as well
> >in the perf script stream.
> 
> Any progress on a solution? This is a regression in 3.13.

So the problem is that when a thread overrides its default ":%pid" comm, we forget
to tag the thread comm as overriden. Hence, this overriden comm is not inherited on
future forks.

So here is a fix. Tell me if you see more issue, I'll cook a proper changelog and
resend if everyting looks good.

Thanks.

diff --git a/tools/perf/util/thread.c b/tools/perf/util/thread.c
index cd8e2f5..49eaf1d 100644
--- a/tools/perf/util/thread.c
+++ b/tools/perf/util/thread.c
@@ -70,14 +70,13 @@ int thread__set_comm(struct thread *thread, const char *str, u64 timestamp)
 	/* Override latest entry if it had no specific time coverage */
 	if (!curr->start) {
 		comm__override(curr, str, timestamp);
-		return 0;
+	} else {
+		new = comm__new(str, timestamp);
+		if (!new)
+			return -ENOMEM;
+		list_add(&new->list, &thread->comm_list);
 	}
 
-	new = comm__new(str, timestamp);
-	if (!new)
-		return -ENOMEM;
-
-	list_add(&new->list, &thread->comm_list);
 	thread->comm_set = true;
 
 	return 0;

Re: perf tip: fails to convert comm

[Namhyung Kim]

Hi Frederic,

2013-11-16 (토), 02:02 +0100, Frederic Weisbecker:
> On Fri, Nov 15, 2013 at 09:29:51AM -0700, David Ahern wrote:
> > HI Frederic:
> > 
> > On 11/13/13, 11:03 AM, Frederic Weisbecker wrote:
> > >
> > >I see. I can reproduce, I'll check and see what happens. It would be nice if
> > >we could have an option to dump internal perf events like comm events as well
> > >in the perf script stream.
> > 
> > Any progress on a solution? This is a regression in 3.13.
> 
> So the problem is that when a thread overrides its default ":%pid" comm, we forget
> to tag the thread comm as overriden. Hence, this overriden comm is not inherited on
> future forks.
> 
> So here is a fix. Tell me if you see more issue, I'll cook a proper changelog and
> resend if everyting looks good.
> 
> Thanks.
> 
> diff --git a/tools/perf/util/thread.c b/tools/perf/util/thread.c
> index cd8e2f5..49eaf1d 100644
> --- a/tools/perf/util/thread.c
> +++ b/tools/perf/util/thread.c
> @@ -70,14 +70,13 @@ int thread__set_comm(struct thread *thread, const char *str, u64 timestamp)
>  	/* Override latest entry if it had no specific time coverage */
>  	if (!curr->start) {
>  		comm__override(curr, str, timestamp);
> -		return 0;
> +	} else {
> +		new = comm__new(str, timestamp);
> +		if (!new)
> +			return -ENOMEM;
> +		list_add(&new->list, &thread->comm_list);
>  	}
>  
> -	new = comm__new(str, timestamp);
> -	if (!new)
> -		return -ENOMEM;
> -
> -	list_add(&new->list, &thread->comm_list);
>  	thread->comm_set = true;
>  
>  	return 0;

Looks good to me.

Thanks for the fix.
Namhyung

Re: perf tip: fails to convert comm

[David Ahern]

On 11/15/13, 6:02 PM, Frederic Weisbecker wrote:
> On Fri, Nov 15, 2013 at 09:29:51AM -0700, David Ahern wrote:
>> HI Frederic:
>>
>> On 11/13/13, 11:03 AM, Frederic Weisbecker wrote:
>>>
>>> I see. I can reproduce, I'll check and see what happens. It would be nice if
>>> we could have an option to dump internal perf events like comm events as well
>>> in the perf script stream.
>>
>> Any progress on a solution? This is a regression in 3.13.
>
> So the problem is that when a thread overrides its default ":%pid" comm, we forget
> to tag the thread comm as overriden. Hence, this overriden comm is not inherited on
> future forks.
>
> So here is a fix. Tell me if you see more issue, I'll cook a proper changelog and
> resend if everyting looks good.

That works for me. Thank you.

Tested-by: David Ahern <dsahern@gmail.com>

[tip:perf/urgent] perf tools: Tag thread comm as overriden

[tip-bot for Frederic Weisbecker]

Commit-ID:  a5285ad9e30fd90b88a11adcab97bd4c3ffe44eb
Gitweb:     http://git.kernel.org/tip/a5285ad9e30fd90b88a11adcab97bd4c3ffe44eb
Author:     Frederic Weisbecker <fweisbec@gmail.com>
AuthorDate: Sat, 16 Nov 2013 02:02:09 +0100
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Tue, 19 Nov 2013 10:33:29 -0300

perf tools: Tag thread comm as overriden

The problem is that when a thread overrides its default ":%pid" comm, we
forget to tag the thread comm as overriden. Hence, this overriden comm
is not inherited on future forks. Fix it.

Signed-off-by: Frederic Weisbecker <fweisbec@gmail.com>
Tested-by: David Ahern <dsahern@gmail.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20131116010207.GA18855@localhost.localdomain
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/util/thread.c | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/tools/perf/util/thread.c b/tools/perf/util/thread.c
index cd8e2f5..49eaf1d 100644
--- a/tools/perf/util/thread.c
+++ b/tools/perf/util/thread.c
@@ -70,14 +70,13 @@ int thread__set_comm(struct thread *thread, const char *str, u64 timestamp)
 	/* Override latest entry if it had no specific time coverage */
 	if (!curr->start) {
 		comm__override(curr, str, timestamp);
-		return 0;
+	} else {
+		new = comm__new(str, timestamp);
+		if (!new)
+			return -ENOMEM;
+		list_add(&new->list, &thread->comm_list);
 	}
 
-	new = comm__new(str, timestamp);
-	if (!new)
-		return -ENOMEM;
-
-	list_add(&new->list, &thread->comm_list);
 	thread->comm_set = true;
 
 	return 0;