2009-10-06 06:10:42

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting

Hi,

This patchset defines a generic interface for processing the binary
output of 'perf trace' and making it directly available to
user-defined scripts written in general-purpose scripting languages
such as Perl or Python. It also builds a general-purpose Perl
scripting trace processor on top of the new interface and provides a
few example scripts that exercise the basic functionality.

The main motivation behind it is to provide a more efficient and
powerful alternative to the popular method of parsing the ascii trace
output in order to extract useful information from it. To avoid the
overhead and complexity of all that, this patchset provides a
direct-to-script-interpreter pathway for doing the same thing, but in
a more regularized fashion, one that takes advantage of all the event
meta-info provided by the tracing infrustructure, such as the
event/field info contained in the 'format files' designed for that
purpose.

Anyone who still wants to deal with the trace stream as straight ascii
text can still have the scripts generate it (and in fact the interface
provides a way to have event printing code auto-generated. Also, the
original ascii output mode is preserved when the scripting options
aren't used), but for anyone wanting to do something more interesting
with the data using a rapid prototyping language such as Perl, this
patchset makes it easy to do so. It allows the full power of
general-purpose scripting languages to be applied to the trace stream
to do non-trivial analyses, and suddenly makes available huge
libraries of useful tools and modules (e.g. CPAN for Perl) to be
applied to the problem of creating new and interesting trace
applications.

This patchset only implements a Perl interface, but the intention is
to make it relatively easy to add support for other languages such as
Python, Ruby, etc, etc - all they need to do is follow the example of
the Perl implementation and provide their own implementations of the
trace_scripting_operations (more details below).

It's loosely based on the 'zedtrace' tracer I posted awhile back and
still has some rough edges, but it should be useful enough to try out
and get something useful out of.

Known problems/shortcomings:

Probably the biggest problem right now is the sorting hack I added as
the last patch. It's just meant as a temporary thing, but is there
because tracing scripts in general want to see events in the order
they happened i.e. timestamp order. Considering that all this would
probably be much more useful if the script handling could happen in
essentially real time i.e. in 'live-mode', some work probably needs to
be done to create a sort that can work on small batches of events, as
they come in (and making sure no older ones can sneak in after a batch
has been processed).

For the Perl implemention I decided not to pass all of the available
event fields to the script handlers, only the ones that I thought
would be commonly used. So for example, common_flags and
common_preempt_count aren't passed. The idea would be that these
unpassed fields should still be available to the event handler, but
via a library function available to the script. This would also be
true for any other metadata it might be useful to give scripts access
to. It should be easy to do, but I'll have to do some more looking
into the Perl->C interface.

Even with some of the simple examples provided here, its apparent that
the recording code needs to be able to specify that some filtering be
done in the kernel. Maybe have a higher-level command that invokes
both 'perf record', passing it filters defined in a 'perf trace'
script and piping the binary output to 'perf trace' instead of writing
it to a file.

Anyway, here are some simple examples to get started...

First, you should build and install perf after installing the perl
development library, libperl (e.g. apt-get install liberl-dev in
ubuntu).

Having done that, you can run 'perf record' with a set of tracepoint
events you're interested in e.g.:

root@tropicana:~# perf record -c 1 -f -a -R -e kmem:kmalloc -e kmem:kfree -e irq:softirq_entry -e irq:softirq_exit -e sched:sched_switch
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.485 MB perf.data (~21198 samples) ]

Next, you can use the -p -g options of perf trace to have it generate
a script with one handler function for each event in the trace:

root@tropicana:~# perf trace -p -g

The name of the generated script will be 'perf-trace.pl':

root@tropicana:~# ls -al *.pl
-rw-r--r-- 1 root root 2904 2009-10-04 20:24 perf-trace.pl

Here's a portion of the Perl code generated for this trace, to give
some idea of what a trace script looks like:

# perf trace event handlers, generated by perf trace -p -g

# The common_* event handler fields are the most useful fields common to
# all events. They don't necessarily correspond to the 'common_*' fields
# in the status files. Those fields not available as handler params can
# be retrieved via script functions of the form get_common_*().

use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
use lib "./Perf-Trace-Util/lib";
use Perf::Trace::Core;
use Perf::Trace::Util;

sub trace_begin
{
# optional
}

sub trace_end
{
# optional
}

sub irq::softirq_entry
{
my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
$common_comm, $vec) = @_;

print_header($event_name, $common_cpu, $common_secs, $common_nsecs,
$common_pid, $common_comm);

printf("vec=%s\n", symbol_str("irq::softirq_entry", "vec", $vec));
}

sub kmem::kfree
{
my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
$common_comm, $call_site, $ptr) = @_;

print_header($event_name, $common_cpu, $common_secs, $common_nsecs,
$common_pid, $common_comm);

printf("call_site=%u, ptr=%u\n", $call_site, $ptr);
}

sub kmem::kmalloc
{
my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
$common_comm,
$call_site, $ptr, $bytes_req, $bytes_alloc, $gfp_flags) = @_;

print_header($event_name, $common_cpu, $common_secs, $common_nsecs,
$common_pid, $common_comm);

printf("call_site=%u, ptr=%u, bytes_req=%u, bytes_alloc=%u, gfp_flags=%s\n",
$call_site, $ptr, $bytes_req, $bytes_alloc,
flag_str("kmem::kmalloc", "gfp_flags", $gfp_flags));
}
.
.
.

For each event in the trace, the generated event handlers will print
the event name along with all the fields for the event. To have the
script do that, run perf trace with the -p -s options:

root@tropicana:~# perf trace -p -s perf-trace.pl

The output should look something like this:

kmem::kmalloc 1 04751.387886420 7249 perf call_site=18446744071579906539, ptr=18446612133245372416, bytes_req=640, bytes_alloc=1024, gfp_flags=GFP_WAIT | GFP_IO | GFP_ZERO
kmem::kmalloc 1 04751.387947149 7249 perf call_site=18446744071579905993, ptr=18446612134690881536, bytes_req=1112, bytes_alloc=2048, gfp_flags=GFP_WAIT | GFP_IO | GFP_ZERO
irq::softirq_entry 0 04751.388019731 0 swapper vec=TIMER
irq::softirq_exit 0 04751.388025089 0 swapper vec=TIMER
sched::sched_switch 1 04751.422756873 7249 perf prev_comm=perf, prev_pid=7249, prev_prio=120, prev_state=R, next_comm=apache2, next_pid=5659, next_prio=120
sched::sched_switch 1 04751.422783231 5659 apache2 prev_comm=apache2, prev_pid=5659, prev_prio=120, prev_state=S, next_comm=perf, next_pid=7249, next_prio=120
.
.
.

Notice the gfp_flags and vec fields in the previous trace snippet.
Not only does the generated script display the normal string and
numeric fields, but it also automatically figures out that certain
fields, though numeric, should be interpreted as flags or symbols
instead, and generates the code to do that (using the flag and
symbolic enumerations defined in the event's format file).

Running the autogenerated script and displaying the printed events is
only marginally useful; at the least it can be used to see what's
there and verify that things basically work.

One of the other things that might be marginally useful might be to
remove all the handlers from the generated script and replace it with
a single handler for the 'unhandled_trace' event which is available to
every script. Here's a complete script for doing that:

# perf trace event handlers, generated by perf trace -p -g

# The common_* event handler fields are the most useful fields common to
# all events. They don't necessarily correspond to the 'common_*' fields
# in the status files. Those fields not available as handler params can
# be retrieved via script functions of the form get_common_*().

use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
use lib "./Perf-Trace-Util/lib";
use Perf::Trace::Core;
use Perf::Trace::Util;

my %unhandled;

sub trace_end
{
print_unhandled();
}

sub trace_unhandled
{
my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
$common_comm) = @_;

$unhandled{$event_name}++;
}

sub print_unhandled
{
if ((scalar keys %unhandled) == 0) {
return;
}

print "\nunhandled events:\n\n";

printf("%-40s %10s\n", "event", "count");
printf("%-40s %10s\n", "----------------------------------------",
"-----------");

foreach my $event_name (keys %unhandled) {
printf("%-40s %10d\n", $event_name, $unhandled{$event_name});
}
}

For every unhandled event (every event for this script, since we
removed all the real handlers), the total counts for each are hashed
by event name and printed out at the end of the trace (in the
'trace_end' handler, which can also be defined for each script.
Here's some example output for this script:

root@tropicana:~# perf trace -p -s perf-trace-unhandled.pl
perf trace started with Perl script perf-trace.pl


unhandled events:

event count
---------------------------------------- -----------
kmem::kfree 927
irq::softirq_entry 288
kmem::kmalloc 929
sched::sched_switch 222
irq::softirq_exit 288

perf trace Perl script stopped

The main point of being able to script the trace stream, however, is
to use the power of the scripting language to do more useful analyses.
One simple example would be to display the total r/w activity for all
processes on the system:

root@tropicana:~# perf record -c 1 -f -a -R -e syscalls:sys_enter_read -e syscalls:sys_exit_read -e syscalls:sys_enter_write -e syscalls:sys_exit_write
^C[ perf record: Woken up 0 times to write data ]
[ perf record: Captured and wrote 8.540 MB perf.data (~373127 samples) ]

root@tropicana:~# perf trace -p -s libexec/perf-core/scripts/perl/rw-by-pid.pl
perf trace started with Perl script libexec/perf-core/scripts/perl/rw-by-pid.pl

read counts by pid:

pid comm # reads bytes_requested bytes_read
------ -------------------- ----------- ---------- ----------
8565 perf 1886 1928288 1683584
5520 Xorg 54 1296 1296
6242 gvfsd-trash 2 4096 194
6637 wterm 7 28672 64
6225 gnome-screensav 8 32768 64
6202 nautilus 5 16384 48
6169 gnome-settings- 3 12288 32
6200 gnome-panel 1 4096

failed reads by pid:

pid comm error # # errors
------ -------------------- ------ ----------
6202 nautilus -11 4
6169 gnome-settings- -11 2
6200 gnome-panel -11 1
6637 wterm -11 5
8565 perf 0 144
6225 gnome-screensav -11 6
6242 gvfsd-trash -11 1

write counts by pid:

pid comm # writes bytes_written
------ -------------------- ----------- ----------
8565 perf 122604 20204544
6242 gvfsd-trash 2 93
8566 gvfsd-trash 1 35
6637 wterm 1 1

failed writes by pid:

pid comm error # # errors
------ -------------------- ------ ----------

perf trace Perl script stopped

The above output shows sorted tables of reads and write activity, and
also tracks counts of each different read/write return error seen by
each process.

We can use the results of a higher-level trace analysis like the one
above to create other scripts that drill down to get more detailed
output. For example, the above results show that perf itself was
responsible for a lot of reading and writing. To see more detail
about which files it's reading from/writing to, we can write and run
another script:

root@tropicana:~# perf trace -p -s libexec/perf-core/scripts/perl/rw-by-file.pl
perf trace started with Perl script libexec/perf-core/scripts/perl/rw-by-file.pl

file read counts for perf:

fd # reads bytes_requested
------ ---------- -----------
19 1883 1928192
3 22 90112
30 2 4096
13 2 4096
12 54 1296
16 1 32
17 1 32
15 1 32

file write counts for perf:

fd # writes bytes_written
------ ---------- -----------
3 122604 20204544
1 3 128
4 1 1

unhandled events:

event count
---------------------------------------- -----------
syscalls::sys_exit_read 1965
syscalls::sys_exit_write 122608

perf trace Perl script stopped

>From the above, we see that most of the reads are coming from fd 19
and most of the writes are going to fd 3. At this point, we don't
have any further information about what those files actually are - to
do that we'd need to be able to get it from either the open() system
call tracepoint (preferably, but the filename isn't yet available from
that source) or from reading /proc during the trace.

Actually, we probably don't really event want to see the events from
perf itself, so should also have a way to filter out anything from
perf in the kernel, another todo item.

Another simple example could be to use a script to track wakeup
latencies:

root@tropicana:~# perf record -c 1 -f -a -R -e sched:sched_switch -e sched:sched_wakeup
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.375 MB perf.data (~16379 samples) ]

root@tropicana:~# perf trace -p -s libexec/perf-core/scripts/perl/wakeup-latency.pl

perf trace started with Perl script libexec/perf-core/scripts/perl/wakeup-latency.pl

wakeup_latency stats:

total_wakeups: 323
avg_wakeup_latency (ns): 12844
min_wakeup_latency (ns): 2229
max_wakeup_latency (ns): 360072

perf trace Perl script stopped

This script tracks the time differences between sched_wakeup and
sched_switch events and prints out the totals when the script is done.

One of the nice things about using trace data to do this kind of
analysis is that the individual trace records can be displayed at any
time, so for instance if one was interested in seeing exactly which
events caused the min an max latencies displayed in the output, the
individual events could be viewed by simply uncommenting the
auto-generated print statements.

See the wakeup-latency.pl script for details.

Finally, here's another example that displays workqueue stats for a
trace run:

root@tropicana:~# perf record -c 1 -f -a -R -e workqueue:workqueue_creation -e workqueue:workqueue_destruction -e workqueue:workqueue_execution -e workqueue:workqueue_insertion
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.312 MB perf.data (~13631 samples) ]

root@tropicana:~# perf trace -p -s libexec/perf-core/scripts/perl/workqueue-stats.pl
perf trace started with Perl script libexec/perf-core/scripts/perl/workqueue-stats.pl

workqueue work stats:

cpu ins exec name
--- --- ---- ----
0 99 99 kondemand/0
0 33 33 events/0
0 10 10 ata/0
1 30 30 kblockd/1
1 102 102 ata/1
1 35 35 events/1

workqueue lifecycle stats:

cpu created destroyed name
--- ------- --------- ----

perf trace Perl script stopped

See the workqueue-stats.pl script for details.


Adding support for a new language
---------------------------------

It should be relatively easy to add support for a new language,
especially if the language implementation supports an interface
allowing an interpreter to be 'embedded' inside another program (in
this case the containing program will be 'perf trace') and have
user-defined script-level functions invoked with the parameters
associated with an event. The event and field type information
exported by the event tracing infrastructure (via the event 'format'
files) should be enough to parse and send any piece of trace data to
the user script. The easiest way to see how this can be done would be
to look at the Perl implementation contained in
perf/util/trace-event-perl.c/.h.

The minimum that needs to be done do add support for a new language is
to implement the trace_scripting_operations interface:

start_script()
stop_script()
process_event()
generate_event_handlers()

start_script() is called before any events are processed, and is meant
to give the scripting language support an opportunity to set things up
to receive events e.g. create and initialize an instance of a language
interpreter.

stop_script() is called after all events are processed, and is meant
to give the scripting language support an opportunity to clean up
e.g. destroy the interpreter instance, etc.

process_event() is called once for each event and takes as its main
parameter a pointer to the binary trace event record to be processed.
The implementation is responsible for picking out the binary fields
from the event record and sending them to the script handler function
associated with that event e.g. a function derived from the event name
it's meant to handle e.g. 'sched::sched_switch()'. It's probably not
as much work as you'd think to parse the binary data and map it into a
form usable by a given scripting language - on the 'perf trace' side
you have extensive information about the field data types and on the
scripting language side you probably only have a few data types to
worry about, since dynamically typed languages are typically pretty
loose about typing e.g. for the Perl implementation, only 3
type-related interpreter functions were used, one each for signed,
unsigned, and string variables.

generate_event_handlers() should generate a ready-to-run script for
the current set of events in the trace, preferably with bodies that
print out every fields for every event. Again, look at the Perl
implementation for clues as to how that can be done. This is an
optional, but very useful op.

There are a couple of other things that aren't covered by the
trace_scripting_operations because different implementations might
want to do things differently, but that should be implemented anyway.
One of these is support for 'flag' and 'symbolic' fields e.g. being
able to use more human-readable values such as 'GFP_KERNEL' or
HI/BLOCK_IOPOLL/TASKLET in place of raw flag values. See the Perl
implementation to see how this might be done. Again, it shouldn't be
too painful if you can follow that example.

The final thing would be to provide a library of functions that script
writers could call to get trace meta-information or unpassed fields,
but even the Perl implementation hasn't gotten to that yet, so there's
nothing to look at there...

Thanks,

Tom


Tom Zanussi (9):
tracing/events: Add 'signed' field to format files
perf trace: Add subsystem string to struct event
perf trace: Add string/dynamic cases to format_flags
perf trace: Add trace scripting ops
perf trace: Add Perl scripting support
perf trace: Add scripting op for generating empty event handling
scripts
perf trace: Add FIELD_IS_FLAG/SYMBOLIC cases to format_flags
perf trace: Add perf trace scripting support modules for Perl
perf trace: Add throwaway timestamp sorting

include/trace/ftrace.h | 15 +-
kernel/trace/ring_buffer.c | 15 +-
kernel/trace/trace_events.c | 24 +-
kernel/trace/trace_export.c | 25 +-
kernel/trace/trace_syscalls.c | 20 +-
tools/perf/Makefile | 25 +
tools/perf/builtin-trace.c | 610 +++++++++++++++++++-
tools/perf/scripts/perl/Perf-Trace-Util/Changes | 6 +
tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST | 6 +
.../perf/scripts/perl/Perf-Trace-Util/Makefile.PL | 12 +
tools/perf/scripts/perl/Perf-Trace-Util/README | 30 +
.../perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm | 165 ++++++
.../perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm | 97 +++
.../perl/Perf-Trace-Util/t/Perf-Trace-Util.t | 15 +
tools/perf/scripts/perl/rw-by-file.pl | 95 +++
tools/perf/scripts/perl/rw-by-pid.pl | 151 +++++
tools/perf/scripts/perl/wakeup-latency.pl | 94 +++
tools/perf/scripts/perl/workqueue-stats.pl | 121 ++++
tools/perf/util/trace-event-parse.c | 87 +++-
tools/perf/util/trace-event-perl.c | 514 +++++++++++++++++
tools/perf/util/trace-event-perl.h | 37 ++
tools/perf/util/trace-event.h | 23 +-
22 files changed, 2135 insertions(+), 52 deletions(-)
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/Changes
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/Makefile.PL
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/README
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/t/Perf-Trace-Util.t
create mode 100644 tools/perf/scripts/perl/rw-by-file.pl
create mode 100644 tools/perf/scripts/perl/rw-by-pid.pl
create mode 100644 tools/perf/scripts/perl/wakeup-latency.pl
create mode 100644 tools/perf/scripts/perl/workqueue-stats.pl
create mode 100644 tools/perf/util/trace-event-perl.c
create mode 100644 tools/perf/util/trace-event-perl.h


2009-10-06 06:18:07

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 1/9] tracing/events: Add 'signed' field to format files

The sign info used for filters in the kernel is also useful to
applications that process the trace stream. Add it to the format
files and make it available to userspace.

Signed-off-by: Tom Zanussi <[email protected]>
---
include/trace/ftrace.h | 15 +++++++++------
kernel/trace/ring_buffer.c | 15 +++++++++------
kernel/trace/trace_events.c | 24 ++++++++++++------------
kernel/trace/trace_export.c | 25 ++++++++++++++-----------
kernel/trace/trace_syscalls.c | 20 +++++++++++++-------
tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
tools/perf/util/trace-event.h | 1 +
7 files changed, 82 insertions(+), 42 deletions(-)

diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index cc0d966..c9bbcab 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -120,9 +120,10 @@
#undef __field
#define __field(type, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%u;\tsize:%u;\n", \
+ "offset:%u;\tsize:%u;\tsigned:%u;\n", \
(unsigned int)offsetof(typeof(field), item), \
- (unsigned int)sizeof(field.item)); \
+ (unsigned int)sizeof(field.item), \
+ (unsigned int)is_signed_type(type)); \
if (!ret) \
return 0;

@@ -132,19 +133,21 @@
#undef __array
#define __array(type, item, len) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
- "offset:%u;\tsize:%u;\n", \
+ "offset:%u;\tsize:%u;\tsigned:%u;\n", \
(unsigned int)offsetof(typeof(field), item), \
- (unsigned int)sizeof(field.item)); \
+ (unsigned int)sizeof(field.item), \
+ (unsigned int)is_signed_type(type)); \
if (!ret) \
return 0;

#undef __dynamic_array
#define __dynamic_array(type, item, len) \
ret = trace_seq_printf(s, "\tfield:__data_loc " #type "[] " #item ";\t"\
- "offset:%u;\tsize:%u;\n", \
+ "offset:%u;\tsize:%u;\tsigned:%u;\n", \
(unsigned int)offsetof(typeof(field), \
__data_loc_##item), \
- (unsigned int)sizeof(field.__data_loc_##item)); \
+ (unsigned int)sizeof(field.__data_loc_##item), \
+ (unsigned int)is_signed_type(type)); \
if (!ret) \
return 0;

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index d4ff019..e43c928 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -397,18 +397,21 @@ int ring_buffer_print_page_header(struct trace_seq *s)
int ret;

ret = trace_seq_printf(s, "\tfield: u64 timestamp;\t"
- "offset:0;\tsize:%u;\n",
- (unsigned int)sizeof(field.time_stamp));
+ "offset:0;\tsize:%u;\tsigned:%u;\n",
+ (unsigned int)sizeof(field.time_stamp),
+ (unsigned int)is_signed_type(u64));

ret = trace_seq_printf(s, "\tfield: local_t commit;\t"
- "offset:%u;\tsize:%u;\n",
+ "offset:%u;\tsize:%u;\tsigned:%u;\n",
(unsigned int)offsetof(typeof(field), commit),
- (unsigned int)sizeof(field.commit));
+ (unsigned int)sizeof(field.commit),
+ (unsigned int)is_signed_type(long));

ret = trace_seq_printf(s, "\tfield: char data;\t"
- "offset:%u;\tsize:%u;\n",
+ "offset:%u;\tsize:%u;\tsigned:%u;\n",
(unsigned int)offsetof(typeof(field), data),
- (unsigned int)BUF_PAGE_SIZE);
+ (unsigned int)BUF_PAGE_SIZE,
+ (unsigned int)is_signed_type(char));

return ret;
}
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index d128f65..cf3cabf 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -507,7 +507,7 @@ extern char *__bad_type_size(void);
#define FIELD(type, name) \
sizeof(type) != sizeof(field.name) ? __bad_type_size() : \
#type, "common_" #name, offsetof(typeof(field), name), \
- sizeof(field.name)
+ sizeof(field.name), is_signed_type(type)

