Fwd: filtering perf itself

Fwd: filtering perf itself

[Brendan Gregg]

G'Day perf users,

Is there a way to filter perf from tracing itself?

Here's an idle system:

# ./perf record -e syscalls:sys_enter_read -a sleep 5
[ perf record: Woken up 2 times to write data ]
[ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
# ./perf record -e syscalls:sys_enter_write -a sleep 5
[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples) ]

Note the disparity. perf is capturing its own writes, creating a feedback loop.

I haven't seen a way to filter this. Eg:

# ./perf record -q -e syscalls:sys_enter_write --filter 'comm != perf'
-a sleep 5
  Error: failed to set filter with 22 (Invalid argument)

# ./perf record -q -e syscalls:sys_enter_write --filter 'ppid != '$$ -a sleep 5
  Error: failed to set filter with 22 (Invalid argument)

# ./perf record -q -e raw_syscalls:sys_enter --filter 'comm != perf' -a sleep 5
  Error: failed to set filter with 22 (Invalid argument)

# ./perf record -q -e raw_syscalls:sys_enter --filter 'common_ppid !=
'$$ -a sleep 5
  Error: failed to set filter with 22 (Invalid argument)

This is because comm, ppid, common_ppid, etc, aren't available for
those tracepoints.

I thought there might be a simple way I'm missing. I'm on
linux-3.16-rc2. Thanks,

Brendan

-- 
http://www.brendangregg.com

Re: Fwd: filtering perf itself

[David Ahern]

On 7/7/14, 12:38 PM, Brendan Gregg wrote:
> G'Day perf users,
>
> Is there a way to filter perf from tracing itself?
>
> Here's an idle system:
>
> # ./perf record -e syscalls:sys_enter_read -a sleep 5
> [ perf record: Woken up 2 times to write data ]
> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
> # ./perf record -e syscalls:sys_enter_write -a sleep 5
> [ perf record: Woken up 0 times to write data ]
> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples) ]
>
> Note the disparity. perf is capturing its own writes, creating a feedback loop.

Not a filter, but works around the problem using mmap'ed output file:

https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3

David

Re: Fwd: filtering perf itself

[Brendan Gregg]

On Mon, Jul 7, 2014 at 11:44 AM, David Ahern <dsahern@gmail.com> wrote:
> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>>
>> G'Day perf users,
>>
>> Is there a way to filter perf from tracing itself?
>>
>> Here's an idle system:
>>
>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>> [ perf record: Woken up 2 times to write data ]
>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>> [ perf record: Woken up 0 times to write data ]
>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples)
>> ]
>>
>> Note the disparity. perf is capturing its own writes, creating a feedback
>> loop.
>
>
> Not a filter, but works around the problem using mmap'ed output file:
>
> https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3
>

Ah, thanks David, that should work! Looking forward to having this
patch included.

Brendan

-- 
http://www.brendangregg.com

Re: Fwd: filtering perf itself

[Brendan Gregg]

On Mon, Jul 7, 2014 at 12:00 PM, Brendan Gregg
<brendan.d.gregg@gmail.com> wrote:
> On Mon, Jul 7, 2014 at 11:44 AM, David Ahern <dsahern@gmail.com> wrote:
>> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>>>
>>> G'Day perf users,
>>>
>>> Is there a way to filter perf from tracing itself?
>>>
>>> Here's an idle system:
>>>
>>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>>> [ perf record: Woken up 2 times to write data ]
>>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>>> [ perf record: Woken up 0 times to write data ]
>>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples)
>>> ]
>>>
>>> Note the disparity. perf is capturing its own writes, creating a feedback
>>> loop.
>>
>>
>> Not a filter, but works around the problem using mmap'ed output file:
>>
>> https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3
>>
>
> Ah, thanks David, that should work! Looking forward to having this
> patch included.
>

While this should help a lot of cases, I realized I am using stdout
from time to time as well (similar to the "perf script" framework),
where I don't think mmap() is going to work. Eg:

# perf record -e raw_syscalls:sys_enter -a -o - sleep 5 | perf script
-i - | stuff...

