[BUG] perf: cannot read counts in per-process mode in 3.17-rcX

[BUG] perf: cannot read counts in per-process mode in 3.17-rcX

[Stephane Eranian]

Hi,

It seems something is seriously broken with perf_events in
3.17-rcX. I have tried rc3, rc4. No way to get any counts
out using perf stat in per-process mode. I am trying on Intel
and the PMU is correctly detected:

$ perf stat -e cycles ls
      <not counted> cycles

It is not a permission problem. It is a read problem!
$ strace perf stat -e cycles ls

perf_event_open(0x27d7e20, 2261, -1, -1, 0x8 /* PERF_FLAG_??? */) = 3
write(6, "\0", 1)                       = 1
close(6)                                = 0
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 2261
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=2261,
si_status=0, si_utime=0, si_stime=0} ---
rt_sigreturn()                          = 2261
read(3, "", 24)                         = 0
 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Looks like read() on the perf returns 0 (nothing read!).

It seems to work fine in system-wide mode. So I bet  there were some
recent changes in the way the events are stored when the process
terminates.

I think the perf tool is not to blame here. I see the same problem with my
libpfm4 toy examples.

Can you reproduce the problem on your system?

Re: [BUG] perf: cannot read counts in per-process mode in 3.17-rcX

[Jiri Olsa]

On Mon, Sep 08, 2014 at 02:35:06PM +0200, Stephane Eranian wrote:
> Hi,
> 
> It seems something is seriously broken with perf_events in
> 3.17-rcX. I have tried rc3, rc4. No way to get any counts
> out using perf stat in per-process mode. I am trying on Intel
> and the PMU is correctly detected:
> 
> $ perf stat -e cycles ls
>       <not counted> cycles
> 
> It is not a permission problem. It is a read problem!
> $ strace perf stat -e cycles ls
> 
> perf_event_open(0x27d7e20, 2261, -1, -1, 0x8 /* PERF_FLAG_??? */) = 3
> write(6, "\0", 1)                       = 1
> close(6)                                = 0
> wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 2261
> --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=2261,
> si_status=0, si_utime=0, si_stime=0} ---
> rt_sigreturn()                          = 2261
> read(3, "", 24)                         = 0
>  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^

ouch thats me.. sry :-\

the PERF_EVENT_STATE_EXIT check should not go to the
read path.. could you please test attached patch?

jirka


---
diff --git a/kernel/events/core.c b/kernel/events/core.c
index d8cb4d2..6d1c9ce 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -3600,8 +3600,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
 	 * error state (i.e. because it was pinned but it couldn't be
 	 * scheduled on to the CPU at some point).
 	 */
-	if ((event->state == PERF_EVENT_STATE_ERROR) ||
-	    (event->state == PERF_EVENT_STATE_EXIT))
+	if (event->state == PERF_EVENT_STATE_ERROR)
 		return 0;
 
 	if (count < event->read_size)

Re: [BUG] perf: cannot read counts in per-process mode in 3.17-rcX

[Stephane Eranian]

On Mon, Sep 8, 2014 at 2:49 PM, Jiri Olsa <jolsa@redhat.com> wrote:
>
> On Mon, Sep 08, 2014 at 02:35:06PM +0200, Stephane Eranian wrote:
> > Hi,
> >
> > It seems something is seriously broken with perf_events in
> > 3.17-rcX. I have tried rc3, rc4. No way to get any counts
> > out using perf stat in per-process mode. I am trying on Intel
> > and the PMU is correctly detected:
> >
> > $ perf stat -e cycles ls
> >       <not counted> cycles
> >
> > It is not a permission problem. It is a read problem!
> > $ strace perf stat -e cycles ls
> >
> > perf_event_open(0x27d7e20, 2261, -1, -1, 0x8 /* PERF_FLAG_??? */) = 3
> > write(6, "\0", 1)                       = 1
> > close(6)                                = 0
> > wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 2261
> > --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=2261,
> > si_status=0, si_utime=0, si_stime=0} ---
> > rt_sigreturn()                          = 2261
> > read(3, "", 24)                         = 0
> >  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
>
> ouch thats me.. sry :-\
>
> the PERF_EVENT_STATE_EXIT check should not go to the
> read path.. could you please test attached patch?
>
> jirka
>
Works for me again now. Thanks for the quick fix. Please push it upstream.

Acked-by: Stephane Eranian <eranian@google.com>
>
>
> ---
> diff --git a/kernel/events/core.c b/kernel/events/core.c
> index d8cb4d2..6d1c9ce 100644
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -3600,8 +3600,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
>          * error state (i.e. because it was pinned but it couldn't be
>          * scheduled on to the CPU at some point).
>          */
> -       if ((event->state == PERF_EVENT_STATE_ERROR) ||
> -           (event->state == PERF_EVENT_STATE_EXIT))
> +       if (event->state == PERF_EVENT_STATE_ERROR)
>                 return 0;
>
>         if (count < event->read_size)

[PATCH] perf: Do not check PERF_EVENT_STATE_EXIT on syscall read path

[Jiri Olsa]