static int trace_write_header(struct trace_seq *s)
{
@@ -515,17 +515,17 @@ static int trace_write_header(struct trace_seq *s)

/* struct trace_entry */
return trace_seq_printf(s,
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\n",
- FIELD(unsigned short, type),
- FIELD(unsigned char, flags),
- FIELD(unsigned char, preempt_count),
- FIELD(int, pid),
- FIELD(int, lock_depth));
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\n",
+ FIELD(unsigned short, type),
+ FIELD(unsigned char, flags),
+ FIELD(unsigned char, preempt_count),
+ FIELD(int, pid),
+ FIELD(int, lock_depth));
}

static ssize_t
diff --git a/kernel/trace/trace_export.c b/kernel/trace/trace_export.c
index 9753fcc..31da218 100644
--- a/kernel/trace/trace_export.c
+++ b/kernel/trace/trace_export.c
@@ -66,44 +66,47 @@ static void __used ____ftrace_check_##name(void) \
#undef __field
#define __field(type, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%zu;\tsize:%zu;\n", \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
offsetof(typeof(field), item), \
- sizeof(field.item)); \
+ sizeof(field.item), is_signed_type(type)); \
if (!ret) \
return 0;

#undef __field_desc
#define __field_desc(type, container, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%zu;\tsize:%zu;\n", \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
offsetof(typeof(field), container.item), \
- sizeof(field.container.item)); \
+ sizeof(field.container.item), \
+ is_signed_type(type)); \
if (!ret) \
return 0;

#undef __array
#define __array(type, item, len) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
- "offset:%zu;\tsize:%zu;\n", \
- offsetof(typeof(field), item), \
- sizeof(field.item)); \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
+ offsetof(typeof(field), item), \
+ sizeof(field.item), is_signed_type(type)); \
if (!ret) \
return 0;

#undef __array_desc
#define __array_desc(type, container, item, len) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
- "offset:%zu;\tsize:%zu;\n", \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
offsetof(typeof(field), container.item), \
- sizeof(field.container.item)); \
+ sizeof(field.container.item), \
+ is_signed_type(type)); \
if (!ret) \
return 0;

#undef __dynamic_array
#define __dynamic_array(type, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%zu;\tsize:0;\n", \
- offsetof(typeof(field), item)); \
+ "offset:%zu;\tsize:0;\tsigned:%u;\n", \
+ offsetof(typeof(field), item), \
+ is_signed_type(type)); \
if (!ret) \
return 0;

diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index 527e17e..d99abc4 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -103,7 +103,8 @@ extern char *__bad_type_size(void);
#define SYSCALL_FIELD(type, name) \
sizeof(type) != sizeof(trace.name) ? \
__bad_type_size() : \
- #type, #name, offsetof(typeof(trace), name), sizeof(trace.name)
+ #type, #name, offsetof(typeof(trace), name), \
+ sizeof(trace.name), is_signed_type(type)

int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
{
@@ -120,7 +121,8 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
if (!entry)
return 0;

- ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
+ ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
+ "\tsigned:%u;\n",
SYSCALL_FIELD(int, nr));
if (!ret)
return 0;
@@ -130,8 +132,10 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
entry->args[i]);
if (!ret)
return 0;
- ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;\n", offset,
- sizeof(unsigned long));
+ ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;"
+ "\tsigned:%u;\n", offset,
+ sizeof(unsigned long),
+ is_signed_type(unsigned long));
if (!ret)
return 0;
offset += sizeof(unsigned long);
@@ -163,8 +167,10 @@ int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
struct syscall_trace_exit trace;

ret = trace_seq_printf(s,
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
+ "\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
+ "\tsigned:%u;\n",
SYSCALL_FIELD(int, nr),
SYSCALL_FIELD(long, ret));
if (!ret)
@@ -212,7 +218,7 @@ int syscall_exit_define_fields(struct ftrace_event_call *call)
if (ret)
return ret;

- ret = trace_define_field(call, SYSCALL_FIELD(long, ret), 0,
+ ret = trace_define_field(call, SYSCALL_FIELD(long, ret),
FILTER_OTHER);

return ret;
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 55b41b9..be8412d 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -897,6 +897,21 @@ static int event_read_fields(struct event *event, struct format_field **fields)
if (read_expected(EVENT_OP, (char *)";") < 0)
goto fail_expect;

+ if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
+ goto fail_expect;
+
+ if (read_expected(EVENT_OP, (char *)":") < 0)
+ goto fail_expect;
+
+ if (read_expect_type(EVENT_ITEM, &token))
+ goto fail;
+ if (strtoul(token, NULL, 0))
+ field->flags |= FIELD_IS_SIGNED;
+ free_token(token);
+
+ if (read_expected(EVENT_OP, (char *)";") < 0)
+ goto fail_expect;
+
if (read_expect_type(EVENT_NEWLINE, &token) < 0)
goto fail;
free_token(token);
@@ -2845,6 +2860,15 @@ static void parse_header_field(char *type,
free_token(token);
if (read_expected(EVENT_OP, (char *)";") < 0)
return;
+ if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
+ return;
+ if (read_expected(EVENT_OP, (char *)":") < 0)
+ return;
+ if (read_expect_type(EVENT_ITEM, &token) < 0)
+ return;
+ free_token(token);
+ if (read_expected(EVENT_OP, (char *)";") < 0)
+ return;
if (read_expect_type(EVENT_NEWLINE, &token) < 0)
return;
free_token(token);
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 162c3e6..00b440d 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -26,6 +26,7 @@ enum {
enum format_flags {
FIELD_IS_ARRAY = 1,
FIELD_IS_POINTER = 2,
+ FIELD_IS_SIGNED = 4,
};

struct format_field {
--
1.6.4.GIT

2009-10-06 06:10:46

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 2/9] perf trace: Add subsystem string to struct event

Needed to fully qualify event names for event stream processing.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/util/trace-event-parse.c | 4 +++-
tools/perf/util/trace-event.h | 3 ++-
2 files changed, 5 insertions(+), 2 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index be8412d..de3fc8b 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -2950,7 +2950,7 @@ int parse_ftrace_file(char *buf, unsigned long size)
return 0;
}

-int parse_event_file(char *buf, unsigned long size, char *system__unused __unused)
+int parse_event_file(char *buf, unsigned long size, char *sys)
{
struct event *event;
int ret;
@@ -2977,6 +2977,8 @@ int parse_event_file(char *buf, unsigned long size, char *system__unused __unuse
if (ret < 0)
die("failed to read event print fmt");

+ event->system = strdup(sys);
+
#define PRINT_ARGS 0
if (PRINT_ARGS && event->print_fmt.args)
print_args(event->print_fmt.args);
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 00b440d..cb92978 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -133,6 +133,7 @@ struct event {
int flags;
struct format format;
struct print_fmt print_fmt;
+ char *system;
};

enum {
@@ -167,7 +168,7 @@ void print_funcs(void);
void print_printk(void);

int parse_ftrace_file(char *buf, unsigned long size);
-int parse_event_file(char *buf, unsigned long size, char *system);
+int parse_event_file(char *buf, unsigned long size, char *sys);
void print_event(int cpu, void *data, int size, unsigned long long nsecs,
char *comm);

--
1.6.4.GIT

2009-10-06 06:11:32

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 3/9] perf trace: Add string/dynamic cases to format_flags

Needed for distinguishing string fields in event stream processing.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
tools/perf/util/trace-event.h | 2 ++
2 files changed, 26 insertions(+), 0 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index de3fc8b..6f851f9 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -721,6 +721,24 @@ static int event_read_id(void)
return -1;
}

+static int field_is_string(struct format_field *field)
+{
+ if ((field->flags & FIELD_IS_ARRAY) &&
+ (!strstr(field->type, "char") || !strstr(field->type, "u8") ||
+ !strstr(field->type, "s8")))
+ return 1;
+
+ return 0;
+}
+
+static int field_is_dynamic(struct format_field *field)
+{
+ if (!strcmp(field->type, "__data_loc"))
+ return 1;
+
+ return 0;
+}
+
static int event_read_fields(struct event *event, struct format_field **fields)
{
struct format_field *field = NULL;
@@ -865,6 +883,12 @@ static int event_read_fields(struct event *event, struct format_field **fields)
free(brackets);
}

+ if (field_is_string(field)) {
+ field->flags |= FIELD_IS_STRING;
+ if (field_is_dynamic(field))
+ field->flags |= FIELD_IS_DYNAMIC;
+ }
+
if (test_type_token(type, token, EVENT_OP, (char *)";"))
goto fail;
free_token(token);
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index cb92978..5f59a39 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -27,6 +27,8 @@ enum format_flags {
FIELD_IS_ARRAY = 1,
FIELD_IS_POINTER = 2,
FIELD_IS_SIGNED = 4,
+ FIELD_IS_STRING = 8,
+ FIELD_IS_DYNAMIC = 16,
};

struct format_field {
--
1.6.4.GIT

2009-10-06 06:10:52

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 4/9] perf trace: Add trace scripting ops

Support any number of scripting languages for trace stream processing
by adding a set of functions, trace_scripting_operations, that can be
implemented to support a given language.

- start_script() - initialize e.g. create and initialize the interpreter
- stop_script() - clean up e.g. destroy the interpreter
- process_event() - send each event and its data to the interpreter

Support for a given language should also modify setup_scripting() to
replace the do-nothing default_scripting_ops with the
language-specific scripting ops for that language.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/builtin-trace.c | 53 +++++++++++++++++++++++++++++++++++++++-
tools/perf/util/trace-event.h | 7 +++++
2 files changed, 58 insertions(+), 2 deletions(-)

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 5d4c84d..a654a5a 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -27,6 +27,37 @@ static struct thread *last_match;
static struct perf_header *header;
static u64 sample_type;

+static char const *script_name;
+
+static int default_start_script(const char *script __attribute((unused)))
+{
+ return 0;
+}
+
+static int default_stop_script(void)
+{
+ return 0;
+}
+
+static struct trace_scripting_operations default_scripting_ops = {
+ .start_script = default_start_script,
+ .stop_script = default_stop_script,
+ .process_event = print_event,
+};
+
+static struct trace_scripting_operations *scripting_ops;
+
+static int setup_scripting(const char *script __attribute((unused)))
+{
+ scripting_ops = &default_scripting_ops;
+
+ return 0;
+}
+
+static int cleanup_scripting(void)
+{
+ return scripting_ops->stop_script();
+}

static int
process_comm_event(event_t *event, unsigned long offset, unsigned long head)
@@ -105,7 +136,8 @@ process_sample_event(event_t *event, unsigned long offset, unsigned long head)
* field, although it should be the same than this perf
* event pid
*/
- print_event(cpu, raw->data, raw->size, timestamp, thread->comm);
+ scripting_ops->process_event(cpu, raw->data, raw->size,
+ timestamp, thread->comm);
}
total += period;

@@ -239,11 +271,15 @@ static const struct option options[] = {
"dump raw trace in ASCII"),
OPT_BOOLEAN('v', "verbose", &verbose,
"be more verbose (show symbol address, etc)"),
+ OPT_STRING('s', "script", &script_name, "file",
+ "script file name"),
OPT_END()
};

int cmd_trace(int argc, const char **argv, const char *prefix __used)
{
+ int err;
+
symbol__init();
page_size = getpagesize();

@@ -259,5 +295,18 @@ int cmd_trace(int argc, const char **argv, const char *prefix __used)

setup_pager();

- return __cmd_trace();
+ err = setup_scripting(script_name);
+ if (err)
+ goto out;
+
+ if (script_name) {
+ err = scripting_ops->start_script(script_name);
+ goto out;
+ }
+
+ err = __cmd_trace();
+
+ cleanup_scripting();
+out:
+ return err;
}
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 5f59a39..449c23d 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -246,4 +246,11 @@ void *raw_field_ptr(struct event *event, const char *name, void *data);

void read_tracing_data(struct perf_event_attr *pattrs, int nb_events);

+struct trace_scripting_operations {
+ int (*start_script) (const char *);
+ int (*stop_script) (void);
+ void (*process_event) (int cpu, void *data, int size,
+ unsigned long long nsecs, char *comm);
+};
+
#endif /* __PERF_TRACE_EVENTS_H */
--
1.6.4.GIT

2009-10-06 06:17:29

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 5/9] perf trace: Add Perl scripting support

Implement trace_scripting_operations to make Perl a supported perf
trace scripting language.

Also adds code that allows Perl trace scripts to access the 'flag' and
'symbolic' (__print_flags(), __print_symbolic()) field information
parsed from the trace format files.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/Makefile | 13 ++
tools/perf/builtin-trace.c | 37 +++-
tools/perf/util/trace-event-parse.c | 18 ++-
tools/perf/util/trace-event-perl.c | 385 +++++++++++++++++++++++++++++++++++
tools/perf/util/trace-event-perl.h | 37 ++++
tools/perf/util/trace-event.h | 7 +
6 files changed, 480 insertions(+), 17 deletions(-)
create mode 100644 tools/perf/util/trace-event-perl.c
create mode 100644 tools/perf/util/trace-event-perl.h

