From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752349AbdLLQHZ (ORCPT ); Tue, 12 Dec 2017 11:07:25 -0500 Received: from mga05.intel.com ([192.55.52.43]:64676 "EHLO mga05.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751577AbdLLQHW (ORCPT ); Tue, 12 Dec 2017 11:07:22 -0500 X-Amp-Result: SKIPPED(no attachment in message) X-Amp-File-Uploaded: False X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.45,395,1508828400"; d="scan'208";a="1840897" Message-ID: <1513094839.18728.13.camel@tzanussi-mobl.amr.corp.intel.com> Subject: Re: [PATCH v7 24/37] tracing: Add support for 'synthetic' events From: Tom Zanussi To: Namhyung Kim Cc: rostedt@goodmis.org, tglx@linutronix.de, mhiramat@kernel.org, vedang.patel@intel.com, bigeasy@linutronix.de, joel.opensrc@gmail.com, joelaf@google.com, mathieu.desnoyers@efficios.com, baohong.liu@intel.com, rajvi.jingar@intel.com, julia@ni.com, fengguang.wu@intel.com, linux-kernel@vger.kernel.org, linux-rt-users@vger.kernel.org, kernel-team@lge.com Date: Tue, 12 Dec 2017 10:07:19 -0600 In-Reply-To: <20171212144201.GA21538@danjae.aot.lge.com> References: <20171212144201.GA21538@danjae.aot.lge.com> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.10.4 (3.10.4-4.fc20) Mime-Version: 1.0 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hi Namhyung, On Tue, 2017-12-12 at 23:42 +0900, Namhyung Kim wrote: > On Wed, Dec 06, 2017 at 04:38:05PM -0600, Tom Zanussi wrote: > > Synthetic events are user-defined events generated from hist trigger > > variables saved from one or more other events. > > > > To define a synthetic event, the user writes a simple specification > > consisting of the name of the new event along with one or more > > variables and their type(s), to the tracing/synthetic_events file. > > > > For instance, the following creates a new event named 'wakeup_latency' > > with 3 fields: lat, pid, and prio: > > > > # echo 'wakeup_latency u64 lat; pid_t pid; int prio' >> \ > > /sys/kernel/debug/tracing/synthetic_events > > > > Reading the tracing/synthetic_events file lists all the > > currently-defined synthetic events, in this case the event we defined > > above: > > > > # cat /sys/kernel/debug/tracing/synthetic_events > > wakeup_latency u64 lat; pid_t pid; int prio > > > > At this point, the synthetic event is ready to use, and a histogram > > can be defined using it: > > > > # echo 'hist:keys=pid,prio,lat.log2:sort=pid,lat' >> \ > > /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger > > > > The new event is created under the tracing/events/synthetic/ directory > > and looks and behaves just like any other event: > > > > # ls /sys/kernel/debug/tracing/events/synthetic/wakeup_latency > > enable filter format hist id trigger > > > > Although a histogram can be defined for it, nothing will happen until > > an action tracing that event via the trace_synth() function occurs. > > The trace_synth() function is very similar to all the other trace_* > > invocations spread throughout the kernel, except in this case the > > trace_ function and its corresponding tracepoint isn't statically > > generated but defined by the user at run-time. > > > > How this can be automatically hooked up via a hist trigger 'action' is > > discussed in a subsequent patch. > > > > Signed-off-by: Tom Zanussi > > [fix noderef.cocci warnings, sizeof pointer for kcalloc of event->fields] > > Signed-off-by: Fengguang Wu > > --- > > [SNIP] > > +static enum print_line_t print_synth_event(struct trace_iterator *iter, > > + int flags, > > + struct trace_event *event) > > +{ > > + struct trace_array *tr = iter->tr; > > + struct trace_seq *s = &iter->seq; > > + struct synth_trace_event *entry; > > + struct synth_event *se; > > + unsigned int i, n_u64; > > + char print_fmt[32]; > > + const char *fmt; > > + > > + entry = (struct synth_trace_event *)iter->ent; > > + se = container_of(event, struct synth_event, call.event); > > + > > + trace_seq_printf(s, "%s: ", se->name); > > + > > + for (i = 0, n_u64 = 0; i < se->n_fields; i++) { > > + if (trace_seq_has_overflowed(s)) > > + goto end; > > + > > + fmt = synth_field_fmt(se->fields[i]->type); > > + > > + /* parameter types */ > > + if (tr->trace_flags & TRACE_ITER_VERBOSE) > > + trace_seq_printf(s, "%s ", fmt); > > + > > + snprintf(print_fmt, sizeof(print_fmt), "%%s=%s%%s", fmt); > > + > > + /* parameter values */ > > + if (se->fields[i]->is_string) { > > + trace_seq_printf(s, print_fmt, se->fields[i]->name, > > + (char *)(long)entry->fields[n_u64], > > Hmm.. shouldn't it be (char *)&entry->fields[n_u64] ? > Yes, thanks for pointing this out - looks like I need to add something that enables string-containing synthetic events and looks at the trace file display to my testing.. Tom > Thanks, > Namhyung > > > > + i == se->n_fields - 1 ? "" : " "); > > + n_u64 += STR_VAR_LEN_MAX / sizeof(u64); > > + } else { > > + trace_seq_printf(s, print_fmt, se->fields[i]->name, > > + entry->fields[n_u64], > > + i == se->n_fields - 1 ? "" : " "); > > + n_u64++; > > + } > > + } > > +end: > > + trace_seq_putc(s, '\n'); > > + > > + return trace_handle_return(s); > > +}