linux-kernel - Re: Ftrace vs perf user page fault statistics differences

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <CAE+MWFt8csSJ9__FF27T+D8SOEGH41yL40z3SHmDeqM=G1DA4A@mail.gmail.com>
Date:   Wed, 14 Jun 2017 13:30:59 -0400
From:   Will Hawkins <whh8b@...ginia.edu>
To:     Namhyung Kim <namhyung@...il.com>
Cc:     Steven Rostedt <rostedt@...dmis.org>,
        LKML <linux-kernel@...r.kernel.org>
Subject: Re: Ftrace vs perf user page fault statistics differences

On Tue, Jun 13, 2017 at 11:04 PM, Namhyung Kim <namhyung@...il.com> wrote:
> Hello,
>
> On Wed, Jun 14, 2017 at 5:04 AM, Steven Rostedt <rostedt@...dmis.org> wrote:
>> On Tue, 13 Jun 2017 14:02:08 -0400
>> Will Hawkins <whh8b@...ginia.edu> wrote:
>>
>>> Thank you for pointing this out. I had been using -F for exactly the
>>> reason that you mentioned. I failed to include it in the command that
>>> I sent along. Very sorry for the confusion. Here is an updated version
>>> of the command that I issued:
>>>
>>>
>>> sudo ./trace-cmd record -e exceptions:page_fault_user -T --profile -l
>>> handle_mm_fault -F ../one_page_play/page
>>>
>>> and I generated output like
>>>
>>> ./trace-cmd report --profile
>>>
>>> and I see the following (among some other output):
>>>
>>>   Event: page_fault_user:0x7f094f7dd104 (1)
>>>   Event: page_fault_user:0x4000e0 (1)
>>>   Event: page_fault_user:0x7f094f7eae4a (1)
>>>   Event: page_fault_user:0x7f094f860d40 (1)
>>>   Event: page_fault_user:0x7f094f7db560 (1)
>>>   Event: page_fault_user:0x4040cb (1)
>>>   Event: page_fault_user:0x401825 (1)
>>>   Event: page_fault_user:0x401473 (1)
>>>   Event: page_fault_user:0x7f094f7e64c4 (1)
>>>   Event: page_fault_user:0x7f094f7f1212 (1)
>>>
>>> That output comes from under the task: page-<pid> heading, so it seems
>>> like those faults are being attributed to the page task.
>>>
>>> This command seems to show something interesting:
>>>
>>> sudo ./trace-cmd record -e exceptions:page_fault_user -p
>>> function_graph -g __do_fault -F ../one_page_play/page
>>>
>>> and the relevant output from
>>>
>>> ./trace-cmd report --profile
>>>
>>> is
>>>
>>> task: page-4032
>>>   Event: func: __do_fault() (4) Total: 6685 Avg: 1671 Max:
>>> 2398(ts:170150.060916) Min:855(ts:170150.054713)
>>>   Event: page_fault_user:0x7ffad3143d40 (1)
>>>   Event: page_fault_user:0x4000e0 (1)
>>>   Event: page_fault_user:0x401473 (1)
>>>   Event: page_fault_user:0x7ffad30c94c4 (1)
>>>
>>> This is closer to what I would expect. The first of the two 0x4...
>>> addresses is the entry point and the second is the target. Basically,
>>> that is exactly what I expect. The other two are the "suspicious"
>>> entries. Neither matches the copy_user_enhanced_fast_string symbol
>>> location and are not loaded in the binary (according to gdb).
>>
>> As you state below, there is faults recorded before the exec. Which is
>> true with trace-cmd (not sure about perf). As trace-cmd does do some
>> work after tracing is started and before the exec is called.
>
> When perf profiles a program started by the same command line, it
> disables the events by default and enables them during exec.  Please
> see linux/tools/perf/util/evsel.c:perf_evsel__config().
>
> Thanks,
> Namhyung

Namhyung,

I think that this answers a very important question! Thanks for chiming in!

Will