diff --git a/tools/perf/Makefile b/tools/perf/Makefile
index 5a42996..a443bd3 100644
--- a/tools/perf/Makefile
+++ b/tools/perf/Makefile
@@ -375,6 +375,7 @@ LIB_OBJS += util/thread.o
LIB_OBJS += util/trace-event-parse.o
LIB_OBJS += util/trace-event-read.o
LIB_OBJS += util/trace-event-info.o
+LIB_OBJS += util/trace-event-perl.o
LIB_OBJS += util/svghelper.o
LIB_OBJS += util/sort.o
LIB_OBJS += util/hist.o
@@ -423,6 +424,15 @@ ifneq ($(shell sh -c "(echo '\#include <libelf.h>'; echo 'int main(void) { Elf *
msg := $(error No libelf.h/libelf found, please install libelf-dev/elfutils-libelf-devel);
endif

+PERL_EMBED_LDOPTS = `perl -MExtUtils::Embed -e ldopts`
+PERL_EMBED_CCOPTS = `perl -MExtUtils::Embed -e ccopts`
+
+ifneq ($(shell sh -c "(echo '\#include <EXTERN.h>'; echo '\#include <perl.h>'; echo 'int main(void) { perl_alloc(); return 0; }') | $(CC) -x c - $(PERL_EMBED_CCOPTS) -o /dev/null $(PERL_EMBED_LDOPTS) > /dev/null 2>&1 && echo y"), y)
+ BASIC_CFLAGS += -DNO_LIBPERL
+else
+ ALL_LDFLAGS += $(PERL_EMBED_LDOPTS)
+endif
+
ifdef NO_DEMANGLE
BASIC_CFLAGS += -DNO_DEMANGLE
else
@@ -781,6 +791,9 @@ util/config.o: util/config.c PERF-CFLAGS
util/rbtree.o: ../../lib/rbtree.c PERF-CFLAGS
$(QUIET_CC)$(CC) -o util/rbtree.o -c $(ALL_CFLAGS) -DETC_PERFCONFIG='"$(ETC_PERFCONFIG_SQ)"' $<

+util/trace-event-perl.o: util/trace-event-perl.c PERF-CFLAGS
+ $(QUIET_CC)$(CC) -o util/trace-event-perl.o -c $(ALL_CFLAGS) $(PERL_EMBED_CCOPTS) -Wno-redundant-decls -Wno-strict-prototypes -Wno-unused-parameter $<
+
perf-%$X: %.o $(PERFLIBS)
$(QUIET_LINK)$(CC) $(ALL_CFLAGS) -o $@ $(ALL_LDFLAGS) $(filter %.o,$^) $(LIBS)

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index a654a5a..74aec38 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -29,6 +29,8 @@ static u64 sample_type;

static char const *script_name;

+static int do_perl;
+
static int default_start_script(const char *script __attribute((unused)))
{
return 0;
@@ -47,18 +49,6 @@ static struct trace_scripting_operations default_scripting_ops = {

static struct trace_scripting_operations *scripting_ops;

-static int setup_scripting(const char *script __attribute((unused)))
-{
- scripting_ops = &default_scripting_ops;
-
- return 0;
-}
-
-static int cleanup_scripting(void)
-{
- return scripting_ops->stop_script();
-}
-
static int
process_comm_event(event_t *event, unsigned long offset, unsigned long head)
{
@@ -271,11 +261,34 @@ static const struct option options[] = {
"dump raw trace in ASCII"),
OPT_BOOLEAN('v', "verbose", &verbose,
"be more verbose (show symbol address, etc)"),
+ OPT_BOOLEAN('p', "perl", &do_perl,
+ "send output to a Perl script"),
OPT_STRING('s', "script", &script_name, "file",
"script file name"),
OPT_END()
};

+static int setup_scripting(const char *script)
+{
+ if ((do_perl && !script) || (script && !do_perl))
+ usage_with_options(annotate_usage, options);
+
+ scripting_ops = &default_scripting_ops;
+
+ if (do_perl) {
+ scripting_ops = setup_perl_scripting();
+ if (!scripting_ops)
+ return -1;
+ }
+
+ return 0;
+}
+
+static int cleanup_scripting(void)
+{
+ return scripting_ops->stop_script();
+}
+
int cmd_trace(int argc, const char **argv, const char *prefix __used)
{
int err;
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 6f851f9..bc482c5 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -1798,7 +1798,7 @@ find_any_field(struct event *event, const char *name)
return find_field(event, name);
}

-static unsigned long long read_size(void *ptr, int size)
+unsigned long long read_size(void *ptr, int size)
{
switch (size) {
case 1:
@@ -1877,7 +1877,7 @@ int trace_parse_common_type(void *data)
return read_size(data + type_offset, type_size);
}

-static int parse_common_pid(void *data)
+int trace_parse_common_pid(void *data)
{
static int pid_offset;
static int pid_size;
@@ -1905,6 +1905,14 @@ struct event *trace_find_event(int id)
return event;
}

+struct event *trace_find_next_event(struct event *event)
+{
+ if (!event)
+ return event_list;
+
+ return event->next;
+}
+
static unsigned long long eval_num_arg(void *data, int size,
struct event *event, struct print_arg *arg)
{
@@ -2017,7 +2025,7 @@ static const struct flag flags[] = {
{ "HRTIMER_RESTART", 1 },
};

-static unsigned long long eval_flag(const char *flag)
+unsigned long long eval_flag(const char *flag)
{
int i;

@@ -2491,7 +2499,7 @@ get_return_for_leaf(int cpu, int cur_pid, unsigned long long cur_func,
if (!(event->flags & EVENT_FL_ISFUNCRET))
return NULL;

- pid = parse_common_pid(next->data);
+ pid = trace_parse_common_pid(next->data);
field = find_field(event, "func");
if (!field)
die("function return does not have field func");
@@ -2767,7 +2775,7 @@ void print_event(int cpu, void *data, int size, unsigned long long nsecs,
return;
}

- pid = parse_common_pid(data);
+ pid = trace_parse_common_pid(data);

if (event->flags & (EVENT_FL_ISFUNCENT | EVENT_FL_ISFUNCRET))
return pretty_print_func_graph(data, size, event, cpu,
diff --git a/tools/perf/util/trace-event-perl.c b/tools/perf/util/trace-event-perl.c
new file mode 100644
index 0000000..1264e14
--- /dev/null
+++ b/tools/perf/util/trace-event-perl.c
@@ -0,0 +1,385 @@
+/*
+ * trace-event-perl. Feed perf trace events to an embedded Perl interpreter.
+ *
+ * Copyright (C) 2009 Tom Zanussi <[email protected]>
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
+ *
+ */
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <ctype.h>
+#include <errno.h>
+
+#include "../perf.h"
+#include "util.h"
+#include "exec_cmd.h"
+#include "trace-event.h"
+#include "trace-event-perl.h"
+
+INTERP my_perl;
+
+#define FTRACE_MAX_EVENT \
+ ((1 << (sizeof(unsigned short) * 8)) - 1)
+
+struct event *events[FTRACE_MAX_EVENT];
+
+static char *cur_field_name;
+static int zero_flag_atom;
+
+static void define_symbolic_value(const char *ev_name,
+ const char *field_name,
+ const char *field_value,
+ const char *field_str)
+{
+ unsigned long long value;
+ dSP;
+
+ value = eval_flag(field_value);
+
+ ENTER;
+ SAVETMPS;
+ PUSHMARK(SP);
+
+ XPUSHs(sv_2mortal(newSVpv(ev_name, 0)));
+ XPUSHs(sv_2mortal(newSVpv(field_name, 0)));
+ XPUSHs(sv_2mortal(newSVuv(value)));
+ XPUSHs(sv_2mortal(newSVpv(field_str, 0)));
+
+ PUTBACK;
+ if (get_cv("main::define_symbolic_value", 0))
+ call_pv("main::define_symbolic_value", G_SCALAR);
+ SPAGAIN;
+ PUTBACK;
+ FREETMPS;
+ LEAVE;
+}
+
+static void define_symbolic_values(struct print_flag_sym *field,
+ const char *ev_name,
+ const char *field_name)
+{
+ define_symbolic_value(ev_name, field_name, field->value, field->str);
+ if (field->next)
+ define_symbolic_values(field->next, ev_name, field_name);
+}
+
+static void define_symbolic_field(const char *ev_name,
+ const char *field_name)
+{
+ dSP;
+
+ ENTER;
+ SAVETMPS;
+ PUSHMARK(SP);
+
+ XPUSHs(sv_2mortal(newSVpv(ev_name, 0)));
+ XPUSHs(sv_2mortal(newSVpv(field_name, 0)));
+
+ PUTBACK;
+ if (get_cv("main::define_symbolic_field", 0))
+ call_pv("main::define_symbolic_field", G_SCALAR);
+ SPAGAIN;
+ PUTBACK;
+ FREETMPS;
+ LEAVE;
+}
+
+static void define_flag_value(const char *ev_name,
+ const char *field_name,
+ const char *field_value,
+ const char *field_str)
+{
+ unsigned long long value;
+ dSP;
+
+ value = eval_flag(field_value);
+
+ ENTER;
+ SAVETMPS;
+ PUSHMARK(SP);
+
+ XPUSHs(sv_2mortal(newSVpv(ev_name, 0)));
+ XPUSHs(sv_2mortal(newSVpv(field_name, 0)));
+ XPUSHs(sv_2mortal(newSVuv(value)));
+ XPUSHs(sv_2mortal(newSVpv(field_str, 0)));
+
+ PUTBACK;
+ if (get_cv("main::define_flag_value", 0))
+ call_pv("main::define_flag_value", G_SCALAR);
+ SPAGAIN;
+ PUTBACK;
+ FREETMPS;
+ LEAVE;
+}
+
+static void define_flag_values(struct print_flag_sym *field,
+ const char *ev_name,
+ const char *field_name)
+{
+ define_flag_value(ev_name, field_name, field->value, field->str);
+ if (field->next)
+ define_flag_values(field->next, ev_name, field_name);
+}
+
+static void define_flag_field(const char *ev_name,
+ const char *field_name,
+ const char *delim)
+{
+ dSP;
+
+ ENTER;
+ SAVETMPS;
+ PUSHMARK(SP);
+
+ XPUSHs(sv_2mortal(newSVpv(ev_name, 0)));
+ XPUSHs(sv_2mortal(newSVpv(field_name, 0)));
+ XPUSHs(sv_2mortal(newSVpv(delim, 0)));
+
+ PUTBACK;
+ if (get_cv("main::define_flag_field", 0))
+ call_pv("main::define_flag_field", G_SCALAR);
+ SPAGAIN;
+ PUTBACK;
+ FREETMPS;
+ LEAVE;
+}
+
+static void define_event_symbols(struct event *event,
+ const char *ev_name,
+ struct print_arg *args)
+{
+ switch (args->type) {
+ case PRINT_NULL:
+ break;
+ case PRINT_ATOM:
+ define_flag_value(ev_name, cur_field_name, "0",
+ args->atom.atom);
+ zero_flag_atom = 0;
+ break;
+ case PRINT_FIELD:
+ if (cur_field_name)
+ free(cur_field_name);
+ cur_field_name = strdup(args->field.name);
+ break;
+ case PRINT_FLAGS:
+ define_event_symbols(event, ev_name, args->flags.field);
+ define_flag_field(ev_name, cur_field_name, args->flags.delim);
+ define_flag_values(args->flags.flags, ev_name, cur_field_name);
+ break;
+ case PRINT_SYMBOL:
+ define_event_symbols(event, ev_name, args->symbol.field);
+ define_symbolic_field(ev_name, cur_field_name);
+ define_symbolic_values(args->symbol.symbols, ev_name,
+ cur_field_name);
+ break;
+ case PRINT_STRING:
+ break;
+ case PRINT_TYPE:
+ define_event_symbols(event, ev_name, args->typecast.item);
+ break;
+ case PRINT_OP:
+ if (strcmp(args->op.op, ":") == 0)
+ zero_flag_atom = 1;
+ define_event_symbols(event, ev_name, args->op.left);
+ define_event_symbols(event, ev_name, args->op.right);
+ break;
+ default:
+ /* we should warn... */
+ return;
+ }
+
+ if (args->next)
+ define_event_symbols(event, ev_name, args->next);
+}
+
+static inline struct event *find_cache_event(int type)
+{
+ static char ev_name[256];
+ struct event *event;
+
+ if (events[type])
+ return events[type];
+
+ events[type] = event = trace_find_event(type);
+ if (!event)
+ return NULL;
+
+ sprintf(ev_name, "%s::%s", event->system, event->name);
+
+ define_event_symbols(event, ev_name, event->print_fmt.args);
+
+ return event;
+}
+
+static void perl_process_event(int cpu, void *data,
+ int size __attribute((unused)),
+ unsigned long long nsecs, char *comm)
+{
+ struct format_field *field;
+ static char handler[256];
+ unsigned long long val;
+ unsigned long s, ns;
+ struct event *event;
+ int type;
+ int pid;
+
+ dSP;
+
+ type = trace_parse_common_type(data);
+
+ event = find_cache_event(type);
+ if (!event)
+ die("ug! no event found for type %d", type);
+
+ pid = trace_parse_common_pid(data);
+
+ sprintf(handler, "%s::%s", event->system, event->name);
+
+ s = nsecs / NSECS_PER_SEC;
+ ns = nsecs - s * NSECS_PER_SEC;
+
+ ENTER;
+ SAVETMPS;
+ PUSHMARK(SP);
+
+ XPUSHs(sv_2mortal(newSVpv(handler, 0)));
+ XPUSHs(sv_2mortal(newSVuv(cpu)));
+ XPUSHs(sv_2mortal(newSVuv(s)));
+ XPUSHs(sv_2mortal(newSVuv(ns)));
+ XPUSHs(sv_2mortal(newSViv(pid)));
+ XPUSHs(sv_2mortal(newSVpv(comm, 0)));
+
+ /* common fields other than pid can be accessed via xsub fns */
+
+ for (field = event->format.fields; field; field = field->next) {
+ if (field->flags & FIELD_IS_STRING) {
+ int offset;
+ if (field->flags & FIELD_IS_DYNAMIC) {
+ offset = *(int *)(data + field->offset);
+ offset &= 0xffff;
+ } else
+ offset = field->offset;
+ XPUSHs(sv_2mortal(newSVpv((char *)data + offset, 0)));
+ } else { /* FIELD_IS_NUMERIC */
+ val = read_size(data + field->offset, field->size);
+ if (field->flags & FIELD_IS_SIGNED) {
+ XPUSHs(sv_2mortal(newSViv(val)));
+ } else {
+ XPUSHs(sv_2mortal(newSVuv(val)));
+ }
+ }
+ }
+
+ PUTBACK;
+ if (get_cv(handler, 0))
+ call_pv(handler, G_SCALAR);
+ else if (get_cv("main::trace_unhandled", 0)) {
+ XPUSHs(sv_2mortal(newSVpv(handler, 0)));
+ XPUSHs(sv_2mortal(newSVuv(cpu)));
+ XPUSHs(sv_2mortal(newSVuv(nsecs)));
+ XPUSHs(sv_2mortal(newSViv(pid)));
+ XPUSHs(sv_2mortal(newSVpv(comm, 0)));
+ call_pv("main::trace_unhandled", G_SCALAR);
+ }
+ SPAGAIN;
+ PUTBACK;
+ FREETMPS;
+ LEAVE;
+}
+
+static void run_start_sub(void)
+{
+ dSP; /* access to Perl stack */
+ PUSHMARK(SP);
+
+ if (get_cv("main::trace_begin", 0))
+ call_pv("main::trace_begin", G_DISCARD | G_NOARGS);
+}
+
+/*
+ * Start trace script
+ */
+static int perl_start_script(const char *script)
+{
+ const char *command_line[2] = { "", NULL };
+
+ command_line[1] = script;
+
+ my_perl = perl_alloc();
+ perl_construct(my_perl);
+
+ if (perl_parse(my_perl, NULL, 2, (char **)command_line, (char **)NULL))
+ return -1;
+
+ perl_run(my_perl);
+ if (SvTRUE(ERRSV))
+ return -1;
+
+ run_start_sub();
+
+ fprintf(stderr, "perf trace started with Perl script %s\n\n", script);
+
+ return 0;
+}
+
+/*
+ * Stop trace script
+ */
+static int perl_stop_script(void)
+{
+ dSP; /* access to Perl stack */
+ PUSHMARK(SP);
+
+ if (get_cv("main::trace_end", 0))
+ call_pv("main::trace_end", G_DISCARD | G_NOARGS);
+
+ perl_destruct(my_perl);
+ perl_free(my_perl);
+
+ fprintf(stderr, "\nperf trace Perl script stopped\n");
+
+ return 0;
+}
+
+struct trace_scripting_operations perl_scripting_ops = {
+ .start_script = perl_start_script,
+ .stop_script = perl_stop_script,
+ .process_event = perl_process_event,
+};
+
+#ifdef NO_LIBPERL
+struct trace_scripting_operations *setup_perl_scripting(void)
+{
+ fprintf(stderr, "Perl scripting not supported."
+ " Install libperl-dev[el] and rebuild perf to get it.\n");
+
+ return NULL;
+}
+#else
+struct trace_scripting_operations *setup_perl_scripting(void)
+{
+ struct trace_scripting_operations *scripting_ops;
+
+ scripting_ops = &perl_scripting_ops;
+
+ /* make sure PERF_EXEC_PATH is set for scripts */
+ perf_set_argv_exec_path(perf_exec_path());
+
+ return scripting_ops;
+}
+#endif
diff --git a/tools/perf/util/trace-event-perl.h b/tools/perf/util/trace-event-perl.h
new file mode 100644
index 0000000..0db7484
--- /dev/null
+++ b/tools/perf/util/trace-event-perl.h
@@ -0,0 +1,37 @@
+#ifndef __PERF_TRACE_EVENT_PERL_H
+#define __PERF_TRACE_EVENT_PERL_H
+#ifdef NO_LIBPERL
+typedef int INTERP;
+#define dSP
+#define ENTER
+#define SAVETMPS
+#define PUTBACK
+#define SPAGAIN
+#define FREETMPS
+#define LEAVE
+#define SP
+#define ERRSV
+#define G_SCALAR (0)
+#define G_DISCARD (0)
+#define G_NOARGS (0)
+#define PUSHMARK(a)
+#define SvTRUE(a) (0)
+#define XPUSHs(s)
+#define sv_2mortal(a)
+#define newSVpv(a,b)
+#define newSVuv(a)
+#define newSViv(a)
+#define get_cv(a,b) (0)
+#define call_pv(a,b) (0)
+#define perl_alloc() (0)
+#define perl_construct(a) (0)
+#define perl_parse(a,b,c,d,e) (0)
+#define perl_run(a) (0)
+#define perl_destruct(a) (0)
+#define perl_free(a) (0)
+#else
+#include <EXTERN.h>
+#include <perl.h>
+typedef PerlInterpreter * INTERP;
+#endif
+#endif /* __PERF_TRACE_EVENT_PERL_H */
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 449c23d..f812a8e 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -239,10 +239,14 @@ extern int header_page_data_size;

int parse_header_page(char *buf, unsigned long size);
int trace_parse_common_type(void *data);
+int trace_parse_common_pid(void *data);
struct event *trace_find_event(int id);
+struct event *trace_find_next_event(struct event *event);
+unsigned long long read_size(void *ptr, int size);
unsigned long long
raw_field_value(struct event *event, const char *name, void *data);
void *raw_field_ptr(struct event *event, const char *name, void *data);
+unsigned long long eval_flag(const char *flag);

void read_tracing_data(struct perf_event_attr *pattrs, int nb_events);

@@ -253,4 +257,7 @@ struct trace_scripting_operations {
unsigned long long nsecs, char *comm);
};

+extern struct trace_scripting_operations perl_scripting_ops;
+struct trace_scripting_operations *setup_perl_scripting(void);
+
#endif /* __PERF_TRACE_EVENTS_H */
--
1.6.4.GIT

2009-10-06 06:10:51

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 6/9] perf trace: Add scripting op for generating empty event handling scripts

To give script writers an easy starting point for writing scripts,
scripting language support for a particular language can implement a
generate_event_handlers() scripting op that will output an empty (or
near-empty) set of handlers in the supported language for all the
events contained in a give perf.data trace file.

This patch adds the generate_event_handlers() scripting op and also
adds a Perl implementation that creates a ready-to-run Perl script
that can be passed to perf trace for generic event printing. Scripts
generated by this implementation print out all the fields for each
event (and will detect and generate the proper scripting code for
'flag' and 'symbolic' fields), and will additionally generate handlers
for the special 'trace_unhandled', 'trace_begin' and 'trace_end'
handlers. Script authors can simply remove the printing code to
implement their own custom event handling.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/builtin-trace.c | 23 +++++++-
tools/perf/util/trace-event-perl.c | 114 ++++++++++++++++++++++++++++++++++++
tools/perf/util/trace-event.h | 1 +
3 files changed, 136 insertions(+), 2 deletions(-)

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 74aec38..b151e77 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -30,6 +30,7 @@ static u64 sample_type;
static char const *script_name;

static int do_perl;
+static int generate_handlers;

static int default_start_script(const char *script __attribute((unused)))
{
@@ -41,10 +42,16 @@ static int default_stop_script(void)
return 0;
}

+static int default_generate_event_handlers(const char *outfile __attribute ((unused)))
+{
+ return 0;
+}
+
static struct trace_scripting_operations default_scripting_ops = {
.start_script = default_start_script,
.stop_script = default_stop_script,
.process_event = print_event,
+ .generate_event_handlers = default_generate_event_handlers,
};

static struct trace_scripting_operations *scripting_ops;
@@ -263,6 +270,8 @@ static const struct option options[] = {
"be more verbose (show symbol address, etc)"),
OPT_BOOLEAN('p', "perl", &do_perl,
"send output to a Perl script"),
+ OPT_BOOLEAN('g', "generate-event-handlers", &generate_handlers,
+ "generate empty event handlers for scripting languages"),
OPT_STRING('s', "script", &script_name, "file",
"script file name"),
OPT_END()
@@ -270,11 +279,14 @@ static const struct option options[] = {

static int setup_scripting(const char *script)
{
+ if (do_perl && generate_handlers)
+ goto setup;
+
if ((do_perl && !script) || (script && !do_perl))
usage_with_options(annotate_usage, options);

scripting_ops = &default_scripting_ops;
-
+setup:
if (do_perl) {
scripting_ops = setup_perl_scripting();
if (!scripting_ops)
@@ -312,9 +324,16 @@ int cmd_trace(int argc, const char **argv, const char *prefix __used)
if (err)
goto out;

+ if (generate_handlers) {
+ trace_report();
+ err = scripting_ops->generate_event_handlers("perf-trace.pl");
+ goto out;
+ }
+
if (script_name) {
err = scripting_ops->start_script(script_name);
- goto out;
+ if (err)
+ goto out;
}

err = __cmd_trace();
diff --git a/tools/perf/util/trace-event-perl.c b/tools/perf/util/trace-event-perl.c
index 1264e14..657b87a 100644
--- a/tools/perf/util/trace-event-perl.c
+++ b/tools/perf/util/trace-event-perl.c
@@ -356,10 +356,124 @@ static int perl_stop_script(void)
return 0;
}

+static int perl_generate_event_handlers(const char *outfile)
+{
+ struct event *event = NULL;
+ struct format_field *f;
+ int not_first;
+ FILE *ofp;
+
+ ofp = fopen(outfile, "w");
+ if (ofp == NULL) {
+ fprintf(stderr, "couldn't open %s\n", outfile);
+ return -1;
+ }
+
+ fprintf(ofp, "# perf trace event handlers, "
+ "generated by perf trace -p -g\n\n");
+
+ fprintf(ofp, "# The common_* event handler fields are the most useful "
+ "fields common to\n");
+
+ fprintf(ofp, "# all events. They don't necessarily correspond to "
+ "the 'common_*' fields\n");
+
+ fprintf(ofp, "# in the status files. Those fields not available as "
+ "handler params can\n");
+
+ fprintf(ofp, "# be retrieved via script functions of the form "
+ "get_common_*().\n\n");
+
+ fprintf(ofp, "use lib \"$ENV{'PERF_EXEC_PATH'}/scripts/perl/"
+ "Perf-Trace-Util/lib\";\n");
+
+ fprintf(ofp, "use lib \"./Perf-Trace-Util/lib\";\n");
+ fprintf(ofp, "use Perf::Trace::Core;\n");
+ fprintf(ofp, "use Perf::Trace::Util;\n\n");
+
+ fprintf(ofp, "sub trace_begin\n{\n # optional\n}\n\n");
+ fprintf(ofp, "sub trace_end\n{\n # optional\n}\n\n");
+
+ while ((event = trace_find_next_event(event))) {
+ fprintf(ofp, "sub %s::%s\n{\n", event->system, event->name);
+ fprintf(ofp, " my (");
+
+ fprintf(ofp, "$event_name, ");
+ fprintf(ofp, "$common_cpu, ");
+ fprintf(ofp, "$common_secs, ");
+ fprintf(ofp, "$common_nsecs, ");
+ fprintf(ofp, "$common_pid, ");
+ fprintf(ofp, "$common_comm,\n ");
+
+ not_first = 0;
+
+ for (f = event->format.fields; f; f = f->next) {
+ if (not_first++)
+ fprintf(ofp, ", ");
+
+ fprintf(ofp, "$%s", f->name);
+ }
+ fprintf(ofp, ") = @_;\n\n");
+
+ fprintf(ofp, " print_header($event_name, $common_cpu, "
+ "$common_secs, $common_nsecs, $common_pid, "
+ "$common_comm);\n\n");
+
+ fprintf(ofp, " printf(\"");
+
+ not_first = 0;
+
+ for (f = event->format.fields; f; f = f->next) {
+ if (not_first++)
+ fprintf(ofp, ", ");
+
+ fprintf(ofp, "%s=", f->name);
+ if (f->flags & FIELD_IS_STRING)
+ fprintf(ofp, "%%s");
+ else if (f->flags & FIELD_IS_SIGNED)
+ fprintf(ofp, "%%d");
+ else
+ fprintf(ofp, "%%u");
+ }
+
+ fprintf(ofp, "\\n\", ");
+
+ not_first = 0;
+
+ for (f = event->format.fields; f; f = f->next) {
+ if (not_first++)
+ fprintf(ofp, ", ");
+
+ fprintf(ofp, "$%s", f->name);
+ }
+
+ fprintf(ofp, ");\n");
+ fprintf(ofp, "}\n\n");
+ }
+
+ fprintf(ofp, "sub trace_unhandled\n{\n my ($event_name, "
+ "$common_cpu, $common_secs, $common_nsecs, $common_pid, "
+ "$common_comm) = @_;\n\n");
+
+ fprintf(ofp, " print_header($event_name, $common_cpu, "
+ "$common_secs, $common_nsecs, $common_pid, "
+ "$common_comm);\n}\n\n");
+
+ fprintf(ofp, "sub print_header\n{\n"
+ " my ($event_name, $cpu, $secs, $nsecs, $pid, $comm) = @_;\n\n"
+ " printf(\"%%-20s %%5u %%05u.%%09u %%8u %%-20s \", "
+ "$event_name, $cpu, $secs, $nsecs, $pid, $comm);\n}");
+
+ fclose(ofp);
+
+ return 0;
+}
+
struct trace_scripting_operations perl_scripting_ops = {
.start_script = perl_start_script,
.stop_script = perl_stop_script,
.process_event = perl_process_event,
+ .generate_event_handlers = perl_generate_event_handlers,
};

#ifdef NO_LIBPERL
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index f812a8e..582e0eb 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -255,6 +255,7 @@ struct trace_scripting_operations {
int (*stop_script) (void);
void (*process_event) (int cpu, void *data, int size,
unsigned long long nsecs, char *comm);
+ int (*generate_event_handlers) (const char *outfile);
};

extern struct trace_scripting_operations perl_scripting_ops;
--
1.6.4.GIT

2009-10-06 06:15:54

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 7/9] perf trace: Add FIELD_IS_FLAG/SYMBOLIC cases to format_flags

Detects whether a particular field is a 'flag' or 'symbolic' field and
uses that information in the Perl generate_event_handlers()
implementation.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/util/trace-event-parse.c | 17 +++++++++++++++++
tools/perf/util/trace-event-perl.c | 19 +++++++++++++++++--
tools/perf/util/trace-event.h | 2 ++
3 files changed, 36 insertions(+), 2 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index bc482c5..1dbe17f 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -46,6 +46,11 @@ static unsigned long long input_buf_siz;

static int cpus;
static int long_size;
+static int is_flag_field;
+static int is_symbolic_field;
+
+static struct format_field *
+find_any_field(struct event *event, const char *name);

static void init_input_buf(char *buf, unsigned long long size)
{
@@ -1227,6 +1232,16 @@ process_entry(struct event *event __unused, struct print_arg *arg,
arg->type = PRINT_FIELD;
arg->field.name = field;

+ if (is_flag_field) {
+ arg->field.field = find_any_field(event, arg->field.name);
+ arg->field.field->flags |= FIELD_IS_FLAG;
+ is_flag_field = 0;
+ } else if (is_symbolic_field) {
+ arg->field.field = find_any_field(event, arg->field.name);
+ arg->field.field->flags |= FIELD_IS_SYMBOLIC;
+ is_symbolic_field = 0;
+ }
+
type = read_token(&token);
*tok = token;

@@ -1617,9 +1632,11 @@ process_arg_token(struct event *event, struct print_arg *arg,
type = process_entry(event, arg, &token);
} else if (strcmp(token, "__print_flags") == 0) {
free_token(token);
+ is_flag_field = 1;
type = process_flags(event, arg, &token);
} else if (strcmp(token, "__print_symbolic") == 0) {
free_token(token);
+ is_symbolic_field = 1;
type = process_symbols(event, arg, &token);
} else if (strcmp(token, "__get_str") == 0) {
free_token(token);
diff --git a/tools/perf/util/trace-event-perl.c b/tools/perf/util/trace-event-perl.c
index 657b87a..b9fbd7b 100644
--- a/tools/perf/util/trace-event-perl.c
+++ b/tools/perf/util/trace-event-perl.c
@@ -428,7 +428,9 @@ static int perl_generate_event_handlers(const char *outfile)
fprintf(ofp, ", ");

fprintf(ofp, "%s=", f->name);
- if (f->flags & FIELD_IS_STRING)
+ if (f->flags & FIELD_IS_STRING ||
+ f->flags & FIELD_IS_FLAG ||
+ f->flags & FIELD_IS_SYMBOLIC)
fprintf(ofp, "%%s");
else if (f->flags & FIELD_IS_SIGNED)
fprintf(ofp, "%%d");
@@ -444,7 +446,20 @@ static int perl_generate_event_handlers(const char *outfile)
if (not_first++)
fprintf(ofp, ", ");

- fprintf(ofp, "$%s", f->name);
+ if (f->flags & FIELD_IS_FLAG) {
+ fprintf(ofp, "flag_str(\"");
+ fprintf(ofp, "%s::%s\", ", event->system,
+ event->name);
+ fprintf(ofp, "\"%s\", $%s)", f->name,
+ f->name);
+ } else if (f->flags & FIELD_IS_SYMBOLIC) {
+ fprintf(ofp, "symbol_str(\"");
+ fprintf(ofp, "%s::%s\", ", event->system,
+ event->name);
+ fprintf(ofp, "\"%s\", $%s)", f->name,
+ f->name);
+ } else
+ fprintf(ofp, "$%s", f->name);
}

fprintf(ofp, ");\n");
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 582e0eb..dc90b2e 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -29,6 +29,8 @@ enum format_flags {
FIELD_IS_SIGNED = 4,
FIELD_IS_STRING = 8,
FIELD_IS_DYNAMIC = 16,
+ FIELD_IS_FLAG = 32,
+ FIELD_IS_SYMBOLIC = 64,
};

struct format_field {
--
1.6.4.GIT

2009-10-06 06:11:14

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 8/9] perf trace: Add perf trace scripting support modules for Perl

Add Perf-Trace-Util support module and example scripts that use it.
Also adds some makefile bits to install them in
libexec/perf-core/scripts/perl (or wherever perfexec_instdir points).

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/Makefile | 12 ++
tools/perf/scripts/perl/Perf-Trace-Util/Changes | 6 +
tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST | 6 +
.../perf/scripts/perl/Perf-Trace-Util/Makefile.PL | 12 ++
tools/perf/scripts/perl/Perf-Trace-Util/README | 30 ++++
.../perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm | 165 ++++++++++++++++++++
.../perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm | 97 ++++++++++++
.../perl/Perf-Trace-Util/t/Perf-Trace-Util.t | 15 ++
tools/perf/scripts/perl/rw-by-file.pl | 95 +++++++++++
tools/perf/scripts/perl/rw-by-pid.pl | 151 ++++++++++++++++++
tools/perf/scripts/perl/wakeup-latency.pl | 94 +++++++++++
tools/perf/scripts/perl/workqueue-stats.pl | 121 ++++++++++++++
12 files changed, 804 insertions(+), 0 deletions(-)
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/Changes
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/Makefile.PL
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/README
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm
create mode 100644 tools/perf/scripts/perl/Perf-Trace-Util/t/Perf-Trace-Util.t
create mode 100644 tools/perf/scripts/perl/rw-by-file.pl
create mode 100644 tools/perf/scripts/perl/rw-by-pid.pl
create mode 100644 tools/perf/scripts/perl/wakeup-latency.pl
create mode 100644 tools/perf/scripts/perl/workqueue-stats.pl

diff --git a/tools/perf/Makefile b/tools/perf/Makefile
index a443bd3..50b8f64 100644
--- a/tools/perf/Makefile
+++ b/tools/perf/Makefile
@@ -901,6 +901,18 @@ export perfexec_instdir
install: all
$(INSTALL) -d -m 755 '$(DESTDIR_SQ)$(bindir_SQ)'
$(INSTALL) perf$X '$(DESTDIR_SQ)$(bindir_SQ)'
+ $(INSTALL) -d -m 755 '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util/lib/Perf/Trace'
+ $(INSTALL) -d -m 755 '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util/t'
+ $(INSTALL) scripts/perl/Perf-Trace-Util/lib/Perf/Trace/* -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util/lib/Perf/Trace'
+ $(INSTALL) scripts/perl/Perf-Trace-Util/t/* -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util/t'
+ $(INSTALL) scripts/perl/Perf-Trace-Util/Changes -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util'
+ $(INSTALL) scripts/perl/Perf-Trace-Util/Makefile.PL -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util'
+ $(INSTALL) scripts/perl/Perf-Trace-Util/MANIFEST -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util'
+ $(INSTALL) scripts/perl/Perf-Trace-Util/README -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl/Perf-Trace-Util'
+ $(INSTALL) scripts/perl/wakeup-latency.pl -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl'
+ $(INSTALL) scripts/perl/workqueue-stats.pl -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl'
+ $(INSTALL) scripts/perl/rw-by-pid.pl -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl'
+ $(INSTALL) scripts/perl/rw-by-file.pl -t '$(DESTDIR_SQ)$(perfexec_instdir_SQ)/scripts/perl'
ifdef BUILT_INS
$(INSTALL) -d -m 755 '$(DESTDIR_SQ)$(perfexec_instdir_SQ)'
$(INSTALL) $(BUILT_INS) '$(DESTDIR_SQ)$(perfexec_instdir_SQ)'
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/Changes b/tools/perf/scripts/perl/Perf-Trace-Util/Changes
new file mode 100644
index 0000000..3deccab
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/Changes
@@ -0,0 +1,6 @@
+Revision history for Perl extension Perf::Trace::Util.
+
+0.01 Fri Sep 25 12:08:40 2009
+ - original version; created by h2xs 1.23 with options
+ -AXn Perf::Trace::Util
+
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST b/tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST
new file mode 100644
index 0000000..09379e1
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/MANIFEST
@@ -0,0 +1,6 @@
+Changes
+Makefile.PL
+MANIFEST
+README
+t/Perf-Trace-Util.t
+lib/Perf/Trace/Util.pm
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/Makefile.PL b/tools/perf/scripts/perl/Perf-Trace-Util/Makefile.PL
new file mode 100644
index 0000000..b0de02e
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/Makefile.PL
@@ -0,0 +1,12 @@
+use 5.010000;
+use ExtUtils::MakeMaker;
+# See lib/ExtUtils/MakeMaker.pm for details of how to influence
+# the contents of the Makefile that is written.
+WriteMakefile(
+ NAME => 'Perf::Trace::Util',
+ VERSION_FROM => 'lib/Perf/Trace/Util.pm', # finds $VERSION
+ PREREQ_PM => {}, # e.g., Module::Name => 1.1
+ ($] >= 5.005 ? ## Add these new keywords supported since 5.005
+ (ABSTRACT_FROM => 'lib/Perf/Trace/Util.pm', # retrieve abstract from module
+ AUTHOR => 'Tom Zanussi <[email protected]>') : ()),
+);
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/README b/tools/perf/scripts/perl/Perf-Trace-Util/README
new file mode 100644
index 0000000..af1078c
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/README
@@ -0,0 +1,30 @@
+Perf-Trace-Util version 0.01
+============================
+
+This module contains utility functions for use with perf trace.
+
+INSTALLATION
+
+Building perf with perf trace Perl scripting should install this
+module in the right place.
+
+You should make sure libperl is installed first e.g. apt-get install
+libperl-dev.
+
+DEPENDENCIES
+
+This module requires these other modules and libraries:
+
+ blah blah blah
+
+COPYRIGHT AND LICENCE
+
+Put the correct copyright and licence information here.
+
+Copyright (C) 2009 by Tom Zanussi <[email protected]>
+
+This library is free software; you can redistribute it and/or modify
+it under the same terms as Perl itself, either Perl version 5.10.0 or,
+at your option, any later version of Perl 5 you may have available.
+
+
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm b/tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm
new file mode 100644
index 0000000..37b52d3
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Core.pm
@@ -0,0 +1,165 @@
+package Perf::Trace::Core;
+
+use 5.010000;
+use strict;
+use warnings;
+
+require Exporter;
+
+our @ISA = qw(Exporter);
+
+our %EXPORT_TAGS = ( 'all' => [ qw(
+) ] );
+
+our @EXPORT_OK = ( @{ $EXPORT_TAGS{'all'} } );
+
+our @EXPORT = qw(
+define_flag_field define_flag_value flag_str dump_flag_fields
+define_symbolic_field define_symbolic_value symbol_str dump_symbolic_fields
+);
+
+our $VERSION = '0.01';
+
+my %flag_fields;
+my %symbolic_fields;
+
+sub flag_str
+{
+ my ($event_name, $field_name, $value) = @_;
+
+ my $string;
+
+ if ($flag_fields{$event_name}{$field_name}) {
+ my $print_delim = 0;
+ foreach my $idx (sort {$a <=> $b} keys %{$flag_fields{$event_name}{$field_name}{"values"}}) {
+ if (!$value && !$idx) {
+ $string .= "$flag_fields{$event_name}{$field_name}{'values'}{$idx}";
+ last;
+ }
+ if ($idx && ($value & $idx) == $idx) {
+ if ($print_delim && $flag_fields{$event_name}{$field_name}{'delim'}) {
+ $string .= " $flag_fields{$event_name}{$field_name}{'delim'} ";
+ }
+ $string .= "$flag_fields{$event_name}{$field_name}{'values'}{$idx}";
+ $print_delim = 1;
+ $value &= ~$idx;
+ }
+ }
+ }
+
+ return $string;
+}
+
+sub define_flag_field
+{
+ my ($event_name, $field_name, $delim) = @_;
+
+ $flag_fields{$event_name}{$field_name}{"delim"} = $delim;
+}
+
+sub define_flag_value
+{
+ my ($event_name, $field_name, $value, $field_str) = @_;
+
+ $flag_fields{$event_name}{$field_name}{"values"}{$value} = $field_str;
+}
+
+sub dump_flag_fields
+{
+ for my $event (keys %flag_fields) {
+ print "event $event:\n";
+ for my $field (keys %{$flag_fields{$event}}) {
+ print " field: $field:\n";
+ print " delim: $flag_fields{$event}{$field}{'delim'}\n";
+ foreach my $idx (sort {$a <=> $b} keys %{$flag_fields{$event}{$field}{"values"}}) {
+ print " value $idx: $flag_fields{$event}{$field}{'values'}{$idx}\n";
+ }
+ }
+ }
+}
+
+sub symbol_str
+{
+ my ($event_name, $field_name, $value) = @_;
+
+ if ($symbolic_fields{$event_name}{$field_name}) {
+ foreach my $idx (sort {$a <=> $b} keys %{$symbolic_fields{$event_name}{$field_name}{"values"}}) {
+ if (!$value && !$idx) {
+ return "$symbolic_fields{$event_name}{$field_name}{'values'}{$idx}";
+ last;
+ }
+ if ($value == $idx) {
+ return "$symbolic_fields{$event_name}{$field_name}{'values'}{$idx}";
+ }
+ }
+ }
+
+ return undef;
+}
+
+sub define_symbolic_field
+{
+ my ($event_name, $field_name) = @_;
+
+ # nothing to do, really
+}
+
+sub define_symbolic_value
+{
+ my ($event_name, $field_name, $value, $field_str) = @_;
+
+ $symbolic_fields{$event_name}{$field_name}{"values"}{$value} = $field_str;
+}
+
+sub dump_symbolic_fields
+{
+ for my $event (keys %symbolic_fields) {
+ print "event $event:\n";
+ for my $field (keys %{$symbolic_fields{$event}}) {
+ print " field: $field:\n";
+ foreach my $idx (sort {$a <=> $b} keys %{$symbolic_fields{$event}{$field}{"values"}}) {
+ print " value $idx: $symbolic_fields{$event}{$field}{'values'}{$idx}\n";
+ }
+ }
+ }
+}
+
+1;
+__END__
+=head1 NAME
+
+Perf::Trace::Core - Perl extension for perf trace
+
+=head1 SYNOPSIS
+
+ use Perf::Trace::Core
+
+=head1 DESCRIPTION
+
+Core functions for use with perf trace. The define_* functions are
+called by the event-processing loop and shouldn't be called by users.
+All others are user-callable.
+
+=head2 EXPORT
+
+ flag_str - return a string with the string represention of a flag field
+ symbolic_str - return a string with the string represention of a symbol field
+
+=head1 SEE ALSO
+
+Perf (trace) documentation
+
+=head1 AUTHOR
+
+Tom Zanussi, E<lt>[email protected]<gt>
+
+=head1 COPYRIGHT AND LICENSE
+
+Copyright (C) 2009 by Tom Zanussi
+
+This library is free software; you can redistribute it and/or modify
+it under the same terms as Perl itself, either Perl version 5.10.0 or,
+at your option, any later version of Perl 5 you may have available.
+
+
+=cut
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm b/tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm
new file mode 100644
index 0000000..b3037fe
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/lib/Perf/Trace/Util.pm
@@ -0,0 +1,97 @@
+package Perf::Trace::Util;
+
+use 5.010000;
+use strict;
+use warnings;
+
+require Exporter;
+
+our @ISA = qw(Exporter);
+
+our %EXPORT_TAGS = ( 'all' => [ qw(
+) ] );
+
+our @EXPORT_OK = ( @{ $EXPORT_TAGS{'all'} } );
+
+our @EXPORT = qw(
+avg nsecs nsecs_secs nsecs_nsecs nsecs_usecs print_nsecs
+);
+
+our $VERSION = '0.01';
+
+sub avg
+{
+ my ($total, $n) = @_;
+
+ return $total / $n;
+}
+
+my $NSECS_PER_SEC = 1000000000;
+
+sub nsecs
+{
+ my ($secs, $nsecs) = @_;
+
+ return $secs * $NSECS_PER_SEC + $nsecs;
+}
+
+sub nsecs_secs {
+ my ($nsecs) = @_;
+
+ return $nsecs / $NSECS_PER_SEC;
+}
+
+sub nsecs_nsecs {
+ my ($nsecs) = @_;
+
+ return $nsecs - nsecs_secs($nsecs);
+}
+
+sub nsecs_str {
+ my ($nsecs) = @_;
+
+ my $str = sprintf("%5u.%09u", nsecs_secs($nsecs), nsecs_nsecs($nsecs));
+
+ return $str;
+}
+
+1;
+__END__
+=head1 NAME
+
+Perf::Trace::Util - Perl extension for perf trace
+
+=head1 SYNOPSIS
+
+ use Perf::Trace::Util;
+
+=head1 DESCRIPTION
+
+Utility functions for use with perf trace.
+
+=head2 EXPORT
+
+ nsecs - return total nsecs given secs/nsecs pair
+ nsecs_secs - return whole secs portion given nsecs
+ nsecs_nsecs - return nsecs remainder given nsecs
+ nsecs_str - return printable string in the form secs.nsecs
+ avg - return average given a sum and a total number of values
+
+=head1 SEE ALSO
+
+Perf (trace) documentation
+
+=head1 AUTHOR
+
+Tom Zanussi, E<lt>[email protected]<gt>
+
+=head1 COPYRIGHT AND LICENSE
+
+Copyright (C) 2009 by Tom Zanussi
+
+This library is free software; you can redistribute it and/or modify
+it under the same terms as Perl itself, either Perl version 5.10.0 or,
+at your option, any later version of Perl 5 you may have available.
+
+
+=cut
diff --git a/tools/perf/scripts/perl/Perf-Trace-Util/t/Perf-Trace-Util.t b/tools/perf/scripts/perl/Perf-Trace-Util/t/Perf-Trace-Util.t
new file mode 100644
index 0000000..8166a8c
--- /dev/null
+++ b/tools/perf/scripts/perl/Perf-Trace-Util/t/Perf-Trace-Util.t
@@ -0,0 +1,15 @@
+# Before `make install' is performed this script should be runnable with
+# `make test'. After `make install' it should work as `perl Perf-Trace-Util.t'
+
+#########################
+
+# change 'tests => 1' to 'tests => last_test_to_print';
+
+use Test::More tests => 1;
+BEGIN { use_ok('Perf::Trace::Util') };
+
+#########################
+
+# Insert your test code below, the Test::More module is use()ed here so read
+# its man page ( perldoc Test::More ) for help writing this test script.
+
diff --git a/tools/perf/scripts/perl/rw-by-file.pl b/tools/perf/scripts/perl/rw-by-file.pl
new file mode 100644
index 0000000..2bf0d0d
--- /dev/null
+++ b/tools/perf/scripts/perl/rw-by-file.pl
@@ -0,0 +1,95 @@
+# Display r/w activity for files read/written to for a given program
+
+# The common_* event handler fields are the most useful fields common to
+# all events. They don't necessarily correspond to the 'common_*' fields
+# in the status files. Those fields not available as handler params can
+# be retrieved via script functions of the form get_common_*().
+
+use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
+use lib "./Perf-Trace-Util/lib";
+use Perf::Trace::Core;
+use Perf::Trace::Util;
+
+# change this to the comm of the program you're interested in
+my $for_comm = "perf";
+
+my %reads;
+my %writes;
+
+sub syscalls::sys_enter_read
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs,
+ $common_pid, $common_comm, $nr, $fd, $buf, $count) = @_;
+
+ if ($common_comm == $for_comm) {
+ $reads{$fd}{bytes_requested} += $count;
+ $reads{$fd}{total_reads}++;
+ }
+}
+
+sub syscalls::sys_enter_write
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs,
+ $common_pid, $common_comm, $nr, $fd, $buf, $count) = @_;
+
+ if ($common_comm == $for_comm) {
+ $writes{$fd}{bytes_written} += $count;
+ $writes{$fd}{total_writes}++;
+ }
+}
+
+sub trace_end
+{
+ printf("file read counts for $for_comm:\n\n");
+
+ printf("%6s %10s %10s\n", "fd", "# reads", "bytes_requested");
+ printf("%6s %10s %10s\n", "------", "----------", "-----------");
+
+ foreach my $fd (sort {$reads{$b}{bytes_requested} <=> $reads{$a}{bytes_requested}} keys %reads) {
+ my $total_reads = $reads{$fd}{total_reads};
+ my $bytes_requested = $reads{$fd}{bytes_requested};
+ printf("%6u %10u %10u\n", $fd, $total_reads, $bytes_requested);
+ }
+
+ printf("\nfile write counts for $for_comm:\n\n");
+
+ printf("%6s %10s %10s\n", "fd", "# writes", "bytes_written");
+ printf("%6s %10s %10s\n", "------", "----------", "-----------");
+
+ foreach my $fd (sort {$writes{$b}{bytes_written} <=> $writes{$a}{bytes_written}} keys %writes) {
+ my $total_writes = $writes{$fd}{total_writes};
+ my $bytes_written = $writes{$fd}{bytes_written};
+ printf("%6u %10u %10u\n", $fd, $total_writes, $bytes_written);
+ }
+
+ print_unhandled();
+}
+
+my %unhandled;
+
+sub print_unhandled
+{
+ if ((scalar keys %unhandled) == 0) {
+ return;
+ }
+
+ print "\nunhandled events:\n\n";
+
+ printf("%-40s %10s\n", "event", "count");
+ printf("%-40s %10s\n", "----------------------------------------",
+ "-----------");
+
+ foreach my $event_name (keys %unhandled) {
+ printf("%-40s %10d\n", $event_name, $unhandled{$event_name});
+ }
+}
+
+sub trace_unhandled
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm) = @_;
+
+ $unhandled{$event_name}++;
+}
+
+
diff --git a/tools/perf/scripts/perl/rw-by-pid.pl b/tools/perf/scripts/perl/rw-by-pid.pl
new file mode 100644
index 0000000..ea7afe8
--- /dev/null
+++ b/tools/perf/scripts/perl/rw-by-pid.pl
@@ -0,0 +1,151 @@
+# Display r/w activity for all processes
+
+# The common_* event handler fields are the most useful fields common to
+# all events. They don't necessarily correspond to the 'common_*' fields
+# in the status files. Those fields not available as handler params can
+# be retrieved via script functions of the form get_common_*().
+
+use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
+use lib "./Perf-Trace-Util/lib";
+use Perf::Trace::Core;
+use Perf::Trace::Util;
+
+my %reads;
+my %writes;
+
+sub syscalls::sys_exit_read
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid, $common_comm,
+ $nr, $ret) = @_;
+
+ if ($ret > 0) {
+ $reads{$common_pid}{bytes_read} += $ret;
+ } else {
+ $reads{$common_pid}{errors}{$ret}++;
+ }
+}
+
+sub syscalls::sys_enter_read
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid, $common_comm,
+ $nr, $fd, $buf, $count) = @_;
+
+ $reads{$common_pid}{bytes_requested} += $count;
+ $reads{$common_pid}{total_reads}++;
+ $reads{$common_pid}{comm} = $common_comm;
+}
+
+sub syscalls::sys_exit_write
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid, $common_comm,
+ $nr, $ret) = @_;
+
+ if ($ret <= 0) {
+ $writes{$common_pid}{errors}{$ret}++;
+ }
+}
+
+sub syscalls::sys_enter_write
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid, $common_comm,
+ $nr, $fd, $buf, $count) = @_;
+
+ $writes{$common_pid}{bytes_written} += $count;
+ $writes{$common_pid}{total_writes}++;
+ $writes{$common_pid}{comm} = $common_comm;
+}
+
+sub trace_end
+{
+ printf("read counts by pid:\n\n");
+
+ printf("%6s %20s %10s %10s %10s\n", "pid", "comm",
+ "# reads", "bytes_requested", "bytes_read");
+ printf("%6s %-20s %10s %10s %10s\n", "------", "--------------------",
+ "-----------", "----------", "----------");
+
+ foreach my $pid (sort {$reads{$b}{bytes_read} <=> $reads{$a}{bytes_read}} keys %reads) {
+ my $comm = $reads{$pid}{comm};
+ my $total_reads = $reads{$pid}{total_reads};
+ my $bytes_requested = $reads{$pid}{bytes_requested};
+ my $bytes_read = $reads{$pid}{bytes_read};
+
+ printf("%6s %-20s %10s %10s %10s\n", $pid, $comm,
+ $total_reads, $bytes_requested, $bytes_read);
+ }
+
+ printf("\nfailed reads by pid:\n\n");
+
+ printf("%6s %20s %6s %10s\n", "pid", "comm", "error #", "# errors");
+ printf("%6s %20s %6s %10s\n", "------", "--------------------",
+ "------", "----------");
+
+ foreach my $pid (keys %reads) {
+ my $comm = $reads{$pid}{comm};
+ foreach my $err (sort {$reads{$b}{comm} cmp $reads{$a}{comm}} keys %{$reads{$pid}{errors}}) {
+ my $errors = $reads{$pid}{errors}{$err};
+
+ printf("%6d %-20s %6d %10s\n", $pid, $comm, $err, $errors);
+ }
+ }
+
+ printf("\nwrite counts by pid:\n\n");
+
+ printf("%6s %20s %10s %10s %10s\n", "pid", "comm",
+ "# writes", "bytes_written");
+ printf("%6s %-20s %10s %10s %10s\n", "------", "--------------------",
+ "-----------", "----------");
+
+ foreach my $pid (sort {$writes{$b}{bytes_written} <=> $writes{$a}{bytes_written}} keys %writes) {
+ my $comm = $writes{$pid}{comm};
+ my $total_writes = $writes{$pid}{total_writes};
+ my $bytes_written = $writes{$pid}{bytes_written};
+
+ printf("%6s %-20s %10s %10s\n", $pid, $comm,
+ $total_writes, $bytes_written);
+ }
+
+ printf("\nfailed writes by pid:\n\n");
+
+ printf("%6s %20s %6s %10s\n", "pid", "comm", "error #", "# errors");
+ printf("%6s %20s %6s %10s\n", "------", "--------------------",
+ "------", "----------");
+
+ foreach my $pid (keys %writes) {
+ my $comm = $writes{$pid}{comm};
+ foreach my $err (sort {$writes{$b}{comm} cmp $writes{$a}{comm}} keys %{$writes{$pid}{errors}}) {
+ my $errors = $writes{$pid}{errors}{$err};
+
+ printf("%6d %-20s %6d %10s\n", $pid, $comm, $err, $errors);
+ }
+ }
+
+ print_unhandled();
+}
+
+my %unhandled;
+
+sub print_unhandled
+{
+ if ((scalar keys %unhandled) == 0) {
+ return;
+ }
+
+ print "\nunhandled events:\n\n";
+
+ printf("%-40s %10s\n", "event", "count");
+ printf("%-40s %10s\n", "----------------------------------------",
+ "-----------");
+
+ foreach my $event_name (keys %unhandled) {
+ printf("%-40s %10d\n", $event_name, $unhandled{$event_name});
+ }
+}
+
+sub trace_unhandled
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm) = @_;
+
+ $unhandled{$event_name}++;
+}
diff --git a/tools/perf/scripts/perl/wakeup-latency.pl b/tools/perf/scripts/perl/wakeup-latency.pl
new file mode 100644
index 0000000..34011ff
--- /dev/null
+++ b/tools/perf/scripts/perl/wakeup-latency.pl
@@ -0,0 +1,94 @@
+# Display avg/min/max wakeup latency
+
+# The common_* event handler fields are the most useful fields common to
+# all events. They don't necessarily correspond to the 'common_*' fields
+# in the status files. Those fields not available as handler params can
+# be retrieved via script functions of the form get_common_*().
+
+use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
+use lib "./Perf-Trace-Util/lib";
+use Perf::Trace::Core;
+use Perf::Trace::Util;
+
+my %last_wakeup;
+
+my $max_wakeup_latency;
+my $min_wakeup_latency;
+my $total_wakeup_latency;
+my $total_wakeups;
+
+sub sched::sched_switch
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm,
+ $prev_comm, $prev_pid, $prev_prio, $prev_state, $next_comm, $next_pid,
+ $next_prio) = @_;
+
+ my $wakeup_ts = $last_wakeup{$common_cpu}{ts};
+ if ($wakeup_ts) {
+ my $switch_ts = nsecs($common_secs, $common_nsecs);
+ my $wakeup_latency = $switch_ts - $wakeup_ts;
+ if ($wakeup_latency > $max_wakeup_latency) {
+ $max_wakeup_latency = $wakeup_latency;
+ }
+ if ($wakeup_latency < $min_wakeup_latency) {
+ $min_wakeup_latency = $wakeup_latency;
+ }
+ $total_wakeup_latency += $wakeup_latency;
+ $total_wakeups++;
+ }
+ $last_wakeup{$common_cpu}{ts} = 0;
+}
+
+sub sched::sched_wakeup
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm,
+ $comm, $pid, $prio, $success, $cpu) = @_;
+
+ $last_wakeup{$cpu}{ts} = nsecs($common_secs, $common_nsecs);
+}
+
+sub trace_begin
+{
+ $min_wakeup_latency = 1000000000;
+}
+
+sub trace_end
+{
+ printf("wakeup_latency stats:\n\n");
+ print "total_wakeups: $total_wakeups\n";
+ printf("avg_wakeup_latency (ns): %u\n",
+ avg($total_wakeup_latency, $total_wakeups));
+ printf("min_wakeup_latency (ns): %u\n", $min_wakeup_latency);
+ printf("max_wakeup_latency (ns): %u\n", $max_wakeup_latency);
+
+ print_unhandled();
+}
+
+my %unhandled;
+
+sub print_unhandled
+{
+ if ((scalar keys %unhandled) == 0) {
+ return;
+ }
+
+ print "\nunhandled events:\n\n";
+
+ printf("%-40s %10s\n", "event", "count");
+ printf("%-40s %10s\n", "----------------------------------------",
+ "-----------");
+
+ foreach my $event_name (keys %unhandled) {
+ printf("%-40s %10d\n", $event_name, $unhandled{$event_name});
+ }
+}
+
+sub trace_unhandled
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm) = @_;
+
+ $unhandled{$event_name}++;
+}
diff --git a/tools/perf/scripts/perl/workqueue-stats.pl b/tools/perf/scripts/perl/workqueue-stats.pl
new file mode 100644
index 0000000..45e7a26
--- /dev/null
+++ b/tools/perf/scripts/perl/workqueue-stats.pl
@@ -0,0 +1,121 @@
+# Displays workqueue stats
+#
+# Usage:
+#
+# perf record -c 1 -f -a -R -e workqueue:workqueue_creation -e
+# workqueue:workqueue_destruction -e workqueue:workqueue_execution
+# -e workqueue:workqueue_insertion
+#
+# perf trace -p -s tools/perf/scripts/perl/workqueue-stats.pl
+
+use lib "$ENV{'PERF_EXEC_PATH'}/scripts/perl/Perf-Trace-Util/lib";
+use lib "./Perf-Trace-Util/lib";
+use Perf::Trace::Core;
+use Perf::Trace::Util;
+
+my @cpus;
+
+sub workqueue::workqueue_destruction
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm,
+ $thread_comm, $thread_pid) = @_;
+
+ $cpus[$common_cpu]{$thread_pid}{destroyed}++;
+ $cpus[$common_cpu]{$thread_pid}{comm} = $thread_comm;
+}
+
+sub workqueue::workqueue_creation
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm,
+ $thread_comm, $thread_pid, $cpu) = @_;
+
+ $cpus[$common_cpu]{$thread_pid}{created}++;
+ $cpus[$common_cpu]{$thread_pid}{comm} = $thread_comm;
+}
+
+sub workqueue::workqueue_execution
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm,
+ $thread_comm, $thread_pid, $func) = @_;
+
+ $cpus[$common_cpu]{$thread_pid}{executed}++;
+ $cpus[$common_cpu]{$thread_pid}{comm} = $thread_comm;
+}
+
+sub workqueue::workqueue_insertion
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm,
+ $thread_comm, $thread_pid, $func) = @_;
+
+ $cpus[$common_cpu]{$thread_pid}{inserted}++;
+ $cpus[$common_cpu]{$thread_pid}{comm} = $thread_comm;
+}
+
+sub trace_end
+{
+ print "workqueue work stats:\n\n";
+ my $cpu = 0;
+ printf("%3s %6s %6s\t%-20s\n", "cpu", "ins", "exec", "name");
+ printf("%3s %6s %6s\t%-20s\n", "---", "---", "----", "----");
+ foreach $pidhash (@cpus) {
+ while (($pid, $wqhash) = each %$pidhash) {
+ my $ins = $$wqhash{'inserted'};
+ my $exe = $$wqhash{'executed'};
+ my $comm = $$wqhash{'comm'};
+ if ($ins || $exe) {
+ printf("%3u %6u %6u\t%-20s\n", $cpu, $ins, $exe, $comm);
+ }
+ }
+ $cpu++;
+ }
+
+ $cpu = 0;
+ print "\nworkqueue lifecycle stats:\n\n";
+ printf("%3s %6s %6s\t%-20s\n", "cpu", "created", "destroyed", "name");
+ printf("%3s %6s %6s\t%-20s\n", "---", "-------", "---------", "----");
+ foreach $pidhash (@cpus) {
+ while (($pid, $wqhash) = each %$pidhash) {
+ my $created = $$wqhash{'created'};
+ my $destroyed = $$wqhash{'destroyed'};
+ my $comm = $$wqhash{'comm'};
+ if ($created || $destroyed) {
+ printf("%3u %6u %6u\t%-20s\n", $cpu, $created, $destroyed,
+ $comm);
+ }
+ }
+ $cpu++;
+ }
+
+ print_unhandled();
+}
+
+my %unhandled;
+
+sub print_unhandled
+{
+ if ((scalar keys %unhandled) == 0) {
+ return;
+ }
+
+ print "\nunhandled events:\n\n";
+
+ printf("%-40s %10s\n", "event", "count");
+ printf("%-40s %10s\n", "----------------------------------------",
+ "-----------");
+
+ foreach my $event_name (keys %unhandled) {
+ printf("%-40s %10d\n", $event_name, $unhandled{$event_name});
+ }
+}
+
+sub trace_unhandled
+{
+ my ($event_name, $common_cpu, $common_secs, $common_nsecs, $common_pid,
+ $common_comm) = @_;
+
+ $unhandled{$event_name}++;
+}
--
1.6.4.GIT

2009-10-06 06:10:56

by Tom Zanussi

[permalink] [raw]
Subject: [RFC][PATCH 9/9] perf trace: Add throwaway timestamp sorting

Ugly, stupid, non-scaleable code for sorting the perf trace input.
Hopefully it will soon be replaced by something better but for now
it's needed for script processing since most scripts like to process
events in the same order they occurred. Non-scripted perf trace
processing still uses the old unsorted path.

Signed-off-by: Tom Zanussi <[email protected]>
---
tools/perf/builtin-trace.c | 525 +++++++++++++++++++++++++++++++++++++++++++-
1 files changed, 524 insertions(+), 1 deletions(-)

diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index b151e77..e539292 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -20,6 +20,7 @@ static unsigned long mmap_window = 32;

static unsigned long total = 0;
static unsigned long total_comm = 0;
+static unsigned long total_sample = 0;

static struct rb_root threads;
static struct thread *last_match;
@@ -32,6 +33,10 @@ static char const *script_name;
static int do_perl;
static int generate_handlers;

+static unsigned long outbuf_head;
+static event_t **sorted_events;
+static int sorted_idx;
+
static int default_start_script(const char *script __attribute((unused)))
{
return 0;
@@ -167,6 +172,513 @@ process_event(event_t *event, unsigned long offset, unsigned long head)
return 0;
}

+static int
+count_event(event_t *event)
+{
+ switch (event->header.type) {
+ case PERF_RECORD_MMAP ... PERF_RECORD_LOST:
+ return 0;
+
+ case PERF_RECORD_COMM:
+ total_comm++;
+ return 0;
+
+ case PERF_RECORD_EXIT ... PERF_RECORD_READ:
+ return 0;
+
+ case PERF_RECORD_SAMPLE:
+ total_sample++;
+ return 0;
+
+ case PERF_RECORD_MAX:
+ default:
+ return -1;
+ }
+
+ return 0;
+}
+
+static int count_events(void)
+{
+ int ret, rc = EXIT_FAILURE;
+ unsigned long offset = 0;
+ unsigned long head = 0;
+ struct stat perf_stat;
+ event_t *event;
+ uint32_t size;
+ char *buf;
+
+ trace_report();
+
+ input = open(input_name, O_RDONLY);
+ if (input < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ ret = fstat(input, &perf_stat);
+ if (ret < 0) {
+ perror("failed to stat file");
+ exit(-1);
+ }
+
+ if (!perf_stat.st_size) {
+ fprintf(stderr, "zero-sized file, nothing to do!\n");
+ exit(0);
+ }
+ header = perf_header__read(input);
+ head = header->data_offset;
+ sample_type = perf_header__sample_type(header);
+
+ if (!(sample_type & PERF_SAMPLE_RAW))
+ die("No trace sample to read. Did you call perf record "
+ "without -R?");
+
+remap:
+ buf = (char *)mmap(NULL, page_size * mmap_window, PROT_READ,
+ MAP_SHARED, input, offset);
+ if (buf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+
+more:
+ event = (event_t *)(buf + head);
+
+ if (head + event->header.size >= page_size * mmap_window) {
+ unsigned long shift = page_size * (head / page_size);
+ int res;
+
+ res = munmap(buf, page_size * mmap_window);
+ assert(res == 0);
+
+ offset += shift;
+ head -= shift;
+ goto remap;
+ }
+
+ size = event->header.size;
+
+ if (!size || count_event(event) < 0) {
+
+ /*
+ * assume we lost track of the stream, check alignment, and
+ * increment a single u64 in the hope to catch on again 'soon'.
+ */
+
+ if (unlikely(head & 7))
+ head &= ~7ULL;
+
+ size = 8;
+ }
+
+ head += size;
+
+ if (offset + head < (unsigned long)perf_stat.st_size)
+ goto more;
+
+ rc = EXIT_SUCCESS;
+ close(input);
+
+ return rc;
+}
+
+static int copy_header(void)
+{
+ int ret, rc = EXIT_FAILURE;
+ unsigned long head = 0;
+ struct stat perf_stat;
+ char *buf, *outbuf;
+ int output;
+ int res;
+
+ trace_report();
+
+ input = open(input_name, O_RDONLY);
+ if (input < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ ret = fstat(input, &perf_stat);
+ if (ret < 0) {
+ perror("failed to stat file");
+ exit(-1);
+ }
+
+ if (!perf_stat.st_size) {
+ fprintf(stderr, "zero-sized file, nothing to do!\n");
+ exit(0);
+ }
+ header = perf_header__read(input);
+ head = header->data_offset;
+
+ buf = (char *)mmap(NULL, perf_stat.st_size, PROT_READ,
+ MAP_SHARED, input, 0);
+ if (buf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+
+ output = open("perf.data.tmp",
+ O_RDWR | O_CREAT | O_TRUNC | O_LARGEFILE, 0644);
+ if (output < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ if (ftruncate(output, head) < 0) {
+ perror("failed to truncate file");
+ exit(-1);
+ }
+
+ outbuf = (char *)mmap(NULL, head, PROT_WRITE,
+ MAP_SHARED, output, 0);
+ if (outbuf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+
+ memcpy(outbuf, buf, head);
+
+ res = munmap(buf, perf_stat.st_size);
+ assert(res == 0);
+
+ res = munmap(outbuf, head);
+ assert(res == 0);
+
+ close(input);
+ close(output);
+
+ return rc;
+}
+
+static int
+copy_comm_event(char *outbuf, event_t *event, int size)
+{
+ switch (event->header.type) {
+ case PERF_RECORD_MMAP ... PERF_RECORD_LOST:
+ return 0;
+
+ case PERF_RECORD_COMM:
+ memcpy(outbuf, event, size);
+ outbuf_head += size;
+ return 0;
+
+ case PERF_RECORD_EXIT ... PERF_RECORD_READ:
+ return 0;
+
+ case PERF_RECORD_SAMPLE:
+ return 0;
+
+ case PERF_RECORD_MAX:
+ default:
+ return -1;
+ }
+
+ return 0;
+}
+
+static int copy_comm_events(void)
+{
+ struct stat perf_stat, output_perf_stat;
+ int ret, rc = EXIT_FAILURE;
+ unsigned long offset = 0;
+ unsigned long head = 0;
+ char *buf, *outbuf;
+ event_t *event;
+ uint32_t size;
+ int output;
+ int res;
+
+ trace_report();
+
+ input = open(input_name, O_RDONLY);
+ if (input < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ ret = fstat(input, &perf_stat);
+ if (ret < 0) {
+ perror("failed to stat file");
+ exit(-1);
+ }
+
+ if (!perf_stat.st_size) {
+ fprintf(stderr, "zero-sized file, nothing to do!\n");
+ exit(0);
+ }
+
+ header = perf_header__read(input);
+ head = header->data_offset;
+ sample_type = perf_header__sample_type(header);
+
+ output = open("perf.data.tmp",
+ O_RDWR | O_APPEND | O_LARGEFILE, 0644);
+ if (output < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ ret = fstat(output, &output_perf_stat);
+ if (ret < 0) {
+ perror("failed to stat file");
+ exit(-1);
+ }
+
+ if (!output_perf_stat.st_size) {
+ fprintf(stderr, "zero-sized file, nothing to do!\n");
+ exit(0);
+ }
+
+ if (ftruncate(output, perf_stat.st_size) < 0) {
+ perror("failed to truncate file");
+ exit(-1);
+ }
+
+ outbuf = (char *)mmap(NULL, perf_stat.st_size, PROT_WRITE,
+ MAP_SHARED, output, 0);
+ if (outbuf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+ outbuf_head = output_perf_stat.st_size;
+
+remap:
+ buf = (char *)mmap(NULL, page_size * mmap_window, PROT_READ,
+ MAP_SHARED, input, offset);
+ if (buf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+
+more:
+ event = (event_t *)(buf + head);
+
+ if (head + event->header.size >= page_size * mmap_window) {
+ unsigned long shift = page_size * (head / page_size);
+
+ res = munmap(buf, page_size * mmap_window);
+ assert(res == 0);
+
+ offset += shift;
+ head -= shift;
+ goto remap;
+ }
+
+ size = event->header.size;
+
+ if (!size || copy_comm_event(outbuf + outbuf_head, event, size) < 0) {
+
+ /*
+ * assume we lost track of the stream, check alignment, and
+ * increment a single u64 in the hope to catch on again 'soon'.
+ */
+
+ if (unlikely(head & 7))
+ head &= ~7ULL;
+
+ size = 8;
+ }
+
+ head += size;
+
+ if (offset + head < (unsigned long)perf_stat.st_size)
+ goto more;
+
+ rc = EXIT_SUCCESS;
+ close(input);
+
+ res = munmap(outbuf, head);
+ assert(res == 0);
+
+ if (ftruncate(output, output_perf_stat.st_size + outbuf_head) < 0) {
+ perror("failed to truncate file");
+ exit(-1);
+ }
+
+ close(output);
+
+ return rc;
+}
+
+static int
+save_sort_event(event_t *event)
+{
+ switch (event->header.type) {
+ case PERF_RECORD_MMAP ... PERF_RECORD_LOST:
+ return 0;
+
+ case PERF_RECORD_COMM:
+ return 0;
+
+ case PERF_RECORD_EXIT ... PERF_RECORD_READ:
+ return 0;
+
+ case PERF_RECORD_SAMPLE:
+ sorted_events[sorted_idx++] = event;
+ return 0;
+
+ case PERF_RECORD_MAX:
+ default:
+ return -1;
+ }
+
+ return 0;
+}
+
+static int event_cmp(const void *a, const void *b)
+{
+ const event_t **pa = (const event_t **)a;
+ const event_t **pb = (const event_t **)b;
+ const event_t *eventa = *pa;
+ const event_t *eventb = *pb;
+ const void *more_data;
+ u64 timea, timeb;
+
+ more_data = eventa->ip.__more_data;
+ timea = *(u64 *)more_data;
+
+ more_data = eventb->ip.__more_data;
+ timeb = *(u64 *)more_data;
+
+ if (timea < timeb)
+ return -1;
+ if (timea > timeb)
+ return 1;
+
+ return 0;
+}
+
+static int sort_sample_events(void)
+{
+ struct stat perf_stat, output_perf_stat;
+ int ret, rc = EXIT_FAILURE;
+ unsigned long offset = 0;
+ unsigned long head = 0;
+ char *buf, *outbuf;
+ event_t *event;
+ uint32_t size;
+ int output;
+ int res;
+ unsigned i;
+
+ sorted_events = malloc(total_sample * sizeof(event_t *));
+ if (!sorted_events) {
+ perror("failed to malloc sample array");
+ exit(-1);
+ }
+
+ trace_report();
+
+ input = open(input_name, O_RDONLY);
+ if (input < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ ret = fstat(input, &perf_stat);
+ if (ret < 0) {
+ perror("failed to stat file");
+ exit(-1);
+ }
+
+ if (!perf_stat.st_size) {
+ fprintf(stderr, "zero-sized file, nothing to do!\n");
+ exit(0);
+ }
+
+ header = perf_header__read(input);
+ head = header->data_offset;
+ sample_type = perf_header__sample_type(header);
+
+ buf = (char *)mmap(NULL, perf_stat.st_size, PROT_READ,
+ MAP_SHARED, input, 0);
+ if (buf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+
+more:
+ event = (event_t *)(buf + head);
+
+ size = event->header.size;
+
+ if (!size || save_sort_event(event) < 0) {
+
+ /*
+ * assume we lost track of the stream, check alignment, and
+ * increment a single u64 in the hope to catch on again 'soon'.
+ */
+
+ if (unlikely(head & 7))
+ head &= ~7ULL;
+
+ size = 8;
+ }
+
+ head += size;
+
+ if (offset + head < (unsigned long)perf_stat.st_size)
+ goto more;
+
+ rc = EXIT_SUCCESS;
+ close(input);
+
+ qsort(sorted_events, total_sample, sizeof(event_t *), event_cmp);
+
+ output = open("perf.data.tmp",
+ O_RDWR | O_APPEND | O_LARGEFILE, 0644);
+ if (output < 0) {
+ perror("failed to open file");
+ exit(-1);
+ }
+
+ ret = fstat(output, &output_perf_stat);
+ if (ret < 0) {
+ perror("failed to stat file");
+ exit(-1);
+ }
+
+ if (!output_perf_stat.st_size) {
+ fprintf(stderr, "zero-sized file, nothing to do!\n");
+ exit(0);
+ }
+
+ if (ftruncate(output, perf_stat.st_size) < 0) {
+ perror("failed to truncate file");
+ exit(-1);
+ }
+
+ outbuf = (char *)mmap(NULL, perf_stat.st_size, PROT_WRITE,
+ MAP_SHARED, output, 0);
+ if (outbuf == MAP_FAILED) {
+ perror("failed to mmap file");
+ exit(-1);
+ }
+ outbuf_head = output_perf_stat.st_size;
+
+ for (i = 0; i < total_sample; i++) {
+ event = sorted_events[i];
+ memcpy(outbuf + outbuf_head, sorted_events[i],
+ event->header.size);
+ outbuf_head += event->header.size;
+ }
+
+ res = munmap(outbuf, head);
+ assert(res == 0);
+
+ if (ftruncate(output, output_perf_stat.st_size + outbuf_head) < 0) {
+ perror("failed to truncate file");
+ exit(-1);
+ }
+
+ close(output);
+
+ return rc;
+}
+
static int __cmd_trace(void)
{
int ret, rc = EXIT_FAILURE;
@@ -180,7 +692,11 @@ static int __cmd_trace(void)
trace_report();
register_idle_thread(&threads, &last_match);

- input = open(input_name, O_RDONLY);
+ if (script_name)
+ input = open("perf.data.tmp", O_RDONLY);
+ else
+ input = open(input_name, O_RDONLY);
+
if (input < 0) {
perror("failed to open file");
exit(-1);
@@ -334,10 +850,17 @@ int cmd_trace(int argc, const char **argv, const char *prefix __used)
err = scripting_ops->start_script(script_name);
if (err)
goto out;
+
+ count_events();
+ copy_header();
+ copy_comm_events();
+ sort_sample_events();
}

err = __cmd_trace();

+ unlink("perf.data.tmp");
+
cleanup_scripting();
out:
return err;
--
1.6.4.GIT

2009-10-06 09:10:46

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting


* Tom Zanussi <[email protected]> wrote:

> Known problems/shortcomings:
>
> Probably the biggest problem right now is the sorting hack I added as
> the last patch. It's just meant as a temporary thing, but is there
> because tracing scripts in general want to see events in the order
> they happened i.e. timestamp order. [...]

Btw., have you seen the -M/--multiplex option to perf record? It
multiplexes all events into a single buffer - making them all ordered.
(The events are in causal ordering in this case even if there's some TSC
asynchronity)

Ingo

2009-10-06 09:41:16

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting

2009/10/6 Tom Zanussi <[email protected]>:
> Hi,
>
> This patchset defines a generic interface for processing the binary
> output of 'perf trace' and making it directly available to
> user-defined scripts written in general-purpose scripting languages
> such as Perl or Python. ?It also builds a general-purpose Perl
> scripting trace processor on top of the new interface and provides a
> few example scripts that exercise the basic functionality.
>
> The main motivation behind it is to provide a more efficient and
> powerful alternative to the popular method of parsing the ascii trace
> output in order to extract useful information from it. ?To avoid the
> overhead and complexity of all that, this patchset provides a
> direct-to-script-interpreter pathway for doing the same thing, but in
> a more regularized fashion, one that takes advantage of all the event
> meta-info provided by the tracing infrustructure, such as the
> event/field info contained in the 'format files' designed for that
> purpose.


That's really a great thing! I was also hesitating to implement a
python interface to perf in
order to quickly plug post processing tools. But your patchset does
that in a much more
generic way that I imagined: we can support other languages, we have
well defined
callbacks to process the events...

Really nice, I hope we can give it a try in -tip soon.

2009-10-06 12:40:36

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 8/9] perf trace: Add perf trace scripting support modules for Perl


* Tom Zanussi <[email protected]> wrote:

> --- /dev/null
> +++ b/tools/perf/scripts/perl/Perf-Trace-Util/Changes
> @@ -0,0 +1,6 @@
> +Revision history for Perl extension Perf::Trace::Util.
> +
> +0.01 Fri Sep 25 12:08:40 2009
> + - original version; created by h2xs 1.23 with options
> + -AXn Perf::Trace::Util
> +

is this needed? We have Git history which is far more flexible than
in-source changelogs.

Ingo

2009-10-06 12:46:41

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 8/9] perf trace: Add perf trace scripting support modules for Perl


* Tom Zanussi <[email protected]> wrote:

> +++ b/tools/perf/scripts/perl/Perf-Trace-Util/README
> @@ -0,0 +1,30 @@
> +Perf-Trace-Util version 0.01
> +============================
> +
> +This module contains utility functions for use with perf trace.
> +
> +INSTALLATION
> +
> +Building perf with perf trace Perl scripting should install this
> +module in the right place.
> +
> +You should make sure libperl is installed first e.g. apt-get install
> +libperl-dev.
> +
> +DEPENDENCIES
> +
> +This module requires these other modules and libraries:
> +
> + blah blah blah

Some fixing needed here i guess ;-)

> +COPYRIGHT AND LICENCE
> +
> +Put the correct copyright and licence information here.
> +
> +Copyright (C) 2009 by Tom Zanussi <[email protected]>
> +
> +This library is free software; you can redistribute it and/or modify
> +it under the same terms as Perl itself, either Perl version 5.10.0 or,
> +at your option, any later version of Perl 5 you may have available.

Would be nice to dual license it to the kernel (GPLv2) as well.

Ingo

2009-10-06 12:55:11

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting


* Fr?d?ric Weisbecker <[email protected]> wrote:

> 2009/10/6 Tom Zanussi <[email protected]>:
> > Hi,
> >
> > This patchset defines a generic interface for processing the binary
> > output of 'perf trace' and making it directly available to
> > user-defined scripts written in general-purpose scripting languages
> > such as Perl or Python. ?It also builds a general-purpose Perl
> > scripting trace processor on top of the new interface and provides a
> > few example scripts that exercise the basic functionality.
> >
> > The main motivation behind it is to provide a more efficient and
> > powerful alternative to the popular method of parsing the ascii trace
> > output in order to extract useful information from it. ?To avoid the
> > overhead and complexity of all that, this patchset provides a
> > direct-to-script-interpreter pathway for doing the same thing, but in
> > a more regularized fashion, one that takes advantage of all the event
> > meta-info provided by the tracing infrustructure, such as the
> > event/field info contained in the 'format files' designed for that
> > purpose.
>
>
> That's really a great thing! I was also hesitating to implement a
> python interface to perf in order to quickly plug post processing
> tools. But your patchset does that in a much more generic way that I
> imagined: we can support other languages, we have well defined
> callbacks to process the events...
>
> Really nice, I hope we can give it a try in -tip soon.

Agreed! There's a few details to be improved and the license needs to be
kernel compatible but all in one, this is really great stuff! Ad-hoc
scripting based on the binary data stream is a quite powerful concept
IMO.

We might be able to inject more complete data structures into the
scripting space as well in the future, if the C side grows them. I.e. we
could have a healthy mixture of fast C code that provides not just a
dumb stream of records but also metadata and higher level data
structures, plus scripting.

One open question would be compatibility. I think initially we dont want
to provide format guarantees and script guarantees - this area is still
too fluid to pin down random details.

Ingo

2009-10-06 13:01:46

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support


* Tom Zanussi <[email protected]> wrote:

> OPT_BOOLEAN('v', "verbose", &verbose,
> "be more verbose (show symbol address, etc)"),
> + OPT_BOOLEAN('p', "perl", &do_perl,
> + "send output to a Perl script"),
> OPT_STRING('s', "script", &script_name, "file",
> "script file name"),

I dont think we want to use up primary option letters one per language.
If Perl takes 'p' then what will Python use, 'P'? How about PHP, PEARL
and PostScript then? ;-)

I think it's better to make the language specification part of the
-s/--script option, via two methods:

Explicit:

-s Perl::my_script.pl
-s pl::my_script.pl
-s Python::my_script.py
-s Bash::my_script.sh

Implicit, based on the script extension:

-s my_script.pl # maps to the Perl generator
-s my_script.py # maps to the Python generator
-s my_script.sh # maps to the Bash generator

I think we also want to have a 'perf -s *' kind of thing to get a list
of all available language modules.

Ingo

2009-10-06 13:07:53

by Tom Zanussi

[permalink] [raw]
Subject: [tip:perf/core] tracing/events: Add 'signed' field to format files

Commit-ID: 26a50744b21fff65bd754874072857bee8967f4d
Gitweb: http://git.kernel.org/tip/26a50744b21fff65bd754874072857bee8967f4d
Author: Tom Zanussi <[email protected]>
AuthorDate: Tue, 6 Oct 2009 01:09:50 -0500
Committer: Ingo Molnar <[email protected]>
CommitDate: Tue, 6 Oct 2009 15:04:45 +0200

tracing/events: Add 'signed' field to format files

The sign info used for filters in the kernel is also useful to
applications that process the trace stream. Add it to the format
files and make it available to userspace.

Signed-off-by: Tom Zanussi <[email protected]>
Acked-by: Frederic Weisbecker <[email protected]>
Cc: [email protected]
Cc: [email protected]
Cc: [email protected]
Cc: Peter Zijlstra <[email protected]>
Cc: Mike Galbraith <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Arnaldo Carvalho de Melo <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
include/trace/ftrace.h | 15 +++++++++------
kernel/trace/ring_buffer.c | 15 +++++++++------
kernel/trace/trace_events.c | 24 ++++++++++++------------
kernel/trace/trace_export.c | 25 ++++++++++++++-----------
kernel/trace/trace_syscalls.c | 20 +++++++++++++-------
tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
tools/perf/util/trace-event.h | 1 +
7 files changed, 82 insertions(+), 42 deletions(-)

diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
index cc0d966..c9bbcab 100644
--- a/include/trace/ftrace.h
+++ b/include/trace/ftrace.h
@@ -120,9 +120,10 @@
#undef __field
#define __field(type, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%u;\tsize:%u;\n", \
+ "offset:%u;\tsize:%u;\tsigned:%u;\n", \
(unsigned int)offsetof(typeof(field), item), \
- (unsigned int)sizeof(field.item)); \
+ (unsigned int)sizeof(field.item), \
+ (unsigned int)is_signed_type(type)); \
if (!ret) \
return 0;

@@ -132,19 +133,21 @@
#undef __array
#define __array(type, item, len) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
- "offset:%u;\tsize:%u;\n", \
+ "offset:%u;\tsize:%u;\tsigned:%u;\n", \
(unsigned int)offsetof(typeof(field), item), \
- (unsigned int)sizeof(field.item)); \
+ (unsigned int)sizeof(field.item), \
+ (unsigned int)is_signed_type(type)); \
if (!ret) \
return 0;

#undef __dynamic_array
#define __dynamic_array(type, item, len) \
ret = trace_seq_printf(s, "\tfield:__data_loc " #type "[] " #item ";\t"\
- "offset:%u;\tsize:%u;\n", \
+ "offset:%u;\tsize:%u;\tsigned:%u;\n", \
(unsigned int)offsetof(typeof(field), \
__data_loc_##item), \
- (unsigned int)sizeof(field.__data_loc_##item)); \
+ (unsigned int)sizeof(field.__data_loc_##item), \
+ (unsigned int)is_signed_type(type)); \
if (!ret) \
return 0;

diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index d4ff019..e43c928 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -397,18 +397,21 @@ int ring_buffer_print_page_header(struct trace_seq *s)
int ret;

ret = trace_seq_printf(s, "\tfield: u64 timestamp;\t"
- "offset:0;\tsize:%u;\n",
- (unsigned int)sizeof(field.time_stamp));
+ "offset:0;\tsize:%u;\tsigned:%u;\n",
+ (unsigned int)sizeof(field.time_stamp),
+ (unsigned int)is_signed_type(u64));

ret = trace_seq_printf(s, "\tfield: local_t commit;\t"
- "offset:%u;\tsize:%u;\n",
+ "offset:%u;\tsize:%u;\tsigned:%u;\n",
(unsigned int)offsetof(typeof(field), commit),
- (unsigned int)sizeof(field.commit));
+ (unsigned int)sizeof(field.commit),
+ (unsigned int)is_signed_type(long));

ret = trace_seq_printf(s, "\tfield: char data;\t"
- "offset:%u;\tsize:%u;\n",
+ "offset:%u;\tsize:%u;\tsigned:%u;\n",
(unsigned int)offsetof(typeof(field), data),
- (unsigned int)BUF_PAGE_SIZE);
+ (unsigned int)BUF_PAGE_SIZE,
+ (unsigned int)is_signed_type(char));

return ret;
}
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index d128f65..cf3cabf 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -507,7 +507,7 @@ extern char *__bad_type_size(void);
#define FIELD(type, name) \
sizeof(type) != sizeof(field.name) ? __bad_type_size() : \
#type, "common_" #name, offsetof(typeof(field), name), \
- sizeof(field.name)
+ sizeof(field.name), is_signed_type(type)

static int trace_write_header(struct trace_seq *s)
{
@@ -515,17 +515,17 @@ static int trace_write_header(struct trace_seq *s)

/* struct trace_entry */
return trace_seq_printf(s,
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\n",
- FIELD(unsigned short, type),
- FIELD(unsigned char, flags),
- FIELD(unsigned char, preempt_count),
- FIELD(int, pid),
- FIELD(int, lock_depth));
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
+ "\n",
+ FIELD(unsigned short, type),
+ FIELD(unsigned char, flags),
+ FIELD(unsigned char, preempt_count),
+ FIELD(int, pid),
+ FIELD(int, lock_depth));
}

static ssize_t
diff --git a/kernel/trace/trace_export.c b/kernel/trace/trace_export.c
index 9753fcc..31da218 100644
--- a/kernel/trace/trace_export.c
+++ b/kernel/trace/trace_export.c
@@ -66,44 +66,47 @@ static void __used ____ftrace_check_##name(void) \
#undef __field
#define __field(type, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%zu;\tsize:%zu;\n", \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
offsetof(typeof(field), item), \
- sizeof(field.item)); \
+ sizeof(field.item), is_signed_type(type)); \
if (!ret) \
return 0;

#undef __field_desc
#define __field_desc(type, container, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%zu;\tsize:%zu;\n", \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
offsetof(typeof(field), container.item), \
- sizeof(field.container.item)); \
+ sizeof(field.container.item), \
+ is_signed_type(type)); \
if (!ret) \
return 0;

#undef __array
#define __array(type, item, len) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
- "offset:%zu;\tsize:%zu;\n", \
- offsetof(typeof(field), item), \
- sizeof(field.item)); \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
+ offsetof(typeof(field), item), \
+ sizeof(field.item), is_signed_type(type)); \
if (!ret) \
return 0;

#undef __array_desc
#define __array_desc(type, container, item, len) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
- "offset:%zu;\tsize:%zu;\n", \
+ "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
offsetof(typeof(field), container.item), \
- sizeof(field.container.item)); \
+ sizeof(field.container.item), \
+ is_signed_type(type)); \
if (!ret) \
return 0;

#undef __dynamic_array
#define __dynamic_array(type, item) \
ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
- "offset:%zu;\tsize:0;\n", \
- offsetof(typeof(field), item)); \
+ "offset:%zu;\tsize:0;\tsigned:%u;\n", \
+ offsetof(typeof(field), item), \
+ is_signed_type(type)); \
if (!ret) \
return 0;

diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
index 527e17e..d99abc4 100644
--- a/kernel/trace/trace_syscalls.c
+++ b/kernel/trace/trace_syscalls.c
@@ -103,7 +103,8 @@ extern char *__bad_type_size(void);
#define SYSCALL_FIELD(type, name) \
sizeof(type) != sizeof(trace.name) ? \
__bad_type_size() : \
- #type, #name, offsetof(typeof(trace), name), sizeof(trace.name)
+ #type, #name, offsetof(typeof(trace), name), \
+ sizeof(trace.name), is_signed_type(type)

int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
{
@@ -120,7 +121,8 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
if (!entry)
return 0;

- ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
+ ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
+ "\tsigned:%u;\n",
SYSCALL_FIELD(int, nr));
if (!ret)
return 0;
@@ -130,8 +132,10 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
entry->args[i]);
if (!ret)
return 0;
- ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;\n", offset,
- sizeof(unsigned long));
+ ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;"
+ "\tsigned:%u;\n", offset,
+ sizeof(unsigned long),
+ is_signed_type(unsigned long));
if (!ret)
return 0;
offset += sizeof(unsigned long);
@@ -163,8 +167,10 @@ int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
struct syscall_trace_exit trace;

ret = trace_seq_printf(s,
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
- "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
+ "\tsigned:%u;\n"
+ "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
+ "\tsigned:%u;\n",
SYSCALL_FIELD(int, nr),
SYSCALL_FIELD(long, ret));
if (!ret)
@@ -212,7 +218,7 @@ int syscall_exit_define_fields(struct ftrace_event_call *call)
if (ret)
return ret;

