Re: Ftrace vs perf user page fault statistics differences

[Namhyung Kim]

Hello,

On Wed, Jun 14, 2017 at 5:04 AM, Steven Rostedt <rostedt@xxxxxxxxxxx> wrote:
> On Tue, 13 Jun 2017 14:02:08 -0400
> Will Hawkins <whh8b@xxxxxxxxxxxx> 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