Re: [patch 9/9] pref: session: Break event ordering when timestamps are missing

From: Ian Munsie
Date: Wed Dec 08 2010 - 22:50:29 EST


Excerpts from Thomas Gleixner's message of Tue Dec 07 12:49:04 UTC 2010:
> Allow the session client to specify that event ordering should be
> stopped when not all events have time stamps.

> /* These events are processed right away */
> switch (event->header.type) {
> case PERF_RECORD_HEADER_ATTR:
> - return ops->attr(event, session);
> + /* This updates session->sample_id_all */
> + ret = ops->attr(event, session);
> + /* Break ordering if sample_id_all is false */
> + if (ops->ordering_requires_timestamps &&
> + ops->ordered_samples && !session->sample_id_all) {
> + session->ordered_samples.next_flush = ULLONG_MAX;
> + flush_sample_queue(session, ops);
> + ops->ordered_samples = false;
> + }
> + return ret;

This fallback still relies on receiving a PERF_RECORD_HEADER_ATTR, which
will only happen if the output is being piped:

$ git grep event__synthesize_attr
builtin-record.c: err = event__synthesize_attrs(&session->header,
util/header.c:int event__synthesize_attr(struct perf_event_attr *attr, u16 ids, u64 *id,
util/header.c:int event__synthesize_attrs(struct perf_header *self, event__handler_t process,
util/header.c: err = event__synthesize_attr(&attr->attr, attr->ids, attr->id,
util/header.h:int event__synthesize_attr(struct perf_event_attr *attr, u16 ids, u64 *id,
util/header.h:int event__synthesize_attrs(struct perf_header *self,

$ less builtin-record.c
<SNIP>
if (pipe_output) {
err = event__synthesize_attrs(&session->header,
process_synthesized_event,
session);
<SNIP>

So this will work in this situation (timestamps on samples, but this is
an old kernel so not on other events):

delenn% ./perf record -T -o - ~/tests/cachetest | ./perf report -i -
Initialising array...
Trying approach 1: 0x18fff7eb26fd058
Trying approach 2: 0x18fff7eb26fd058
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.081 MB - (~3549 samples) ]
# Events: 1K cycles
#
# Overhead Command Shared Object Symbol
# ........ ....... ................. .......................
#
70.23% cachetest cachetest [.] sumArrayNaive
28.54% cachetest cachetest [.] sumArrayOptimal
0.43% cachetest [kernel.kallsyms] [k] insert_work
0.39% cachetest [kernel.kallsyms] [k] machine_kexec_prepare
0.35% cachetest libc-2.11.2.so [.] __random
0.06% cachetest [kernel.kallsyms] [k] print_cfs_rq
0.01% cachetest [kernel.kallsyms] [k] __register_sysctl_paths


#
# (For a higher level overview, try: perf report --sort comm,dso)
#


But will fail in this case:

delenn% ./perf record -T ~/tests/cachetest ~/linus/tools/perf
Initialising array...
Trying approach 1: 0x18fff7eb26fd058
Trying approach 2: 0x18fff7eb26fd058
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.081 MB perf.data (~3543 samples) ]

delenn% ./perf report|cat ~/linus/tools/perf
# Events: 1K cycles
#
# Overhead Command Shared Object Symbol
# ........ ....... ................. .......................
#
99.47% :5593 [unknown] [.] 0xf770cff5
0.48% :5593 [kernel.kallsyms] [k] hpet_next_event
0.05% :5593 [libahci] [k] ahci_scr_read
0.01% :5593 [kernel.kallsyms] [k] flush_signal_handlers
0.00% :5593 [kernel.kallsyms] [k] native_write_msr_safe


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

Since the fall back isn't triggered, not only are COMM and MMAP events
processed first (from patch 2 in this series), but EXIT will as well,
which causes no userspace events to be attributed.

Cheers,
-Ian
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/