- ret = trace_define_field(call, SYSCALL_FIELD(long, ret), 0,
+ ret = trace_define_field(call, SYSCALL_FIELD(long, ret),
FILTER_OTHER);

return ret;
diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index 55b41b9..be8412d 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -897,6 +897,21 @@ static int event_read_fields(struct event *event, struct format_field **fields)
if (read_expected(EVENT_OP, (char *)";") < 0)
goto fail_expect;

+ if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
+ goto fail_expect;
+
+ if (read_expected(EVENT_OP, (char *)":") < 0)
+ goto fail_expect;
+
+ if (read_expect_type(EVENT_ITEM, &token))
+ goto fail;
+ if (strtoul(token, NULL, 0))
+ field->flags |= FIELD_IS_SIGNED;
+ free_token(token);
+
+ if (read_expected(EVENT_OP, (char *)";") < 0)
+ goto fail_expect;
+
if (read_expect_type(EVENT_NEWLINE, &token) < 0)
goto fail;
free_token(token);
@@ -2845,6 +2860,15 @@ static void parse_header_field(char *type,
free_token(token);
if (read_expected(EVENT_OP, (char *)";") < 0)
return;
+ if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
+ return;
+ if (read_expected(EVENT_OP, (char *)":") < 0)
+ return;
+ if (read_expect_type(EVENT_ITEM, &token) < 0)
+ return;
+ free_token(token);
+ if (read_expected(EVENT_OP, (char *)";") < 0)
+ return;
if (read_expect_type(EVENT_NEWLINE, &token) < 0)
return;
free_token(token);
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 162c3e6..00b440d 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -26,6 +26,7 @@ enum {
enum format_flags {
FIELD_IS_ARRAY = 1,
FIELD_IS_POINTER = 2,
+ FIELD_IS_SIGNED = 4,
};

struct format_field {

2009-10-06 13:08:05

by Tom Zanussi

[permalink] [raw]
Subject: [tip:perf/core] perf trace: Add subsystem string to struct event

Commit-ID: 2774601811bedd04ee7e38624343ea80b4a62d7e
Gitweb: http://git.kernel.org/tip/2774601811bedd04ee7e38624343ea80b4a62d7e
Author: Tom Zanussi <[email protected]>
AuthorDate: Tue, 6 Oct 2009 01:09:51 -0500
Committer: Ingo Molnar <[email protected]>
CommitDate: Tue, 6 Oct 2009 15:04:46 +0200

perf trace: Add subsystem string to struct event

Needed to fully qualify event names for event stream processing.

Signed-off-by: Tom Zanussi <[email protected]>
Acked-by: Frederic Weisbecker <[email protected]>
Cc: [email protected]
Cc: [email protected]
Cc: [email protected]
Cc: Peter Zijlstra <[email protected]>
Cc: Mike Galbraith <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Arnaldo Carvalho de Melo <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
tools/perf/util/trace-event-parse.c | 4 +++-
tools/perf/util/trace-event.h | 3 ++-
2 files changed, 5 insertions(+), 2 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index be8412d..de3fc8b 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -2950,7 +2950,7 @@ int parse_ftrace_file(char *buf, unsigned long size)
return 0;
}

-int parse_event_file(char *buf, unsigned long size, char *system__unused __unused)
+int parse_event_file(char *buf, unsigned long size, char *sys)
{
struct event *event;
int ret;
@@ -2977,6 +2977,8 @@ int parse_event_file(char *buf, unsigned long size, char *system__unused __unuse
if (ret < 0)
die("failed to read event print fmt");

+ event->system = strdup(sys);
+
#define PRINT_ARGS 0
if (PRINT_ARGS && event->print_fmt.args)
print_args(event->print_fmt.args);
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index 00b440d..cb92978 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -133,6 +133,7 @@ struct event {
int flags;
struct format format;
struct print_fmt print_fmt;
+ char *system;
};

enum {
@@ -167,7 +168,7 @@ void print_funcs(void);
void print_printk(void);

int parse_ftrace_file(char *buf, unsigned long size);
-int parse_event_file(char *buf, unsigned long size, char *system);
+int parse_event_file(char *buf, unsigned long size, char *sys);
void print_event(int cpu, void *data, int size, unsigned long long nsecs,
char *comm);

2009-10-06 13:08:16

by Tom Zanussi

[permalink] [raw]
Subject: [tip:perf/core] perf trace: Add string/dynamic cases to format_flags

Commit-ID: 064739bc4b3d7f424b2f25547e6611bcf0132415
Gitweb: http://git.kernel.org/tip/064739bc4b3d7f424b2f25547e6611bcf0132415
Author: Tom Zanussi <[email protected]>
AuthorDate: Tue, 6 Oct 2009 01:09:52 -0500
Committer: Ingo Molnar <[email protected]>
CommitDate: Tue, 6 Oct 2009 15:04:46 +0200

perf trace: Add string/dynamic cases to format_flags

Needed for distinguishing string fields in event stream processing.

Signed-off-by: Tom Zanussi <[email protected]>
Acked-by: Frederic Weisbecker <[email protected]>
Cc: [email protected]
Cc: [email protected]
Cc: [email protected]
Cc: Peter Zijlstra <[email protected]>
Cc: Mike Galbraith <[email protected]>
Cc: Paul Mackerras <[email protected]>
Cc: Arnaldo Carvalho de Melo <[email protected]>
LKML-Reference: <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
tools/perf/util/trace-event.h | 2 ++
2 files changed, 26 insertions(+), 0 deletions(-)

diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
index de3fc8b..6f851f9 100644
--- a/tools/perf/util/trace-event-parse.c
+++ b/tools/perf/util/trace-event-parse.c
@@ -721,6 +721,24 @@ static int event_read_id(void)
return -1;
}

+static int field_is_string(struct format_field *field)
+{
+ if ((field->flags & FIELD_IS_ARRAY) &&
+ (!strstr(field->type, "char") || !strstr(field->type, "u8") ||
+ !strstr(field->type, "s8")))
+ return 1;
+
+ return 0;
+}
+
+static int field_is_dynamic(struct format_field *field)
+{
+ if (!strcmp(field->type, "__data_loc"))
+ return 1;
+
+ return 0;
+}
+
static int event_read_fields(struct event *event, struct format_field **fields)
{
struct format_field *field = NULL;
@@ -865,6 +883,12 @@ static int event_read_fields(struct event *event, struct format_field **fields)
free(brackets);
}

+ if (field_is_string(field)) {
+ field->flags |= FIELD_IS_STRING;
+ if (field_is_dynamic(field))
+ field->flags |= FIELD_IS_DYNAMIC;
+ }
+
if (test_type_token(type, token, EVENT_OP, (char *)";"))
goto fail;
free_token(token);
diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
index cb92978..5f59a39 100644
--- a/tools/perf/util/trace-event.h
+++ b/tools/perf/util/trace-event.h
@@ -27,6 +27,8 @@ enum format_flags {
FIELD_IS_ARRAY = 1,
FIELD_IS_POINTER = 2,
FIELD_IS_SIGNED = 4,
+ FIELD_IS_STRING = 8,
+ FIELD_IS_DYNAMIC = 16,
};

struct format_field {

2009-10-06 13:10:25

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting


* Tom Zanussi <[email protected]> wrote:

> tracing/events: Add 'signed' field to format files
> perf trace: Add subsystem string to struct event
> perf trace: Add string/dynamic cases to format_flags

I've applied these three patches to tip:perf/core, as they are fine
as-is standalone. This should ease the iteration of the remaining
patches.

Thanks,

Ingo

2009-10-06 13:26:31

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting

On Tue, 2009-10-06 at 11:09 +0200, Ingo Molnar wrote:
> * Tom Zanussi <[email protected]> wrote:
>
> > Known problems/shortcomings:
> >
> > Probably the biggest problem right now is the sorting hack I added as
> > the last patch. It's just meant as a temporary thing, but is there
> > because tracing scripts in general want to see events in the order
> > they happened i.e. timestamp order. [...]
>
> Btw., have you seen the -M/--multiplex option to perf record? It
> multiplexes all events into a single buffer - making them all ordered.
> (The events are in causal ordering in this case even if there's some TSC
> asynchronity)

It also wrecks large machines.. I've been thinking about limiting the
number of CPUs you can redirect into a single output stream using the
output_fd thing, but then the inherited stuff makes that very hard.

And we also need a solution for the inhertited counters, the best would
be the per-cpu inherited things, where we use both cpu and pid, instead
of either.

In short, -M is nice, but it also has significant down sides, esp. with
machines getting more and more cores.

2009-10-06 13:54:03

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting


* Peter Zijlstra <[email protected]> wrote:

> On Tue, 2009-10-06 at 11:09 +0200, Ingo Molnar wrote:
> > * Tom Zanussi <[email protected]> wrote:
> >
> > > Known problems/shortcomings:
> > >
> > > Probably the biggest problem right now is the sorting hack I added as
> > > the last patch. It's just meant as a temporary thing, but is there
> > > because tracing scripts in general want to see events in the order
> > > they happened i.e. timestamp order. [...]
> >
> > Btw., have you seen the -M/--multiplex option to perf record? It
> > multiplexes all events into a single buffer - making them all ordered.
> > (The events are in causal ordering in this case even if there's some TSC
> > asynchronity)
>
> It also wrecks large machines.. [...]

With millions of events per sec, for sure. It doesnt with a few thousand
per sec. Right now that's the price of guarantee causality. If you _can_
trust your system-wide TSC then it's not needed - but that's only
possible on a very small subset of machines currently.

> [...] I've been thinking about limiting the number of CPUs you can
> redirect into a single output stream using the output_fd thing, but
> then the inherited stuff makes that very hard.
>
> And we also need a solution for the inhertited counters, the best
> would be the per-cpu inherited things, where we use both cpu and pid,
> instead of either.
>
> In short, -M is nice, but it also has significant down sides, esp.
> with machines getting more and more cores.

Yeah.

Ingo

2009-10-06 15:05:52

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: [tip:perf/core] tracing/events: Add 'signed' field to format files

On Tue, Oct 06, 2009 at 01:06:39PM +0000, tip-bot for Tom Zanussi wrote:
> Commit-ID: 26a50744b21fff65bd754874072857bee8967f4d
> Gitweb: http://git.kernel.org/tip/26a50744b21fff65bd754874072857bee8967f4d
> Author: Tom Zanussi <[email protected]>
> AuthorDate: Tue, 6 Oct 2009 01:09:50 -0500
> Committer: Ingo Molnar <[email protected]>
> CommitDate: Tue, 6 Oct 2009 15:04:45 +0200
>
> tracing/events: Add 'signed' field to format files
>
> The sign info used for filters in the kernel is also useful to
> applications that process the trace stream. Add it to the format
> files and make it available to userspace.



This is something we could already find using the type of
the field.

Also I wonder if that breaks the format definition ABI. I mean:
event formats are not ABI, except for the TRACE_EVENT_ABI.
But concerning how we describe the format description, I
have doubts.

As an example, I don't know if this patch would break 2.6.32-rc1
(and then 2.6.32) based perf tools running on a future 2.6.33
kernel.

2009-10-07 01:08:12

by Steven Rostedt

[permalink] [raw]
Subject: Re: [RFC][PATCH 1/9] tracing/events: Add 'signed' field to format files

On Tue, 2009-10-06 at 01:09 -0500, Tom Zanussi wrote:
> The sign info used for filters in the kernel is also useful to
> applications that process the trace stream. Add it to the format
> files and make it available to userspace.
>
> Signed-off-by: Tom Zanussi <[email protected]>
> ---
> include/trace/ftrace.h | 15 +++++++++------
> kernel/trace/ring_buffer.c | 15 +++++++++------
> kernel/trace/trace_events.c | 24 ++++++++++++------------
> kernel/trace/trace_export.c | 25 ++++++++++++++-----------
> kernel/trace/trace_syscalls.c | 20 +++++++++++++-------
> tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
> tools/perf/util/trace-event.h | 1 +
> 7 files changed, 82 insertions(+), 42 deletions(-)
>
> diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> index cc0d966..c9bbcab 100644
> --- a/include/trace/ftrace.h
> +++ b/include/trace/ftrace.h
> @@ -120,9 +120,10 @@
> #undef __field
> #define __field(type, item) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> - "offset:%u;\tsize:%u;\n", \
> + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> (unsigned int)offsetof(typeof(field), item), \
> - (unsigned int)sizeof(field.item)); \
> + (unsigned int)sizeof(field.item), \
> + (unsigned int)is_signed_type(type)); \
> if (!ret) \
> return 0;

I don't mind this change, but it makes me nervous. We really need to
solidify the output format file. This is adding a new field and will
already break the parsers in perf and trace_cmd.

Is there anything else that is needed? I really want to make sure that
we don't need to modify the output of the format files any more.

-- Steve

>
> @@ -132,19 +133,21 @@
> #undef __array
> #define __array(type, item, len) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
> - "offset:%u;\tsize:%u;\n", \
> + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> (unsigned int)offsetof(typeof(field), item), \
> - (unsigned int)sizeof(field.item)); \
> + (unsigned int)sizeof(field.item), \
> + (unsigned int)is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> #undef __dynamic_array
> #define __dynamic_array(type, item, len) \
> ret = trace_seq_printf(s, "\tfield:__data_loc " #type "[] " #item ";\t"\
> - "offset:%u;\tsize:%u;\n", \
> + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> (unsigned int)offsetof(typeof(field), \
> __data_loc_##item), \
> - (unsigned int)sizeof(field.__data_loc_##item)); \
> + (unsigned int)sizeof(field.__data_loc_##item), \
> + (unsigned int)is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> index d4ff019..e43c928 100644
> --- a/kernel/trace/ring_buffer.c
> +++ b/kernel/trace/ring_buffer.c
> @@ -397,18 +397,21 @@ int ring_buffer_print_page_header(struct trace_seq *s)
> int ret;
>
> ret = trace_seq_printf(s, "\tfield: u64 timestamp;\t"
> - "offset:0;\tsize:%u;\n",
> - (unsigned int)sizeof(field.time_stamp));
> + "offset:0;\tsize:%u;\tsigned:%u;\n",
> + (unsigned int)sizeof(field.time_stamp),
> + (unsigned int)is_signed_type(u64));
>
> ret = trace_seq_printf(s, "\tfield: local_t commit;\t"
> - "offset:%u;\tsize:%u;\n",
> + "offset:%u;\tsize:%u;\tsigned:%u;\n",
> (unsigned int)offsetof(typeof(field), commit),
> - (unsigned int)sizeof(field.commit));
> + (unsigned int)sizeof(field.commit),
> + (unsigned int)is_signed_type(long));
>
> ret = trace_seq_printf(s, "\tfield: char data;\t"
> - "offset:%u;\tsize:%u;\n",
> + "offset:%u;\tsize:%u;\tsigned:%u;\n",
> (unsigned int)offsetof(typeof(field), data),
> - (unsigned int)BUF_PAGE_SIZE);
> + (unsigned int)BUF_PAGE_SIZE,
> + (unsigned int)is_signed_type(char));
>
> return ret;
> }
> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index d128f65..cf3cabf 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -507,7 +507,7 @@ extern char *__bad_type_size(void);
> #define FIELD(type, name) \
> sizeof(type) != sizeof(field.name) ? __bad_type_size() : \
> #type, "common_" #name, offsetof(typeof(field), name), \
> - sizeof(field.name)
> + sizeof(field.name), is_signed_type(type)
>
> static int trace_write_header(struct trace_seq *s)
> {
> @@ -515,17 +515,17 @@ static int trace_write_header(struct trace_seq *s)
>
> /* struct trace_entry */
> return trace_seq_printf(s,
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> - "\n",
> - FIELD(unsigned short, type),
> - FIELD(unsigned char, flags),
> - FIELD(unsigned char, preempt_count),
> - FIELD(int, pid),
> - FIELD(int, lock_depth));
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> + "\n",
> + FIELD(unsigned short, type),
> + FIELD(unsigned char, flags),
> + FIELD(unsigned char, preempt_count),
> + FIELD(int, pid),
> + FIELD(int, lock_depth));
> }
>
> static ssize_t
> diff --git a/kernel/trace/trace_export.c b/kernel/trace/trace_export.c
> index 9753fcc..31da218 100644
> --- a/kernel/trace/trace_export.c
> +++ b/kernel/trace/trace_export.c
> @@ -66,44 +66,47 @@ static void __used ____ftrace_check_##name(void) \
> #undef __field
> #define __field(type, item) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> - "offset:%zu;\tsize:%zu;\n", \
> + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> offsetof(typeof(field), item), \
> - sizeof(field.item)); \
> + sizeof(field.item), is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> #undef __field_desc
> #define __field_desc(type, container, item) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> - "offset:%zu;\tsize:%zu;\n", \
> + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> offsetof(typeof(field), container.item), \
> - sizeof(field.container.item)); \
> + sizeof(field.container.item), \
> + is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> #undef __array
> #define __array(type, item, len) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
> - "offset:%zu;\tsize:%zu;\n", \
> - offsetof(typeof(field), item), \
> - sizeof(field.item)); \
> + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> + offsetof(typeof(field), item), \
> + sizeof(field.item), is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> #undef __array_desc
> #define __array_desc(type, container, item, len) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
> - "offset:%zu;\tsize:%zu;\n", \
> + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> offsetof(typeof(field), container.item), \
> - sizeof(field.container.item)); \
> + sizeof(field.container.item), \
> + is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> #undef __dynamic_array
> #define __dynamic_array(type, item) \
> ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> - "offset:%zu;\tsize:0;\n", \
> - offsetof(typeof(field), item)); \
> + "offset:%zu;\tsize:0;\tsigned:%u;\n", \
> + offsetof(typeof(field), item), \
> + is_signed_type(type)); \
> if (!ret) \
> return 0;
>
> diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
> index 527e17e..d99abc4 100644
> --- a/kernel/trace/trace_syscalls.c
> +++ b/kernel/trace/trace_syscalls.c
> @@ -103,7 +103,8 @@ extern char *__bad_type_size(void);
> #define SYSCALL_FIELD(type, name) \
> sizeof(type) != sizeof(trace.name) ? \
> __bad_type_size() : \
> - #type, #name, offsetof(typeof(trace), name), sizeof(trace.name)
> + #type, #name, offsetof(typeof(trace), name), \
> + sizeof(trace.name), is_signed_type(type)
>
> int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> {
> @@ -120,7 +121,8 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> if (!entry)
> return 0;
>
> - ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
> + ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
> + "\tsigned:%u;\n",
> SYSCALL_FIELD(int, nr));
> if (!ret)
> return 0;
> @@ -130,8 +132,10 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> entry->args[i]);
> if (!ret)
> return 0;
> - ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;\n", offset,
> - sizeof(unsigned long));
> + ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;"
> + "\tsigned:%u;\n", offset,
> + sizeof(unsigned long),
> + is_signed_type(unsigned long));
> if (!ret)
> return 0;
> offset += sizeof(unsigned long);
> @@ -163,8 +167,10 @@ int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
> struct syscall_trace_exit trace;
>
> ret = trace_seq_printf(s,
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
> + "\tsigned:%u;\n"
> + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
> + "\tsigned:%u;\n",
> SYSCALL_FIELD(int, nr),
> SYSCALL_FIELD(long, ret));
> if (!ret)
> @@ -212,7 +218,7 @@ int syscall_exit_define_fields(struct ftrace_event_call *call)
> if (ret)
> return ret;
>
> - ret = trace_define_field(call, SYSCALL_FIELD(long, ret), 0,
> + ret = trace_define_field(call, SYSCALL_FIELD(long, ret),
> FILTER_OTHER);
>
> return ret;
> diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
> index 55b41b9..be8412d 100644
> --- a/tools/perf/util/trace-event-parse.c
> +++ b/tools/perf/util/trace-event-parse.c
> @@ -897,6 +897,21 @@ static int event_read_fields(struct event *event, struct format_field **fields)
> if (read_expected(EVENT_OP, (char *)";") < 0)
> goto fail_expect;
>
> + if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
> + goto fail_expect;
> +
> + if (read_expected(EVENT_OP, (char *)":") < 0)
> + goto fail_expect;
> +
> + if (read_expect_type(EVENT_ITEM, &token))
> + goto fail;
> + if (strtoul(token, NULL, 0))
> + field->flags |= FIELD_IS_SIGNED;
> + free_token(token);
> +
> + if (read_expected(EVENT_OP, (char *)";") < 0)
> + goto fail_expect;
> +
> if (read_expect_type(EVENT_NEWLINE, &token) < 0)
> goto fail;
> free_token(token);
> @@ -2845,6 +2860,15 @@ static void parse_header_field(char *type,
> free_token(token);
> if (read_expected(EVENT_OP, (char *)";") < 0)
> return;
> + if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
> + return;
> + if (read_expected(EVENT_OP, (char *)":") < 0)
> + return;
> + if (read_expect_type(EVENT_ITEM, &token) < 0)
> + return;
> + free_token(token);
> + if (read_expected(EVENT_OP, (char *)";") < 0)
> + return;
> if (read_expect_type(EVENT_NEWLINE, &token) < 0)
> return;
> free_token(token);
> diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
> index 162c3e6..00b440d 100644
> --- a/tools/perf/util/trace-event.h
> +++ b/tools/perf/util/trace-event.h
> @@ -26,6 +26,7 @@ enum {
> enum format_flags {
> FIELD_IS_ARRAY = 1,
> FIELD_IS_POINTER = 2,
> + FIELD_IS_SIGNED = 4,
> };
>
> struct format_field {

2009-10-07 04:02:00

by Tom Zanussi

[permalink] [raw]
Subject: Re: [RFC][PATCH 0/9] perf trace: support for general-purpose scripting

On Tue, 2009-10-06 at 11:09 +0200, Ingo Molnar wrote:
> * Tom Zanussi <[email protected]> wrote:
>
> > Known problems/shortcomings:
> >
> > Probably the biggest problem right now is the sorting hack I added as
> > the last patch. It's just meant as a temporary thing, but is there
> > because tracing scripts in general want to see events in the order
> > they happened i.e. timestamp order. [...]
>
> Btw., have you seen the -M/--multiplex option to perf record? It
> multiplexes all events into a single buffer - making them all ordered.
> (The events are in causal ordering in this case even if there's some TSC
> asynchronity)
>

No, I didn't know about that - thanks for letting me know.

Tom

> Ingo

2009-10-07 04:03:29

by Tom Zanussi

[permalink] [raw]
Subject: Re: [RFC][PATCH 8/9] perf trace: Add perf trace scripting support modules for Perl

On Tue, 2009-10-06 at 14:39 +0200, Ingo Molnar wrote:
> * Tom Zanussi <[email protected]> wrote:
>
> > --- /dev/null
> > +++ b/tools/perf/scripts/perl/Perf-Trace-Util/Changes
> > @@ -0,0 +1,6 @@
> > +Revision history for Perl extension Perf::Trace::Util.
> > +
> > +0.01 Fri Sep 25 12:08:40 2009
> > + - original version; created by h2xs 1.23 with options
> > + -AXn Perf::Trace::Util
> > +
>
> is this needed? We have Git history which is far more flexible than
> in-source changelogs.
>

Yeah, that was generated by the Perl module tool - I'll get rid of it.

Tom

> Ingo

2009-10-07 04:12:47

by Tom Zanussi

[permalink] [raw]
Subject: Re: [RFC][PATCH 8/9] perf trace: Add perf trace scripting support modules for Perl

On Tue, 2009-10-06 at 14:45 +0200, Ingo Molnar wrote:
> * Tom Zanussi <[email protected]> wrote:
>
> > +++ b/tools/perf/scripts/perl/Perf-Trace-Util/README
> > @@ -0,0 +1,30 @@
> > +Perf-Trace-Util version 0.01
> > +============================
> > +
> > +This module contains utility functions for use with perf trace.
> > +
> > +INSTALLATION
> > +
> > +Building perf with perf trace Perl scripting should install this
> > +module in the right place.
> > +
> > +You should make sure libperl is installed first e.g. apt-get install
> > +libperl-dev.
> > +
> > +DEPENDENCIES
> > +
> > +This module requires these other modules and libraries:
> > +
> > + blah blah blah
>
> Some fixing needed here i guess ;-)

Yeah, more auto-generated stuff.

>
> > +COPYRIGHT AND LICENCE
> > +
> > +Put the correct copyright and licence information here.
> > +
> > +Copyright (C) 2009 by Tom Zanussi <[email protected]>
> > +
> > +This library is free software; you can redistribute it and/or modify
> > +it under the same terms as Perl itself, either Perl version 5.10.0 or,
> > +at your option, any later version of Perl 5 you may have available.
>
> Would be nice to dual license it to the kernel (GPLv2) as well.
>

Right, I'll add the GPL license to this.

Thanks,

Tom

> Ingo

2009-10-07 04:18:27

by Tom Zanussi

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support

On Tue, 2009-10-06 at 15:00 +0200, Ingo Molnar wrote:
> * Tom Zanussi <[email protected]> wrote:
>
> > OPT_BOOLEAN('v', "verbose", &verbose,
> > "be more verbose (show symbol address, etc)"),
> > + OPT_BOOLEAN('p', "perl", &do_perl,
> > + "send output to a Perl script"),
> > OPT_STRING('s', "script", &script_name, "file",
> > "script file name"),
>
> I dont think we want to use up primary option letters one per language.
> If Perl takes 'p' then what will Python use, 'P'? How about PHP, PEARL
> and PostScript then? ;-)
>
> I think it's better to make the language specification part of the
> -s/--script option, via two methods:
>
> Explicit:
>
> -s Perl::my_script.pl
> -s pl::my_script.pl
> -s Python::my_script.py
> -s Bash::my_script.sh
>
> Implicit, based on the script extension:
>
> -s my_script.pl # maps to the Perl generator
> -s my_script.py # maps to the Python generator
> -s my_script.sh # maps to the Bash generator
>
> I think we also want to have a 'perf -s *' kind of thing to get a list
> of all available language modules.
>

I knew somebody would point that out (and suggest a better way ;-) That
all makes sense - I'll make these changes in the next version.

Tom


> Ingo

2009-10-07 04:38:17

by Tom Zanussi

[permalink] [raw]
Subject: Re: [tip:perf/core] tracing/events: Add 'signed' field to format files

On Tue, 2009-10-06 at 17:05 +0200, Frederic Weisbecker wrote:
> On Tue, Oct 06, 2009 at 01:06:39PM +0000, tip-bot for Tom Zanussi wrote:
> > Commit-ID: 26a50744b21fff65bd754874072857bee8967f4d
> > Gitweb: http://git.kernel.org/tip/26a50744b21fff65bd754874072857bee8967f4d
> > Author: Tom Zanussi <[email protected]>
> > AuthorDate: Tue, 6 Oct 2009 01:09:50 -0500
> > Committer: Ingo Molnar <[email protected]>
> > CommitDate: Tue, 6 Oct 2009 15:04:45 +0200
> >
> > tracing/events: Add 'signed' field to format files
> >
> > The sign info used for filters in the kernel is also useful to
> > applications that process the trace stream. Add it to the format
> > files and make it available to userspace.
>
>
>
> This is something we could already find using the type of
> the field.
>

Hmm, yeah, we do have the field type but in the form of a string, which
I guess we'd need some kind of type map to get the sign out of. Since
we already have the sign info, though, it made sense to me to stick it
in the format file, other than the fact that it might break some
existing tools. I didn't think the final format was nailed down yet so
thought that might not be so important at this point...

Tom

> Also I wonder if that breaks the format definition ABI. I mean:
> event formats are not ABI, except for the TRACE_EVENT_ABI.
> But concerning how we describe the format description, I
> have doubts.
>
> As an example, I don't know if this patch would break 2.6.32-rc1
> (and then 2.6.32) based perf tools running on a future 2.6.33
> kernel.
>

2009-10-07 05:05:28

by Tom Zanussi

[permalink] [raw]
Subject: Re: [RFC][PATCH 1/9] tracing/events: Add 'signed' field to format files

On Tue, 2009-10-06 at 21:06 -0400, Steven Rostedt wrote:
> On Tue, 2009-10-06 at 01:09 -0500, Tom Zanussi wrote:
> > The sign info used for filters in the kernel is also useful to
> > applications that process the trace stream. Add it to the format
> > files and make it available to userspace.
> >
> > Signed-off-by: Tom Zanussi <[email protected]>
> > ---
> > include/trace/ftrace.h | 15 +++++++++------
> > kernel/trace/ring_buffer.c | 15 +++++++++------
> > kernel/trace/trace_events.c | 24 ++++++++++++------------
> > kernel/trace/trace_export.c | 25 ++++++++++++++-----------
> > kernel/trace/trace_syscalls.c | 20 +++++++++++++-------
> > tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
> > tools/perf/util/trace-event.h | 1 +
> > 7 files changed, 82 insertions(+), 42 deletions(-)
> >
> > diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> > index cc0d966..c9bbcab 100644
> > --- a/include/trace/ftrace.h
> > +++ b/include/trace/ftrace.h
> > @@ -120,9 +120,10 @@
> > #undef __field
> > #define __field(type, item) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> > - "offset:%u;\tsize:%u;\n", \
> > + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> > (unsigned int)offsetof(typeof(field), item), \
> > - (unsigned int)sizeof(field.item)); \
> > + (unsigned int)sizeof(field.item), \
> > + (unsigned int)is_signed_type(type)); \
> > if (!ret) \
> > return 0;
>
> I don't mind this change, but it makes me nervous. We really need to
> solidify the output format file. This is adding a new field and will
> already break the parsers in perf and trace_cmd.
>
> Is there anything else that is needed? I really want to make sure that
> we don't need to modify the output of the format files any more.
>

