lkml.org 
[lkml]   [2010]   [Nov]   [30]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH 2/2] perf tools: Add option to show time history of event samples


On 11/30/10 12:19, Arnaldo Carvalho de Melo wrote:
>
> Suggestion: Please put some example output on the commit log message,
> that way reviewers can have a glimpse of how it looks like.
>

Will do. I actually had a comparison between today's 'report -D' and
'report --timehist'; I forgot to add it to the commit message.

The line lengths will be a bit ugly in an email. In practice, the
timehist is primarily a means of converting event data to sensible text
for 1. processing by scripts and gnuplot, and 2. correlating with log
entries from individual processes.

In case folks are interested now before generating another patch set:

./perf record --timehist -e cs -c 1 -p 983 -g

./perf report -D

0x1200 [0x88]: PERF_RECORD_SAMPLE(IP, 1): 983/983: 0xffffffff813e974f
period: 1 cpu:1
... chain: nr:11
..... 0: ffffffffffffff80
..... 1: ffffffff813e974f
..... 2: ffffffff813ea46d
..... 3: ffffffff813ea549
..... 4: ffffffff8111cf61
..... 5: ffffffff8111d7eb
..... 6: ffffffff8111d9a3
..... 7: ffffffff8111dad8
..... 8: ffffffff81002cf2
..... 9: fffffffffffffe00
..... 10: 00007f2e0d15dec3
... thread: sshd:983
...... dso: /lib/modules/2.6.37-rc2/build/vmlinux


./perf report --timehist -U

12:26:41.890762 105188460714 1 sshd 983 ffffffff813e974f schedule
([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff813ea46d
schedule_hrtimeout_range_clock ([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff813ea549
schedule_hrtimeout_range ([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff8111cf61
poll_schedule_timeout ([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff8111d7eb do_select
([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff8111d9a3
core_sys_select ([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff8111dad8 sys_select
([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 ffffffff81002cf2
system_call ([kernel.kallsyms])
12:26:41.890762 105188460714 1 sshd 983 7f2e0d15dec3
__GI_select (/lib64/libc-2.12.90.so)



>> +static int perf_session__print_sample(struct perf_session *self,
>
> Please replace self with 'session', Thomas suggested that and I agreed
> that its better. We'll slowly rename all those self variables.

Ok. I noted the mix and wasn't sure which name to use.

>
>> + struct addr_location *al,
>> + struct sample_data *data)
>> +{
>> + static int show_timehist_error = 1;
>> + u64 timestamp = 0;
>> + struct map_symbol *syms = NULL;
>> + struct symbol *parent = NULL;
>> + const char *tstr;
>> +
>> + if (show_timehist_error &&
>> + ((data->cpu == (u32) -1) || !(self->sample_type & PERF_SAMPLE_TIME))) {
>> + pr_err("Data for time history missing in perf event samples.\n"
>> + "Did you record with -T option?\n");
>
> --timehist
>
> As you used:
>
> + OPT_BOOLEAN(0, "timehist", &time_history,
> + "Dump time history of event samples"),
>
> In a branch I'm working on I'm using 'T' to mean "--sample_time", i.e.
> to ask for just PERF_SAMPLE_TIME

Ok. I wanted consistency between record and report and moved from -T to
--timehist. Forgot to update the help message above.

David


\
 
 \ /
  Last update: 2010-11-30 20:39    [W:0.041 / U:11.412 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site