On Mon, Sep 08, 2014 at 03:21:12PM +0200, Stephane Eranian wrote:
> On Mon, Sep 8, 2014 at 2:49 PM, Jiri Olsa <jolsa@redhat.com> wrote:
> >
> > On Mon, Sep 08, 2014 at 02:35:06PM +0200, Stephane Eranian wrote:
> > > Hi,
> > >
> > > It seems something is seriously broken with perf_events in
> > > 3.17-rcX. I have tried rc3, rc4. No way to get any counts
> > > out using perf stat in per-process mode. I am trying on Intel
> > > and the PMU is correctly detected:
> > >
> > > $ perf stat -e cycles ls
> > >       <not counted> cycles
> > >
> > > It is not a permission problem. It is a read problem!
> > > $ strace perf stat -e cycles ls
> > >
> > > perf_event_open(0x27d7e20, 2261, -1, -1, 0x8 /* PERF_FLAG_??? */) = 3
> > > write(6, "\0", 1)                       = 1
> > > close(6)                                = 0
> > > wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 2261
> > > --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=2261,
> > > si_status=0, si_utime=0, si_stime=0} ---
> > > rt_sigreturn()                          = 2261
> > > read(3, "", 24)                         = 0
> > >  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
> >
> > ouch thats me.. sry :-\
> >
> > the PERF_EVENT_STATE_EXIT check should not go to the
> > read path.. could you please test attached patch?
> >
> > jirka
> >
> Works for me again now. Thanks for the quick fix. Please push it upstream.
> 
> Acked-by: Stephane Eranian <eranian@google.com>

attached, thanks
jirka


---
Revert PERF_EVENT_STATE_EXIT check on read syscall path.
It breaks standard way to read counter, which is to open
the counter, wait for the monitored process to die and
read the counter.

Reported-by: Stephane Eranian <eranian@google.com>
Acked-by: Stephane Eranian <eranian@google.com>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Stephane Eranian <eranian@google.com>
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
---
 kernel/events/core.c | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index d8cb4d21a346..6d1c9ce1643e 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -3600,8 +3600,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
 	 * error state (i.e. because it was pinned but it couldn't be
 	 * scheduled on to the CPU at some point).
 	 */
-	if ((event->state == PERF_EVENT_STATE_ERROR) ||
-	    (event->state == PERF_EVENT_STATE_EXIT))
+	if (event->state == PERF_EVENT_STATE_ERROR)
 		return 0;
 
 	if (count < event->read_size)
-- 
1.8.3.1

Re: [PATCH] perf: Do not check PERF_EVENT_STATE_EXIT on syscall read path

[Peter Zijlstra]