One of the things I had in mind when writing this patchset was to make
sure that what was there already was enough to write something real on
top of. The only thing I found I needed to add was the signed field,
and that was enough at least for the Perl case, where everything can be
mapped into 3 types - signed, unsigned and string.

Other languages might demand more - I haven't looked into it - so I
couldn't say whether anything else is needed, but it would seem to me
that the current combination of type description strings, sizes and
signs for each field should be enough information to allow any field to
be passed into any scripting interpreter. Actually, you could probably
forget about signs and sizes and just manage on type description strings
alone, if you had a typemap that mapped from the C type descriptions to
the types expected by a given interpreter. That might be what some
language implementations would end up doing, but at least for the Perl
implementation, it's much more convenient to have the is_signed field.

Tom

> -- Steve
>
> >
> > @@ -132,19 +133,21 @@
> > #undef __array
> > #define __array(type, item, len) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
> > - "offset:%u;\tsize:%u;\n", \
> > + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> > (unsigned int)offsetof(typeof(field), item), \
> > - (unsigned int)sizeof(field.item)); \
> > + (unsigned int)sizeof(field.item), \
> > + (unsigned int)is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > #undef __dynamic_array
> > #define __dynamic_array(type, item, len) \
> > ret = trace_seq_printf(s, "\tfield:__data_loc " #type "[] " #item ";\t"\
> > - "offset:%u;\tsize:%u;\n", \
> > + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> > (unsigned int)offsetof(typeof(field), \
> > __data_loc_##item), \
> > - (unsigned int)sizeof(field.__data_loc_##item)); \
> > + (unsigned int)sizeof(field.__data_loc_##item), \
> > + (unsigned int)is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
> > index d4ff019..e43c928 100644
> > --- a/kernel/trace/ring_buffer.c
> > +++ b/kernel/trace/ring_buffer.c
> > @@ -397,18 +397,21 @@ int ring_buffer_print_page_header(struct trace_seq *s)
> > int ret;
> >
> > ret = trace_seq_printf(s, "\tfield: u64 timestamp;\t"
> > - "offset:0;\tsize:%u;\n",
> > - (unsigned int)sizeof(field.time_stamp));
> > + "offset:0;\tsize:%u;\tsigned:%u;\n",
> > + (unsigned int)sizeof(field.time_stamp),
> > + (unsigned int)is_signed_type(u64));
> >
> > ret = trace_seq_printf(s, "\tfield: local_t commit;\t"
> > - "offset:%u;\tsize:%u;\n",
> > + "offset:%u;\tsize:%u;\tsigned:%u;\n",
> > (unsigned int)offsetof(typeof(field), commit),
> > - (unsigned int)sizeof(field.commit));
> > + (unsigned int)sizeof(field.commit),
> > + (unsigned int)is_signed_type(long));
> >
> > ret = trace_seq_printf(s, "\tfield: char data;\t"
> > - "offset:%u;\tsize:%u;\n",
> > + "offset:%u;\tsize:%u;\tsigned:%u;\n",
> > (unsigned int)offsetof(typeof(field), data),
> > - (unsigned int)BUF_PAGE_SIZE);
> > + (unsigned int)BUF_PAGE_SIZE,
> > + (unsigned int)is_signed_type(char));
> >
> > return ret;
> > }
> > diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> > index d128f65..cf3cabf 100644
> > --- a/kernel/trace/trace_events.c
> > +++ b/kernel/trace/trace_events.c
> > @@ -507,7 +507,7 @@ extern char *__bad_type_size(void);
> > #define FIELD(type, name) \
> > sizeof(type) != sizeof(field.name) ? __bad_type_size() : \
> > #type, "common_" #name, offsetof(typeof(field), name), \
> > - sizeof(field.name)
> > + sizeof(field.name), is_signed_type(type)
> >
> > static int trace_write_header(struct trace_seq *s)
> > {
> > @@ -515,17 +515,17 @@ static int trace_write_header(struct trace_seq *s)
> >
> > /* struct trace_entry */
> > return trace_seq_printf(s,
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> > - "\n",
> > - FIELD(unsigned short, type),
> > - FIELD(unsigned char, flags),
> > - FIELD(unsigned char, preempt_count),
> > - FIELD(int, pid),
> > - FIELD(int, lock_depth));
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\tsigned:%u;\n"
> > + "\n",
> > + FIELD(unsigned short, type),
> > + FIELD(unsigned char, flags),
> > + FIELD(unsigned char, preempt_count),
> > + FIELD(int, pid),
> > + FIELD(int, lock_depth));
> > }
> >
> > static ssize_t
> > diff --git a/kernel/trace/trace_export.c b/kernel/trace/trace_export.c
> > index 9753fcc..31da218 100644
> > --- a/kernel/trace/trace_export.c
> > +++ b/kernel/trace/trace_export.c
> > @@ -66,44 +66,47 @@ static void __used ____ftrace_check_##name(void) \
> > #undef __field
> > #define __field(type, item) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> > - "offset:%zu;\tsize:%zu;\n", \
> > + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> > offsetof(typeof(field), item), \
> > - sizeof(field.item)); \
> > + sizeof(field.item), is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > #undef __field_desc
> > #define __field_desc(type, container, item) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> > - "offset:%zu;\tsize:%zu;\n", \
> > + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> > offsetof(typeof(field), container.item), \
> > - sizeof(field.container.item)); \
> > + sizeof(field.container.item), \
> > + is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > #undef __array
> > #define __array(type, item, len) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
> > - "offset:%zu;\tsize:%zu;\n", \
> > - offsetof(typeof(field), item), \
> > - sizeof(field.item)); \
> > + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> > + offsetof(typeof(field), item), \
> > + sizeof(field.item), is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > #undef __array_desc
> > #define __array_desc(type, container, item, len) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item "[" #len "];\t" \
> > - "offset:%zu;\tsize:%zu;\n", \
> > + "offset:%zu;\tsize:%zu;\tsigned:%u;\n", \
> > offsetof(typeof(field), container.item), \
> > - sizeof(field.container.item)); \
> > + sizeof(field.container.item), \
> > + is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > #undef __dynamic_array
> > #define __dynamic_array(type, item) \
> > ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> > - "offset:%zu;\tsize:0;\n", \
> > - offsetof(typeof(field), item)); \
> > + "offset:%zu;\tsize:0;\tsigned:%u;\n", \
> > + offsetof(typeof(field), item), \
> > + is_signed_type(type)); \
> > if (!ret) \
> > return 0;
> >
> > diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c
> > index 527e17e..d99abc4 100644
> > --- a/kernel/trace/trace_syscalls.c
> > +++ b/kernel/trace/trace_syscalls.c
> > @@ -103,7 +103,8 @@ extern char *__bad_type_size(void);
> > #define SYSCALL_FIELD(type, name) \
> > sizeof(type) != sizeof(trace.name) ? \
> > __bad_type_size() : \
> > - #type, #name, offsetof(typeof(trace), name), sizeof(trace.name)
> > + #type, #name, offsetof(typeof(trace), name), \
> > + sizeof(trace.name), is_signed_type(type)
> >
> > int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> > {
> > @@ -120,7 +121,8 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> > if (!entry)
> > return 0;
> >
> > - ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
> > + ret = trace_seq_printf(s, "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
> > + "\tsigned:%u;\n",
> > SYSCALL_FIELD(int, nr));
> > if (!ret)
> > return 0;
> > @@ -130,8 +132,10 @@ int syscall_enter_format(struct ftrace_event_call *call, struct trace_seq *s)
> > entry->args[i]);
> > if (!ret)
> > return 0;
> > - ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;\n", offset,
> > - sizeof(unsigned long));
> > + ret = trace_seq_printf(s, "\toffset:%d;\tsize:%zu;"
> > + "\tsigned:%u;\n", offset,
> > + sizeof(unsigned long),
> > + is_signed_type(unsigned long));
> > if (!ret)
> > return 0;
> > offset += sizeof(unsigned long);
> > @@ -163,8 +167,10 @@ int syscall_exit_format(struct ftrace_event_call *call, struct trace_seq *s)
> > struct syscall_trace_exit trace;
> >
> > ret = trace_seq_printf(s,
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n"
> > - "\tfield:%s %s;\toffset:%zu;\tsize:%zu;\n",
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
> > + "\tsigned:%u;\n"
> > + "\tfield:%s %s;\toffset:%zu;\tsize:%zu;"
> > + "\tsigned:%u;\n",
> > SYSCALL_FIELD(int, nr),
> > SYSCALL_FIELD(long, ret));
> > if (!ret)
> > @@ -212,7 +218,7 @@ int syscall_exit_define_fields(struct ftrace_event_call *call)
> > if (ret)
> > return ret;
> >
> > - ret = trace_define_field(call, SYSCALL_FIELD(long, ret), 0,
> > + ret = trace_define_field(call, SYSCALL_FIELD(long, ret),
> > FILTER_OTHER);
> >
> > return ret;
> > diff --git a/tools/perf/util/trace-event-parse.c b/tools/perf/util/trace-event-parse.c
> > index 55b41b9..be8412d 100644
> > --- a/tools/perf/util/trace-event-parse.c
> > +++ b/tools/perf/util/trace-event-parse.c
> > @@ -897,6 +897,21 @@ static int event_read_fields(struct event *event, struct format_field **fields)
> > if (read_expected(EVENT_OP, (char *)";") < 0)
> > goto fail_expect;
> >
> > + if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
> > + goto fail_expect;
> > +
> > + if (read_expected(EVENT_OP, (char *)":") < 0)
> > + goto fail_expect;
> > +
> > + if (read_expect_type(EVENT_ITEM, &token))
> > + goto fail;
> > + if (strtoul(token, NULL, 0))
> > + field->flags |= FIELD_IS_SIGNED;
> > + free_token(token);
> > +
> > + if (read_expected(EVENT_OP, (char *)";") < 0)
> > + goto fail_expect;
> > +
> > if (read_expect_type(EVENT_NEWLINE, &token) < 0)
> > goto fail;
> > free_token(token);
> > @@ -2845,6 +2860,15 @@ static void parse_header_field(char *type,
> > free_token(token);
> > if (read_expected(EVENT_OP, (char *)";") < 0)
> > return;
> > + if (read_expected(EVENT_ITEM, (char *)"signed") < 0)
> > + return;
> > + if (read_expected(EVENT_OP, (char *)":") < 0)
> > + return;
> > + if (read_expect_type(EVENT_ITEM, &token) < 0)
> > + return;
> > + free_token(token);
> > + if (read_expected(EVENT_OP, (char *)";") < 0)
> > + return;
> > if (read_expect_type(EVENT_NEWLINE, &token) < 0)
> > return;
> > free_token(token);
> > diff --git a/tools/perf/util/trace-event.h b/tools/perf/util/trace-event.h
> > index 162c3e6..00b440d 100644
> > --- a/tools/perf/util/trace-event.h
> > +++ b/tools/perf/util/trace-event.h
> > @@ -26,6 +26,7 @@ enum {
> > enum format_flags {
> > FIELD_IS_ARRAY = 1,
> > FIELD_IS_POINTER = 2,
> > + FIELD_IS_SIGNED = 4,
> > };
> >
> > struct format_field {
>

2009-10-07 13:09:18

by Steven Rostedt

[permalink] [raw]
Subject: Re: [RFC][PATCH 1/9] tracing/events: Add 'signed' field to format files

On Wed, 2009-10-07 at 00:04 -0500, Tom Zanussi wrote:
> On Tue, 2009-10-06 at 21:06 -0400, Steven Rostedt wrote:
> > On Tue, 2009-10-06 at 01:09 -0500, Tom Zanussi wrote:
> > > The sign info used for filters in the kernel is also useful to
> > > applications that process the trace stream. Add it to the format
> > > files and make it available to userspace.
> > >
> > > Signed-off-by: Tom Zanussi <[email protected]>
> > > ---
> > > include/trace/ftrace.h | 15 +++++++++------
> > > kernel/trace/ring_buffer.c | 15 +++++++++------
> > > kernel/trace/trace_events.c | 24 ++++++++++++------------
> > > kernel/trace/trace_export.c | 25 ++++++++++++++-----------
> > > kernel/trace/trace_syscalls.c | 20 +++++++++++++-------
> > > tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
> > > tools/perf/util/trace-event.h | 1 +
> > > 7 files changed, 82 insertions(+), 42 deletions(-)
> > >
> > > diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> > > index cc0d966..c9bbcab 100644
> > > --- a/include/trace/ftrace.h
> > > +++ b/include/trace/ftrace.h
> > > @@ -120,9 +120,10 @@
> > > #undef __field
> > > #define __field(type, item) \
> > > ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> > > - "offset:%u;\tsize:%u;\n", \
> > > + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> > > (unsigned int)offsetof(typeof(field), item), \
> > > - (unsigned int)sizeof(field.item)); \
> > > + (unsigned int)sizeof(field.item), \
> > > + (unsigned int)is_signed_type(type)); \
> > > if (!ret) \
> > > return 0;
> >
> > I don't mind this change, but it makes me nervous. We really need to
> > solidify the output format file. This is adding a new field and will
> > already break the parsers in perf and trace_cmd.
> >
> > Is there anything else that is needed? I really want to make sure that
> > we don't need to modify the output of the format files any more.
> >
>
> One of the things I had in mind when writing this patchset was to make
> sure that what was there already was enough to write something real on
> top of. The only thing I found I needed to add was the signed field,
> and that was enough at least for the Perl case, where everything can be
> mapped into 3 types - signed, unsigned and string.
>
> Other languages might demand more - I haven't looked into it - so I
> couldn't say whether anything else is needed, but it would seem to me
> that the current combination of type description strings, sizes and
> signs for each field should be enough information to allow any field to
> be passed into any scripting interpreter. Actually, you could probably
> forget about signs and sizes and just manage on type description strings
> alone, if you had a typemap that mapped from the C type descriptions to
> the types expected by a given interpreter. That might be what some
> language implementations would end up doing, but at least for the Perl
> implementation, it's much more convenient to have the is_signed field.

Actually I was thinking that the print format part of the format file
would give enough to know if the object was signed or not, or even the
type (unsigned long, etc). But we are still early in this game, and I
would like to think that we are still early enough to be able to change
these formats. But it's getting close that they will soon be locked in
stone.

-- Steve

2009-10-07 14:14:12

by Christoph Hellwig

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support

On Tue, Oct 06, 2009 at 11:09:25PM -0500, Tom Zanussi wrote:
> > I think we also want to have a 'perf -s *' kind of thing to get a list
> > of all available language modules.
> >
>
> I knew somebody would point that out (and suggest a better way ;-) That
> all makes sense - I'll make these changes in the next version.

I'm a bit worried about linking two million scripting language into the
main perf binary. Can't we just have seaprate perlperf / pythonperf,
rubyperf, awkperf binaries that only contain the scripting support?

2009-10-08 04:02:14

by Tom Zanussi

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support

On Wed, 2009-10-07 at 10:13 -0400, Christoph Hellwig wrote:
> On Tue, Oct 06, 2009 at 11:09:25PM -0500, Tom Zanussi wrote:
> > > I think we also want to have a 'perf -s *' kind of thing to get a list
> > > of all available language modules.
> > >
> >
> > I knew somebody would point that out (and suggest a better way ;-) That
> > all makes sense - I'll make these changes in the next version.
>
> I'm a bit worried about linking two million scripting language into the
> main perf binary. Can't we just have seaprate perlperf / pythonperf,
> rubyperf, awkperf binaries that only contain the scripting support?
>

Yeah, that's a good point. Maybe support for each language should be
implemented as shared library 'plugins', where the right one gets loaded
dynamically using dlopen/dlsym based on the type of script invoked or
command-line option used. I'll try something like that for the next
version.

Tom

2009-10-11 08:59:37

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support


* Tom Zanussi <[email protected]> wrote:

> On Wed, 2009-10-07 at 10:13 -0400, Christoph Hellwig wrote:
> > On Tue, Oct 06, 2009 at 11:09:25PM -0500, Tom Zanussi wrote:
> > > > I think we also want to have a 'perf -s *' kind of thing to get a list
> > > > of all available language modules.
> > > >
> > >
> > > I knew somebody would point that out (and suggest a better way ;-) That
> > > all makes sense - I'll make these changes in the next version.
> >
> > I'm a bit worried about linking two million scripting language into the
> > main perf binary. Can't we just have seaprate perlperf / pythonperf,
> > rubyperf, awkperf binaries that only contain the scripting support?
>
> Yeah, that's a good point. [...]

No, we want to keep a single core binary, it has many advantages. Git
has gone through a very painful conversion from many spread out git-*
commands back into a central binary. So we avoided that mistake in perf
from the get go. We are not going to add separate perf-* commands.

ad-hoc extensions using separate perf-* scripts are fine of course and i
use that myself. But once a facility is part of core perf it wants to
move into the binary. Especially something as central as scripting
support.

Thanks,

Ingo

2009-10-11 09:01:24

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 1/9] tracing/events: Add 'signed' field to format files


* Steven Rostedt <[email protected]> wrote:

> On Wed, 2009-10-07 at 00:04 -0500, Tom Zanussi wrote:
> > On Tue, 2009-10-06 at 21:06 -0400, Steven Rostedt wrote:
> > > On Tue, 2009-10-06 at 01:09 -0500, Tom Zanussi wrote:
> > > > The sign info used for filters in the kernel is also useful to
> > > > applications that process the trace stream. Add it to the format
> > > > files and make it available to userspace.
> > > >
> > > > Signed-off-by: Tom Zanussi <[email protected]>
> > > > ---
> > > > include/trace/ftrace.h | 15 +++++++++------
> > > > kernel/trace/ring_buffer.c | 15 +++++++++------
> > > > kernel/trace/trace_events.c | 24 ++++++++++++------------
> > > > kernel/trace/trace_export.c | 25 ++++++++++++++-----------
> > > > kernel/trace/trace_syscalls.c | 20 +++++++++++++-------
> > > > tools/perf/util/trace-event-parse.c | 24 ++++++++++++++++++++++++
> > > > tools/perf/util/trace-event.h | 1 +
> > > > 7 files changed, 82 insertions(+), 42 deletions(-)
> > > >
> > > > diff --git a/include/trace/ftrace.h b/include/trace/ftrace.h
> > > > index cc0d966..c9bbcab 100644
> > > > --- a/include/trace/ftrace.h
> > > > +++ b/include/trace/ftrace.h
> > > > @@ -120,9 +120,10 @@
> > > > #undef __field
> > > > #define __field(type, item) \
> > > > ret = trace_seq_printf(s, "\tfield:" #type " " #item ";\t" \
> > > > - "offset:%u;\tsize:%u;\n", \
> > > > + "offset:%u;\tsize:%u;\tsigned:%u;\n", \
> > > > (unsigned int)offsetof(typeof(field), item), \
> > > > - (unsigned int)sizeof(field.item)); \
> > > > + (unsigned int)sizeof(field.item), \
> > > > + (unsigned int)is_signed_type(type)); \
> > > > if (!ret) \
> > > > return 0;
> > >
> > > I don't mind this change, but it makes me nervous. We really need to
> > > solidify the output format file. This is adding a new field and will
> > > already break the parsers in perf and trace_cmd.
> > >
> > > Is there anything else that is needed? I really want to make sure that
> > > we don't need to modify the output of the format files any more.
> > >
> >
> > One of the things I had in mind when writing this patchset was to make
> > sure that what was there already was enough to write something real on
> > top of. The only thing I found I needed to add was the signed field,
> > and that was enough at least for the Perl case, where everything can be
> > mapped into 3 types - signed, unsigned and string.
> >
> > Other languages might demand more - I haven't looked into it - so I
> > couldn't say whether anything else is needed, but it would seem to
> > me that the current combination of type description strings, sizes
> > and signs for each field should be enough information to allow any
> > field to be passed into any scripting interpreter. Actually, you
> > could probably forget about signs and sizes and just manage on type
> > description strings alone, if you had a typemap that mapped from the
> > C type descriptions to the types expected by a given interpreter.
> > That might be what some language implementations would end up doing,
> > but at least for the Perl implementation, it's much more convenient
> > to have the is_signed field.
>
> Actually I was thinking that the print format part of the format file
> would give enough to know if the object was signed or not, or even the
> type (unsigned long, etc). But we are still early in this game, and I
> would like to think that we are still early enough to be able to
> change these formats. But it's getting close that they will soon be
> locked in stone.

