[2.6.39-rc2] perf top fails to mmap

[2.6.39-rc2] perf top fails to mmap

[Tim Blechmann]

hi all,

when trying to profile a process with `perf top -p $PID', perf exits with:
Failed to mmap with 22 (Invalid argument)

this happens when running perf as the same process as the process and when 
running perf as root.

tim

Re: [2.6.39-rc2] perf top fails to mmap

[David Ahern]

On 04/06/11 04:51, Tim Blechmann wrote:
> hi all,
> 
> when trying to profile a process with `perf top -p $PID', perf exits with:
> Failed to mmap with 22 (Invalid argument)

Works fine for me with latest kernel tree (this morning). Short lived
process?

David

> 
> this happens when running perf as the same process as the process and when 
> running perf as root.
> 
> tim
> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: [2.6.39-rc2] perf top fails to mmap

[Arnaldo Carvalho de Melo]

Em Wed, Apr 06, 2011 at 09:20:53AM -0600, David Ahern escreveu:
> 
> 
> On 04/06/11 04:51, Tim Blechmann wrote:
> > hi all,
> > 
> > when trying to profile a process with `perf top -p $PID', perf exits with:
> > Failed to mmap with 22 (Invalid argument)
> 
> Works fine for me with latest kernel tree (this morning). Short lived
> process?
> 
> David
> 
> > 
> > this happens when running perf as the same process as the process and when 
> > running perf as root.

yep, works for me as well:

[acme@emilia ~]$ cat vsyscall.c 
#include <time.h>

int main(void)
{
        struct timespec t;
        //int i;
        //for(i = 0; i < 10000000; i++)
        while (1) {
                clock_gettime(CLOCK_MONOTONIC, &t);
		usleep(10);
	}
        return 0;
}
[acme@emilia ~]$ cc -lrt vsyscall.c -o vsyscall
[acme@emilia ~]$ ./vsyscall &
[acme@emilia linux]$ perf top -p `pidof vsyscall` -F 10000
PerfTop:  230 irqs/sec  kernel:88.3%  exact:  0.0% [10000Hz cycles],  (target_pid: 2728)
----------------------------------------------------------------------------------------

             samples  pcnt function             DSO
             _______ _____ ____________________ ____________________

               21.00 44.7% __nanosleep_nocancel /lib64/libc-2.12.so 
               13.00 27.7% usleep               /lib64/libc-2.12.so 
                6.00 12.8% __GI_clock_gettime   /lib64/librt-2.12.so
                6.00 12.8% main                 /home/acme/vsyscall
^C
[acme@emilia linux]$ su -
Password: 
[root@emilia ~]# perf top -p `pidof vsyscall` -F 10000 --hide_kernel_symbols
PerfTop:     428 irqs/sec  kernel:90.2%  exact:  0.0% [10000Hz cycles],  (target_pid: 2728)
-------------------------------------------------------------------------------------------

             samples  pcnt function             DSO
             _______ _____ ____________________ ____________________

               15.00 29.4% __nanosleep_nocancel /lib64/libc-2.12.so 
               14.00 27.5% usleep               /lib64/libc-2.12.so 
                9.00 17.6% __GI_clock_gettime   /lib64/librt-2.12.so
                8.00 15.7% main                 /home/acme/vsyscall 
^C
[root@emilia ~]#

- Arnaldo

Re: [2.6.39-rc2] perf top fails to mmap

[Tim Blechmann]

[-- Attachment #1: Type: Text/Plain, Size: 475 bytes --]

> > David
> > 
> > > this happens when running perf as the same process as the process and
> > > when running perf as root.
> 
> yep, works for me as well:
> 
> [acme@emilia ~]$ cat vsyscall.c

after including unistd.h, this compiles and works fine. however i cannot profile 
any multithreaded program. does this work for you?

tim

-- 
tim@klingt.org
http://tim.klingt.org

The most wonderful opportunity which life offers is to be human.
  Henry Miller

[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 230 bytes --]

Re: [2.6.39-rc2] perf top fails to mmap

[David Ahern]

On 04/06/11 14:48, Tim Blechmann wrote:
>>> David
>>>
>>>> this happens when running perf as the same process as the process and
>>>> when running perf as root.
>>
>> yep, works for me as well:
>>
>> [acme@emilia ~]$ cat vsyscall.c
> 
> after including unistd.h, this compiles and works fine. however i cannot profile 
> any multithreaded program. does this work for you?
> 
> tim
> 

That does fail:
# ps -C rsyslogd -L
  PID   LWP TTY          TIME CMD
  795   795 ?        00:00:00 rsyslogd
  795   797 ?        00:00:00 rsyslogd
  795   798 ?        00:00:00 rsyslogd

# /tmp/build-perf/perf top -p 795
Failed to mmap with 22 (Invalid argument)

strace shows it failing at:
ioctl(4, PERF_EVENT_IOC_SET_OUTPUT, 0x3) = -1 EINVAL (Invalid argument)

Changing to use thread only works:
# /tmp/build-perf/perf top -t 795

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[David Ahern]

On 04/06/11 16:15, David Ahern wrote:
> 
> 
> On 04/06/11 14:48, Tim Blechmann wrote:
>>>> David
>>>>
>>>>> this happens when running perf as the same process as the process and
>>>>> when running perf as root.
>>>
>>> yep, works for me as well:
>>>
>>> [acme@emilia ~]$ cat vsyscall.c
>>
>> after including unistd.h, this compiles and works fine. however i cannot profile 
>> any multithreaded program. does this work for you?
>>
>> tim
>>
> 
> That does fail:
> # ps -C rsyslogd -L
>   PID   LWP TTY          TIME CMD
>   795   795 ?        00:00:00 rsyslogd
>   795   797 ?        00:00:00 rsyslogd
>   795   798 ?        00:00:00 rsyslogd
> 
> # /tmp/build-perf/perf top -p 795
> Failed to mmap with 22 (Invalid argument)
> 
> strace shows it failing at:
> ioctl(4, PERF_EVENT_IOC_SET_OUTPUT, 0x3) = -1 EINVAL (Invalid argument)
> 
> Changing to use thread only works:
> # /tmp/build-perf/perf top -t 795

git bisect points to:

70db7533caef02350ec8d6852e589491bca3a951 is the first bad commit
commit 70db7533caef02350ec8d6852e589491bca3a951
Author: Arnaldo Carvalho de Melo <acme@redhat.com>
Date:   Wed Jan 12 22:39:13 2011 -0200

perf evlist: Move the mmap array from perf_evsel

Adopting the new model used in 'perf record', where we don't have a map
per thread per cpu, instead we have an mmap per cpu, established on the
first fd for that cpu and ask the kernel using the
PERF_EVENT_IOC_SET_OUTPUT ioctl to send events for the other fds on that
cpu for the one with the mmap.

The methods moved from perf_evsel to perf_evlist, but for easing review
they were modified in place, in evsel.c, the next patch will move the
migrated methods to evlist.c.

With this 'perf top' now uses the same mmap model used by 'perf record'
and the next patches will make 'perf record' use these new routines,
establishing a common codebase for both tools.

----------

Coincidentally, perf-record is also broken. git bisect points to:

dd7927f4f8ee75b032ff15aeef4bda49719a443a is the first bad commit
commit dd7927f4f8ee75b032ff15aeef4bda49719a443a
Author: Arnaldo Carvalho de Melo <acme@redhat.com>
Date:   Wed Jan 12 14:28:51 2011 -0200

perf record: Use perf_evsel__open

Now its time to factor out the mmap handling bits into the perf_evsel
class.

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[Arnaldo Carvalho de Melo]

Em Wed, Apr 06, 2011 at 04:45:09PM -0600, David Ahern escreveu:
> On 04/06/11 16:15, David Ahern wrote:
> > On 04/06/11 14:48, Tim Blechmann wrote:
> >>>>> this happens when running perf as the same process as the process and
> >>>>> when running perf as root.
> >>>
> >>> yep, works for me as well:
> >>>
> >>> [acme@emilia ~]$ cat vsyscall.c
> >>
> >> after including unistd.h, this compiles and works fine. however i cannot profile 
> >> any multithreaded program. does this work for you?

> > That does fail:
> > # ps -C rsyslogd -L
> >   PID   LWP TTY          TIME CMD
> >   795   795 ?        00:00:00 rsyslogd
> >   795   797 ?        00:00:00 rsyslogd
> >   795   798 ?        00:00:00 rsyslogd

> > # /tmp/build-perf/perf top -p 795
> > Failed to mmap with 22 (Invalid argument)

> > strace shows it failing at:
> > ioctl(4, PERF_EVENT_IOC_SET_OUTPUT, 0x3) = -1 EINVAL (Invalid argument)

> > Changing to use thread only works:
> > # /tmp/build-perf/perf top -t 795
> 
> git bisect points to:
> 
> 70db7533caef02350ec8d6852e589491bca3a951 is the first bad commit
> commit 70db7533caef02350ec8d6852e589491bca3a951
> Author: Arnaldo Carvalho de Melo <acme@redhat.com>
> Date:   Wed Jan 12 22:39:13 2011 -0200
> 
> perf evlist: Move the mmap array from perf_evsel
> 
> Adopting the new model used in 'perf record', where we don't have a map
> per thread per cpu, instead we have an mmap per cpu, established on the
> first fd for that cpu and ask the kernel using the
> PERF_EVENT_IOC_SET_OUTPUT ioctl to send events for the other fds on that
> cpu for the one with the mmap.
> 
> The methods moved from perf_evsel to perf_evlist, but for easing review
> they were modified in place, in evsel.c, the next patch will move the
> migrated methods to evlist.c.
> 
> With this 'perf top' now uses the same mmap model used by 'perf record'
> and the next patches will make 'perf record' use these new routines,
> establishing a common codebase for both tools.
> 
> ----------
> 
> Coincidentally, perf-record is also broken. git bisect points to:
> 
> dd7927f4f8ee75b032ff15aeef4bda49719a443a is the first bad commit
> commit dd7927f4f8ee75b032ff15aeef4bda49719a443a
> Author: Arnaldo Carvalho de Melo <acme@redhat.com>
> Date:   Wed Jan 12 14:28:51 2011 -0200
> 
> perf record: Use perf_evsel__open
> 
> Now its time to factor out the mmap handling bits into the perf_evsel
> class.

I'll work on that tomorrow, if nobody fixes this till then :-)

- Arnaldo

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[David Ahern]

I know you've been busy with other stuff the past few weeks, but have
you had a chance to look into this? Basically, perf in 2.6.39 is broken
when trying to profile a process (-p argument to record or top).

David


> On 04/06/11 16:15, David Ahern wrote:
>>
>>
>> On 04/06/11 14:48, Tim Blechmann wrote:
>>>>> David
>>>>>
>>>>>> this happens when running perf as the same process as the process and
>>>>>> when running perf as root.
>>>>
>>>> yep, works for me as well:
>>>>
>>>> [acme@emilia ~]$ cat vsyscall.c
>>>
>>> after including unistd.h, this compiles and works fine. however i cannot profile 
>>> any multithreaded program. does this work for you?
>>>
>>> tim
>>>
>>
>> That does fail:
>> # ps -C rsyslogd -L
>>   PID   LWP TTY          TIME CMD
>>   795   795 ?        00:00:00 rsyslogd
>>   795   797 ?        00:00:00 rsyslogd
>>   795   798 ?        00:00:00 rsyslogd
>>
>> # /tmp/build-perf/perf top -p 795
>> Failed to mmap with 22 (Invalid argument)
>>
>> strace shows it failing at:
>> ioctl(4, PERF_EVENT_IOC_SET_OUTPUT, 0x3) = -1 EINVAL (Invalid argument)
>>
>> Changing to use thread only works:
>> # /tmp/build-perf/perf top -t 795
> 
> git bisect points to:
> 
> 70db7533caef02350ec8d6852e589491bca3a951 is the first bad commit
> commit 70db7533caef02350ec8d6852e589491bca3a951
> Author: Arnaldo Carvalho de Melo <acme@redhat.com>
> Date:   Wed Jan 12 22:39:13 2011 -0200
> 
> perf evlist: Move the mmap array from perf_evsel
> 
> Adopting the new model used in 'perf record', where we don't have a map
> per thread per cpu, instead we have an mmap per cpu, established on the
> first fd for that cpu and ask the kernel using the
> PERF_EVENT_IOC_SET_OUTPUT ioctl to send events for the other fds on that
> cpu for the one with the mmap.
> 
> The methods moved from perf_evsel to perf_evlist, but for easing review
> they were modified in place, in evsel.c, the next patch will move the
> migrated methods to evlist.c.
> 
> With this 'perf top' now uses the same mmap model used by 'perf record'
> and the next patches will make 'perf record' use these new routines,
> establishing a common codebase for both tools.
> 
> ----------
> 
> Coincidentally, perf-record is also broken. git bisect points to:
> 
> dd7927f4f8ee75b032ff15aeef4bda49719a443a is the first bad commit
> commit dd7927f4f8ee75b032ff15aeef4bda49719a443a
> Author: Arnaldo Carvalho de Melo <acme@redhat.com>
> Date:   Wed Jan 12 14:28:51 2011 -0200
> 
> perf record: Use perf_evsel__open
> 
> Now its time to factor out the mmap handling bits into the perf_evsel
> class.

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[Lin Ming]

On Sat, Apr 23, 2011 at 12:37 AM, David Ahern <dsahern@gmail.com> wrote:
> I know you've been busy with other stuff the past few weeks, but have
> you had a chance to look into this? Basically, perf in 2.6.39 is broken
> when trying to profile a process (-p argument to record or top).

Let me take a look at this.

Lin Ming

>
> David

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[Lin Ming]

On Sat, 2011-04-23 at 22:36 +0800, Lin Ming wrote:
> On Sat, Apr 23, 2011 at 12:37 AM, David Ahern <dsahern@gmail.com> wrote:
> > I know you've been busy with other stuff the past few weeks, but have
> > you had a chance to look into this? Basically, perf in 2.6.39 is broken
> > when trying to profile a process (-p argument to record or top).
> 
> Let me take a look at this.

Below patch fixes the same problem on my box.
Could you have a try it? 

>From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
From: Lin Ming <ming.m.lin@intel.com>
Date: Sat, 23 Apr 2011 14:54:33 +0000
Subject: [PATCH] perf: Allow set output event for task in the same thread group

Signed-off-by: Lin Ming <ming.m.lin@intel.com>
---
 kernel/perf_event.c |    5 +++--
 1 files changed, 3 insertions(+), 2 deletions(-)

diff --git a/kernel/perf_event.c b/kernel/perf_event.c
index 8e81a98..17dbc49 100644
--- a/kernel/perf_event.c
+++ b/kernel/perf_event.c
@@ -6379,9 +6379,10 @@ perf_event_set_output(struct perf_event *event, struct perf_event *output_event)
 		goto out;
 
 	/*
-	 * If its not a per-cpu buffer, it must be the same task.
+	 * If its not a per-cpu buffer, it must be the same task or in the same thread group.
 	 */
-	if (output_event->cpu == -1 && output_event->ctx != event->ctx)
+	if (output_event->cpu == -1 &&
+			!same_thread_group(output_event->ctx->task, event->ctx->task))
 		goto out;
 
 set:


> 
> Lin Ming
> 
> >
> > David

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[Tim Blechmann]

[-- Attachment #1: Type: Text/Plain, Size: 907 bytes --]

> > > I know you've been busy with other stuff the past few weeks, but have
> > > you had a chance to look into this? Basically, perf in 2.6.39 is broken
> > > when trying to profile a process (-p argument to record or top).
> > 
> > Let me take a look at this.
> 
> Below patch fixes the same problem on my box.
> Could you have a try it?

i have done some quick tests with this patch applied on linus/master ... works 
fine for me, thanks a lot!

> >From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
> 
> From: Lin Ming <ming.m.lin@intel.com>
> Date: Sat, 23 Apr 2011 14:54:33 +0000
> Subject: [PATCH] perf: Allow set output event for task in the same thread
> group
> 
> Signed-off-by: Lin Ming <ming.m.lin@intel.com>

Tested-by: Tim Blechmann <tim@klingt.org>

cheers, tim

-- 
tim@klingt.org
http://tim.klingt.org

When you open windows, bugs get in.

[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 230 bytes --]

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[David Ahern]

On 04/24/11 05:47, Tim Blechmann wrote:
>>>> I know you've been busy with other stuff the past few weeks, but have
>>>> you had a chance to look into this? Basically, perf in 2.6.39 is broken
>>>> when trying to profile a process (-p argument to record or top).
>>>
>>> Let me take a look at this.
>>
>> Below patch fixes the same problem on my box.
>> Could you have a try it?
> 
> i have done some quick tests with this patch applied on linus/master ... works 
> fine for me, thanks a lot!

Works for me as well.

> 
>> >From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
>>
>> From: Lin Ming <ming.m.lin@intel.com>
>> Date: Sat, 23 Apr 2011 14:54:33 +0000
>> Subject: [PATCH] perf: Allow set output event for task in the same thread
>> group
>>
>> Signed-off-by: Lin Ming <ming.m.lin@intel.com>
> 
> Tested-by: Tim Blechmann <tim@klingt.org>
> 
> cheers, tim
> 

Re: [2.6.39-rc2] perf top fails to mmap - bisected to 70db7533

[Lin Ming]

On Sun, 2011-04-24 at 21:45 +0800, David Ahern wrote:
> 
> On 04/24/11 05:47, Tim Blechmann wrote:
> >>>> I know you've been busy with other stuff the past few weeks, but have
> >>>> you had a chance to look into this? Basically, perf in 2.6.39 is broken
> >>>> when trying to profile a process (-p argument to record or top).
> >>>
> >>> Let me take a look at this.
> >>
> >> Below patch fixes the same problem on my box.
> >> Could you have a try it?
> > 
> > i have done some quick tests with this patch applied on linus/master ... works 
> > fine for me, thanks a lot!
> 
> Works for me as well.

Thanks for test.

I have send out the format patch.
http://marc.info/?l=linux-kernel&m=130365710014862&w=2

Lin Ming

> 
> > 
> >> >From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
> >>
> >> From: Lin Ming <ming.m.lin@intel.com>
> >> Date: Sat, 23 Apr 2011 14:54:33 +0000
> >> Subject: [PATCH] perf: Allow set output event for task in the same thread
> >> group
> >>
> >> Signed-off-by: Lin Ming <ming.m.lin@intel.com>
> > 
> > Tested-by: Tim Blechmann <tim@klingt.org>
> > 
> > cheers, tim
> >