2011-04-06 10:51:57

by Tim Blechmann

[permalink] [raw]
Subject: [2.6.39-rc2] perf top fails to mmap

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


2011-04-06 15:20:58

by David Ahern

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



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 [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2011-04-06 17:52:27

by Arnaldo Carvalho de Melo

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

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

2011-04-06 20:57:09

by Tim Blechmann

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

> > 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

--
[email protected]
http://tim.klingt.org

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


Attachments:
signature.asc (230.00 B)
This is a digitally signed message part.

2011-04-06 22:15:49

by David Ahern

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



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

2011-04-06 22:45:14

by David Ahern

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



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 <[email protected]>
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 <[email protected]>
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.

2011-04-07 00:13:20

by Arnaldo Carvalho de Melo

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

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 <[email protected]>
> 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 <[email protected]>
> 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

2011-04-22 16:37:46

by David Ahern

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

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 <[email protected]>
> 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 <[email protected]>
> 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.

2011-04-23 13:45:17

by Ming Lin

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

On Sat, Apr 23, 2011 at 12:37 AM, David Ahern <[email protected]> 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