[-- Attachment #1: Type: text/plain, Size: 1406 bytes --]

On Mon, Sep 08, 2014 at 04:31:07PM +0200, Jiri Olsa wrote:
> Revert PERF_EVENT_STATE_EXIT check on read syscall path.
> It breaks standard way to read counter, which is to open
> the counter, wait for the monitored process to die and
> read the counter.
> 
> Reported-by: Stephane Eranian <eranian@google.com>
> Acked-by: Stephane Eranian <eranian@google.com>
> Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
> Cc: Frederic Weisbecker <fweisbec@gmail.com>
> Cc: Ingo Molnar <mingo@kernel.org>
> Cc: Paul Mackerras <paulus@samba.org>
> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
> Cc: Stephane Eranian <eranian@google.com>
> Signed-off-by: Jiri Olsa <jolsa@kernel.org>

Thanks! 

> ---
>  kernel/events/core.c | 3 +--
>  1 file changed, 1 insertion(+), 2 deletions(-)
> 
> diff --git a/kernel/events/core.c b/kernel/events/core.c
> index d8cb4d21a346..6d1c9ce1643e 100644
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -3600,8 +3600,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
>  	 * error state (i.e. because it was pinned but it couldn't be
>  	 * scheduled on to the CPU at some point).
>  	 */
> -	if ((event->state == PERF_EVENT_STATE_ERROR) ||
> -	    (event->state == PERF_EVENT_STATE_EXIT))
> +	if (event->state == PERF_EVENT_STATE_ERROR)
>  		return 0;
>  
>  	if (count < event->read_size)
> -- 
> 1.8.3.1
> 

[-- Attachment #2: Type: application/pgp-signature, Size: 836 bytes --]

Re: [PATCH] perf: Do not check PERF_EVENT_STATE_EXIT on syscall read path

[Stephane Eranian]

Peter,



On Mon, Sep 8, 2014 at 5:22 PM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Mon, Sep 08, 2014 at 04:31:07PM +0200, Jiri Olsa wrote:
>> Revert PERF_EVENT_STATE_EXIT check on read syscall path.
>> It breaks standard way to read counter, which is to open
>> the counter, wait for the monitored process to die and
>> read the counter.
>>
>> Reported-by: Stephane Eranian <eranian@google.com>
>> Acked-by: Stephane Eranian <eranian@google.com>
>> Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
>> Cc: Frederic Weisbecker <fweisbec@gmail.com>
>> Cc: Ingo Molnar <mingo@kernel.org>
>> Cc: Paul Mackerras <paulus@samba.org>
>> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
>> Cc: Stephane Eranian <eranian@google.com>
>> Signed-off-by: Jiri Olsa <jolsa@kernel.org>
>
> Thanks!
Still don't see this fix in tip.git.

>> ---
>>  kernel/events/core.c | 3 +--
>>  1 file changed, 1 insertion(+), 2 deletions(-)
>>
>> diff --git a/kernel/events/core.c b/kernel/events/core.c
>> index d8cb4d21a346..6d1c9ce1643e 100644
>> --- a/kernel/events/core.c
>> +++ b/kernel/events/core.c
>> @@ -3600,8 +3600,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
>>        * error state (i.e. because it was pinned but it couldn't be
>>        * scheduled on to the CPU at some point).
>>        */
>> -     if ((event->state == PERF_EVENT_STATE_ERROR) ||
>> -         (event->state == PERF_EVENT_STATE_EXIT))
>> +     if (event->state == PERF_EVENT_STATE_ERROR)
>>               return 0;
>>
>>       if (count < event->read_size)
>> --
>> 1.8.3.1
>>

Re: [PATCH] perf: Do not check PERF_EVENT_STATE_EXIT on syscall read path

[Stephane Eranian]

On Wed, Sep 10, 2014 at 3:49 PM, Stephane Eranian <eranian@google.com> wrote:
>
> Peter,
>
>
>
> On Mon, Sep 8, 2014 at 5:22 PM, Peter Zijlstra <peterz@infradead.org> wrote:
> > On Mon, Sep 08, 2014 at 04:31:07PM +0200, Jiri Olsa wrote:
> >> Revert PERF_EVENT_STATE_EXIT check on read syscall path.
> >> It breaks standard way to read counter, which is to open
> >> the counter, wait for the monitored process to die and
> >> read the counter.
> >>
> >> Reported-by: Stephane Eranian <eranian@google.com>
> >> Acked-by: Stephane Eranian <eranian@google.com>
> >> Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
> >> Cc: Frederic Weisbecker <fweisbec@gmail.com>
> >> Cc: Ingo Molnar <mingo@kernel.org>
> >> Cc: Paul Mackerras <paulus@samba.org>
> >> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
> >> Cc: Stephane Eranian <eranian@google.com>
> >> Signed-off-by: Jiri Olsa <jolsa@kernel.org>
> >
> > Thanks!
> Still don't see this fix in tip.git.
>
Still not there. This is a problem.

>
> >> ---
> >>  kernel/events/core.c | 3 +--
> >>  1 file changed, 1 insertion(+), 2 deletions(-)
> >>
> >> diff --git a/kernel/events/core.c b/kernel/events/core.c
> >> index d8cb4d21a346..6d1c9ce1643e 100644
> >> --- a/kernel/events/core.c
> >> +++ b/kernel/events/core.c
> >> @@ -3600,8 +3600,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
> >>        * error state (i.e. because it was pinned but it couldn't be
> >>        * scheduled on to the CPU at some point).
> >>        */
> >> -     if ((event->state == PERF_EVENT_STATE_ERROR) ||
> >> -         (event->state == PERF_EVENT_STATE_EXIT))
> >> +     if (event->state == PERF_EVENT_STATE_ERROR)
> >>               return 0;
> >>
> >>       if (count < event->read_size)
> >> --
> >> 1.8.3.1
> >>

[tip:perf/core] perf: Do not check PERF_EVENT_STATE_EXIT on syscall read path

[tip-bot for Jiri Olsa]

Commit-ID:  c88f2096136416b261bd3647cc260935f6e95805
Gitweb:     http://git.kernel.org/tip/c88f2096136416b261bd3647cc260935f6e95805
Author:     Jiri Olsa <jolsa@redhat.com>
AuthorDate: Mon, 8 Sep 2014 16:31:07 +0200
Committer:  Ingo Molnar <mingo@kernel.org>
CommitDate: Tue, 16 Sep 2014 10:30:36 +0200

perf: Do not check PERF_EVENT_STATE_EXIT on syscall read path

Revert PERF_EVENT_STATE_EXIT check on read syscall path.
It breaks standard way to read counter, which is to open
the counter, wait for the monitored process to die and
read the counter.

Reported-by: Stephane Eranian <eranian@google.com>
Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Acked-by: Stephane Eranian <eranian@google.com>
Acked-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: David Ahern <dsahern@gmail.com>
Link: http://lkml.kernel.org/r/20140908143107.GG17728@krava.brq.redhat.com
Signed-off-by: Ingo Molnar <mingo@kernel.org>
---
 kernel/events/core.c | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index f917dec..733c616 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -3601,8 +3601,7 @@ perf_read_hw(struct perf_event *event, char __user *buf, size_t count)
 	 * error state (i.e. because it was pinned but it couldn't be
 	 * scheduled on to the CPU at some point).
 	 */
-	if ((event->state == PERF_EVENT_STATE_ERROR) ||
-	    (event->state == PERF_EVENT_STATE_EXIT))
+	if (event->state == PERF_EVENT_STATE_ERROR)
 		return 0;
 
 	if (count < event->read_size)