Note, the format _must_ be extensible, even if existing bits are cast
into stone. I.e. if a new type or a new sub-type comes up, we want to be
able to add it - and we want to fix all parsers to be ready for that.

Ingo

2009-10-11 12:17:14

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support

On Sun, Oct 11, 2009 at 10:58:46AM +0200, Ingo Molnar wrote:
>
> * Tom Zanussi <[email protected]> wrote:
>
> > On Wed, 2009-10-07 at 10:13 -0400, Christoph Hellwig wrote:
> > > On Tue, Oct 06, 2009 at 11:09:25PM -0500, Tom Zanussi wrote:
> > > > > I think we also want to have a 'perf -s *' kind of thing to get a list
> > > > > of all available language modules.
> > > > >
> > > >
> > > > I knew somebody would point that out (and suggest a better way ;-) That
> > > > all makes sense - I'll make these changes in the next version.
> > >
> > > I'm a bit worried about linking two million scripting language into the
> > > main perf binary. Can't we just have seaprate perlperf / pythonperf,
> > > rubyperf, awkperf binaries that only contain the scripting support?
> >
> > Yeah, that's a good point. [...]
>
> No, we want to keep a single core binary, it has many advantages. Git
> has gone through a very painful conversion from many spread out git-*
> commands back into a central binary. So we avoided that mistake in perf
> from the get go. We are not going to add separate perf-* commands.
>
> ad-hoc extensions using separate perf-* scripts are fine of course and i
> use that myself. But once a facility is part of core perf it wants to
> move into the binary. Especially something as central as scripting
> support.
>
> Thanks,
>
> Ingo


