perf top fails to mmap

2.6.39-rc2 Tim Blechmann 5 participants 13 messages Apr 6, 2011 – Apr 24, 2011 1 message not in the archive

lore

Share & tools

lore

Tim Blechmann

author

2011-04-06 10:51 UTC #0 lore raw

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

David Ahern

2011-04-06 15:20 UTC #1 lore raw

Quoted 4 lines · 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)

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

David

Quoted 12 lines

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/

Arnaldo Carvalho de Melo

2011-04-06 17:52 UTC #2 lore raw

Em Wed, Apr 06, 2011 at 09:20:53AM -0600, David Ahern escreveu:

Quoted 16 lines · Tim Blechmann

Quoted 4 lines
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
Quoted 3 lines
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

Tim Blechmann

author

2011-04-06 20:57 UTC #3 lore raw

Quoted 8 lines

Quoted 4 lines
David
Quoted 2 lines
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

Signature · 5 lines

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

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

David Ahern

2011-04-06 22:15 UTC #4 lore raw

Quoted 5 lines · Tim Blechmann

Quoted 5 lines
Quoted 4 lines
David
Quoted 2 lines
this happens when running perf as the same process as the process and when running perf as root.

Quoted 9 lines

Quoted 3 lines
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

David Ahern

2011-04-06 22:45 UTC #5 lore raw

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

Quoted 25 lines · David Ahern

Quoted 5 lines · Tim Blechmann
Quoted 5 lines
Quoted 4 lines
David
Quoted 2 lines
this happens when running perf as the same process as the process and when running perf as root.
Quoted 9 lines
Quoted 3 lines
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

Quoted 8 lines

# /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.

Arnaldo Carvalho de Melo

2011-04-07 00:13 UTC #6 lore raw

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:

Quoted 57 lines · David Ahern

Quoted 18 lines · Tim Blechmann
Quoted 9 lines
Quoted 6 lines
Quoted 2 lines
Quoted 2 lines
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
Quoted 8 lines
# /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

Quoted 7 lines

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

David Ahern

2011-04-22 16:37 UTC #7 lore raw

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

In reply to 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

Quoted 71 lines · David Ahern

Quoted 25 lines · Tim Blechmann
Quoted 5 lines
Quoted 5 lines
Quoted 4 lines
David
Quoted 2 lines
this happens when running perf as the same process as the process and when running perf as root.
Quoted 9 lines
Quoted 3 lines
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
Quoted 8 lines
# /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.

Lin Ming

2011-04-23 13:45 UTC #8 lore raw

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

Quoted 3 lines · 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).

Let me take a look at this.

Lin Ming

Quoted 2 lines

David

A message that is not in the archive (sent off-list or not yet received): [email protected]

Lin Ming

2011-04-23 14:51 UTC #10 lore raw

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

Quoted 6 lines · Lin Ming

Quoted 3 lines · 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).
Let me take a look at this.

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

Quoted 1 line

From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001

From: Lin Ming <[email protected]>
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 <[email protected]>

---
 kernel/perf_event.c |    5 +++--
 1 files changed, 3 insertions(+), 2 deletions(-)

kernel/perf_event.c +3 -2

index 8e81a98..17dbc49 100644
@@ -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:

Quoted 5 lines

Lin Ming
Quoted 2 lines
David

Tim Blechmann

author Tested-by

2011-04-24 11:48 UTC #11 lore raw

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

Quoted 8 lines

Quoted 5 lines
Quoted 3 lines
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!

Quoted 8 lines

Quoted 1 line
From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
From: Lin Ming <[email protected]>
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 <[email protected]>

Tested-by Tim Blechmann <[email protected]>

cheers, tim

Signature · 4 lines

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

When you open windows, bugs get in.

David Ahern

2011-04-24 13:46 UTC #12 lore raw

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

Quoted 11 lines · Tim Blechmann

Quoted 8 lines
Quoted 5 lines
Quoted 3 lines
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.

Quoted 14 lines

Quoted 9 lines
Quoted 2 lines
From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
From: Lin Ming <[email protected]>
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 <[email protected]>
Tested-by Tim Blechmann <[email protected]>
cheers, tim

Lin Ming

2011-04-24 15:02 UTC #13 lore raw

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

Quoted 8 lines · David Ahern

Quoted 6 lines · Tim Blechmann
Quoted 6 lines
Quoted 5 lines
Quoted 3 lines
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.

Quoted 7 lines

Quoted 5 lines
Quoted 2 lines
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

Quoted 15 lines

Quoted 15 lines
Quoted 10 lines
Quoted 3 lines
From 89f1ab02cd8da55f8829b2f2d7e700fdae77b3af Mon Sep 17 00:00:00 2001
From: Lin Ming <[email protected]>
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 <[email protected]>
Tested-by Tim Blechmann <[email protected]>
cheers, tim