Maybe perf should skip itself by-default, unless asked (eg, -I to
include perf's own events). Or some way to filter it would also work,
eg, common_ppid.

Brendan
-- 
http://www.brendangregg.com

Re: Fwd: filtering perf itself

[Brendan Gregg]

On Mon, Jul 7, 2014 at 12:16 PM, Brendan Gregg
<brendan.d.gregg@gmail.com> wrote:
> On Mon, Jul 7, 2014 at 12:00 PM, Brendan Gregg
> <brendan.d.gregg@gmail.com> wrote:
>> On Mon, Jul 7, 2014 at 11:44 AM, David Ahern <dsahern@gmail.com> wrote:
>>> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>>>>
>>>> G'Day perf users,
>>>>
>>>> Is there a way to filter perf from tracing itself?
>>>>
>>>> Here's an idle system:
>>>>
>>>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>>>> [ perf record: Woken up 2 times to write data ]
>>>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>>>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>>>> [ perf record: Woken up 0 times to write data ]
>>>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples)
>>>> ]
>>>>
>>>> Note the disparity. perf is capturing its own writes, creating a feedback
>>>> loop.
>>>
>>>
>>> Not a filter, but works around the problem using mmap'ed output file:
>>>
>>> https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3
>>>
>>
>> Ah, thanks David, that should work! Looking forward to having this
>> patch included.
>>
>
> While this should help a lot of cases, I realized I am using stdout
> from time to time as well (similar to the "perf script" framework),
> where I don't think mmap() is going to work. Eg:
>
> # perf record -e raw_syscalls:sys_enter -a -o - sleep 5 | perf script
> -i - | stuff...
>
> Maybe perf should skip itself by-default, unless asked (eg, -I to
> include perf's own events). Or some way to filter it would also work,
> eg, common_ppid.

I figured out one workaround...:

# sh -c 'exec ./perf record -e syscalls:sys_enter_write --filter
"common_pid != "$$ -a sleep 5'
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.161 MB perf.data (~7051 samples) ]

Brendan

-- 
http://www.brendangregg.com

Re: Fwd: filtering perf itself

[William Cohen]

On 07/07/2014 03:00 PM, Brendan Gregg wrote:
> On Mon, Jul 7, 2014 at 11:44 AM, David Ahern <dsahern@gmail.com> wrote:
>> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>>>
>>> G'Day perf users,
>>>
>>> Is there a way to filter perf from tracing itself?
>>>
>>> Here's an idle system:
>>>
>>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>>> [ perf record: Woken up 2 times to write data ]
>>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>>> [ perf record: Woken up 0 times to write data ]
>>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples)
>>> ]
>>>
>>> Note the disparity. perf is capturing its own writes, creating a feedback
>>> loop.
>>

What about probing using SystemTap and doing filtering in the probe handler to exclude the monitoring process?

-Will

>>
>> Not a filter, but works around the problem using mmap'ed output file:
>>
>> https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3
>>
> 
> Ah, thanks David, that should work! Looking forward to having this
> patch included.
> 
> Brendan
> 

Re: Fwd: filtering perf itself

[Andi Kleen]

David Ahern <dsahern@gmail.com> writes:

> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>> G'Day perf users,
>>
>> Is there a way to filter perf from tracing itself?
>>
>> Here's an idle system:
>>
>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>> [ perf record: Woken up 2 times to write data ]
>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>> [ perf record: Woken up 0 times to write data ]
>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples) ]
>>
>> Note the disparity. perf is capturing its own writes, creating a feedback loop.
>
> Not a filter, but works around the problem using mmap'ed output file:
>
> https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3

The problem is just getting the perf pid into the filter, right?

Something like this patch should work.

Actually it works most of the time, sometimes there are still EINVALs.

-Andi


commit 414db7523d44fe3afeaed3e2fc879a28263878ba
Author: Andi Kleen <ak@linux.intel.com>
Date:   Tue Jul 8 13:37:24 2014 -0700

    perf, tools: Add PERF_PID
    
    It's currently difficult to filter out perf itself using a filter.
    The best way is to use the pid. But it's difficult to get the pid
    of perf without using hacks.
    
    With this patch the following works
    
    % perf record -e syscalls:sys_enter_write -a --filter 'common_pid != PERF_PID' ...
    
    Signed-off-by: Andi Kleen <ak@linux.intel.com>

diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt
index d460049..b6c5e51 100644
--- a/tools/perf/Documentation/perf-record.txt
+++ b/tools/perf/Documentation/perf-record.txt
@@ -41,7 +41,7 @@ OPTIONS
           'mem:0x1000:rw'.
 
 --filter=<filter>::
