Perf record premature termination

Perf record premature termination

[Tim Chen]

David,

When I am doing a profiling of kernel compile with 32 threads on a 4
socket westmere machine, I found that perf record terminated right away
for the version of perf in 3.7 kernel source tree.
There's no profile data recroded and the compile is running in
background.

$ make -j32 &
then
$ sudo /test/perf record -a -g -f sleep 5
sleep: Terminated

I've bisected the patch responsible to the following patch.

Tim


8d3eca20b9f31cf10088e283d704f6a71b9a4ee2 is the first bad commit
commit 8d3eca20b9f31cf10088e283d704f6a71b9a4ee2
Author: David Ahern <dsahern@gmail.com>
Date:   Sun Aug 26 12:24:47 2012 -0600

    perf record: Remove use of die/exit
    
    Allows perf to clean up properly on exit. If perf-record is exiting
due
    to failure, the on_exit should not run as the session has been
deleted.
    
    Signed-off-by: David Ahern <dsahern@gmail.com>
    Cc: Frederic Weisbecker <fweisbec@gmail.com>
    Cc: Ingo Molnar <mingo@kernel.org>
    Cc: Peter Zijlstra <peterz@infradead.org>
    Link:
http://lkml.kernel.org/r/1346005487-62961-8-git-send-email-dsahern@gmail.com
    Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

Re: Perf record premature termination

[David Ahern]

On 2/11/13 11:50 AM, Tim Chen wrote:
> David,
>
> When I am doing a profiling of kernel compile with 32 threads on a 4
> socket westmere machine, I found that perf record terminated right away
> for the version of perf in 3.7 kernel source tree.
> There's no profile data recroded and the compile is running in
> background.
>
> $ make -j32 &
> then
> $ sudo /test/perf record -a -g -f sleep 5
> sleep: Terminated
>

Race condition collecting the initial thread data:
$ su -c '/tmp/perf-3.7/perf record -a -g -f -o /tmp/perf.data -v sleep 5'
Password:
couldn't open /proc/22518/status
couldn't open /proc/22518/task
couldn't open /proc/22518/maps
sleep: Terminated

David

Re: Perf record premature termination

[David Ahern]

On 2/11/13 11:50 AM, Tim Chen wrote:
> David,
>
> When I am doing a profiling of kernel compile with 32 threads on a 4
> socket westmere machine, I found that perf record terminated right away
> for the version of perf in 3.7 kernel source tree.
> There's no profile data recroded and the compile is running in
> background.
>
> $ make -j32 &
> then
> $ sudo /test/perf record -a -g -f sleep 5
> sleep: Terminated
>

This should fix it. I guess not all return codes were meant to be checked.


diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index e9231659..7733051 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -645,9 +645,6 @@ static int __cmd_record(struct perf_record *rec, int 
argc, const char **argv)
         err = perf_event__synthesize_threads(tool, 
process_synthesized_event,
                            machine);

-   if (err != 0)
-       goto out_delete_session;
-
     if (rec->realtime_prio) {
         struct sched_param param;

Re: Perf record premature termination

[Tim Chen]

On Mon, 2013-02-11 at 12:34 -0700, David Ahern wrote:
> On 2/11/13 11:50 AM, Tim Chen wrote:
> > David,
> >
> > When I am doing a profiling of kernel compile with 32 threads on a 4
> > socket westmere machine, I found that perf record terminated right away
> > for the version of perf in 3.7 kernel source tree.
> > There's no profile data recroded and the compile is running in
> > background.
> >
> > $ make -j32 &
> > then
> > $ sudo /test/perf record -a -g -f sleep 5
> > sleep: Terminated
> >
> 
> This should fix it. I guess not all return codes were meant to be checked.
> 
> 

Thanks.  This fix works for me.

Tim

Re: Perf record premature termination

[David Ahern]

On 2/11/13 3:15 PM, Tim Chen wrote:
> On Mon, 2013-02-11 at 12:34 -0700, David Ahern wrote:
>> On 2/11/13 11:50 AM, Tim Chen wrote:
>>> David,
>>>
>>> When I am doing a profiling of kernel compile with 32 threads on a 4
>>> socket westmere machine, I found that perf record terminated right away
>>> for the version of perf in 3.7 kernel source tree.
>>> There's no profile data recroded and the compile is running in
>>> background.
>>>
>>> $ make -j32 &
>>> then
>>> $ sudo /test/perf record -a -g -f sleep 5
>>> sleep: Terminated

This is the more appropriate fix. Make mmap consistent with comm. Revert 
the other one.

diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index 3cf2c3e..ba74a81 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -183,7 +183,7 @@ static int perf_event__synthesize_mmap_events(struct 
perf_tool *tool,
          * We raced with a task exiting - just return:
          */
         pr_debug("couldn't open %s\n", filename);
-       return -1;
+       return 0;
     }

     event->header.type = PERF_RECORD_MMAP;

Re: Perf record premature termination

[Tim Chen]

On Mon, 2013-02-11 at 15:30 -0700, David Ahern wrote:
> On 2/11/13 3:15 PM, Tim Chen wrote:
> > On Mon, 2013-02-11 at 12:34 -0700, David Ahern wrote:
> >> On 2/11/13 11:50 AM, Tim Chen wrote:
> >>> David,
> >>>
> >>> When I am doing a profiling of kernel compile with 32 threads on a 4
> >>> socket westmere machine, I found that perf record terminated right away
> >>> for the version of perf in 3.7 kernel source tree.
> >>> There's no profile data recroded and the compile is running in
> >>> background.
> >>>
> >>> $ make -j32 &
> >>> then
> >>> $ sudo /test/perf record -a -g -f sleep 5
> >>> sleep: Terminated
> 
> This is the more appropriate fix. Make mmap consistent with comm. Revert 
> the other one.

Thanks.  Works for me.

Tim

Re: Perf record premature termination

[David Ahern]

On 2/12/13 10:07 AM, Tim Chen wrote:
> On Mon, 2013-02-11 at 15:30 -0700, David Ahern wrote:
>> On 2/11/13 3:15 PM, Tim Chen wrote:
>>> On Mon, 2013-02-11 at 12:34 -0700, David Ahern wrote:
>>>> On 2/11/13 11:50 AM, Tim Chen wrote:
>>>>> David,
>>>>>
>>>>> When I am doing a profiling of kernel compile with 32 threads on a 4
>>>>> socket westmere machine, I found that perf record terminated right away
>>>>> for the version of perf in 3.7 kernel source tree.
>>>>> There's no profile data recroded and the compile is running in
>>>>> background.
>>>>>
>>>>> $ make -j32 &
>>>>> then
>>>>> $ sudo /test/perf record -a -g -f sleep 5
>>>>> sleep: Terminated
>>
>> This is the more appropriate fix. Make mmap consistent with comm. Revert
>> the other one.
>
> Thanks.  Works for me.
>
> Tim
>

BTW, this does not seem to be a problem with 3.8 - at least I could not 
reproduce it. So it seems limited to 3.7 kernels only.

David