But I think we may want to have some integrated scripts that can
play the role of subcommands when it comes to process
particular trace events. Because this is just about reading binary
traces and put them in a shape that makes sense wrt to the targeted events.

So I think in this particular area we should better choose scripting
languages. If we limit us to the C in this field, we restrict us
in a slow development.

Re-implemeting the workqueue profiler in Python/Perl/Whatever would
take several hours. In C it's several days, with potential security
holes inside...

2009-10-12 06:03:59

by Ingo Molnar

[permalink] [raw]
Subject: Re: [RFC][PATCH 5/9] perf trace: Add Perl scripting support


* Frederic Weisbecker <[email protected]> wrote:

> > ad-hoc extensions using separate perf-* scripts are fine of course
> > and i use that myself. But once a facility is part of core perf it
> > wants to move into the binary. Especially something as central as
> > scripting support.
>
> But I think we may want to have some integrated scripts that can play
> the role of subcommands when it comes to process particular trace
> events. Because this is just about reading binary traces and put them
> in a shape that makes sense wrt to the targeted events.

Maybe - and even in those cases we can still embedd those scripts in the
binary itself (i.e. we can add a mechanism to embedd it as a string and
execute it from there). It's not like people are going to edit an
installed script in a bin/ or libexec/ path.

Same goes for any .xml file should we grow a GUI - etc.

Ingo