-        Event filter.
+        Event filter. PERF_PID represents the perf pid.
 
 -a::
 --all-cpus::
diff --git a/tools/perf/util/parse-events.c b/tools/perf/util/parse-events.c
index 1e15df1..90ed63f 100644
--- a/tools/perf/util/parse-events.c
+++ b/tools/perf/util/parse-events.c
@@ -967,6 +967,7 @@ int parse_filter(const struct option *opt, const char *str,
 {
 	struct perf_evlist *evlist = *(struct perf_evlist **)opt->value;
 	struct perf_evsel *last = NULL;
+	char *pid;
 
 	if (evlist->nr_entries > 0)
 		last = perf_evlist__last(evlist);
@@ -983,6 +984,14 @@ int parse_filter(const struct option *opt, const char *str,
 		return -1;
 	}
 
+	/* Assume a pid has not more than 8 characters */
+	pid = strstr(last->filter, "PERF_PID");
+	if (pid) {
+		char buf[9];
+		snprintf(buf, 9, "%08d", getpid());
+		memcpy(pid, buf, 8);
+	}
+	fprintf(stderr, "filter |%s|\n", last->filter);
 	return 0;
 }
 



-- 
ak@linux.intel.com -- Speaking for myself only

Re: Fwd: filtering perf itself

[Brendan Gregg]

G'Day Will,

On Tue, Jul 8, 2014 at 12:10 PM, William Cohen <wcohen@redhat.com> wrote:
> On 07/07/2014 03:00 PM, Brendan Gregg wrote:
>> On Mon, Jul 7, 2014 at 11:44 AM, David Ahern <dsahern@gmail.com> wrote:
>>> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>>>>
>>>> G'Day perf users,
>>>>
>>>> Is there a way to filter perf from tracing itself?
>>>>
>>>> Here's an idle system:
>>>>
>>>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>>>> [ perf record: Woken up 2 times to write data ]
>>>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>>>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>>>> [ perf record: Woken up 0 times to write data ]
>>>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples)
>>>> ]
>>>>
>>>> Note the disparity. perf is capturing its own writes, creating a feedback
>>>> loop.
>>>
>
> What about probing using SystemTap and doing filtering in the probe handler to exclude the monitoring process?

Yes, that works, and in addition I can do custom in-kernel
aggregations with SystemTap, which reduces overheads much further. My
problem is finding the time to check that 2.6 is safe for production
use (I already know that perf_events is).

Brendan

-- 
http://www.brendangregg.com

Re: Fwd: filtering perf itself

[Brendan Gregg]

G'Day Andi,

On Tue, Jul 8, 2014 at 1:45 PM, Andi Kleen <andi@firstfloor.org> wrote:
> David Ahern <dsahern@gmail.com> writes:
>
>> On 7/7/14, 12:38 PM, Brendan Gregg wrote:
>>> G'Day perf users,
>>>
>>> Is there a way to filter perf from tracing itself?
>>>
>>> Here's an idle system:
>>>
>>> # ./perf record -e syscalls:sys_enter_read -a sleep 5
>>> [ perf record: Woken up 2 times to write data ]
>>> [ perf record: Captured and wrote 0.569 MB perf.data (~24864 samples) ]
>>> # ./perf record -e syscalls:sys_enter_write -a sleep 5
>>> [ perf record: Woken up 0 times to write data ]
>>> [ perf record: Captured and wrote 150.381 MB perf.data (~6570251 samples) ]
>>>
>>> Note the disparity. perf is capturing its own writes, creating a feedback loop.
>>
>> Not a filter, but works around the problem using mmap'ed output file:
>>
>> https://github.com/dsahern/linux/commit/ae2d7010256f5a5b247fb4df9f764a911a34a2f3
>
> The problem is just getting the perf pid into the filter, right?
>
> Something like this patch should work.
>
> Actually it works most of the time, sometimes there are still EINVALs.

Thanks; this is neat and simple. :) So this will solve many use cases,
where I'm dumping to a perf.data file and then processing later. T(he
mmap() patch is also desirable, to reduce the overheads of doing the
write.) But for when I'm piping perf record into perf script, I need a
way to filter both perf's.

If I'm desperate I can write a C program to perf_event_open() and
mmap() directly, and filter the pid in the same way (gitpid()). But I
think there can be some simple one liners where perf record | perf
script are sufficient, provided I'm not tracing perf.

Brendan
-- 
http://www.brendangregg.com