From 119023d660b7f0403acee57e84047f9303996d28 Mon Sep 17 00:00:00 2001 From: Douglas Raillard Date: Tue, 23 May 2023 15:04:10 +0100 Subject: [PATCH 1/5] lisa.conf: Support typing.Union FEATURE Support typing.Union in lisa.conf.KeyDesc. --- lisa/_generic.py | 38 ++++++++++++++++++++++++++++++++++---- 1 file changed, 34 insertions(+), 4 deletions(-) diff --git a/lisa/_generic.py b/lisa/_generic.py index d06d60e7d..3b1fae86b 100644 --- a/lisa/_generic.py +++ b/lisa/_generic.py @@ -25,6 +25,29 @@ from operator import attrgetter from lisa.utils import sphinx_register_nitpick_ignore +def _isinstance(x, type_): + if isinstance(type_, tuple): + return any(map(lambda type_: _isinstance(x, type_), type_)) + elif isinstance(type_, type): + return isinstance(x, type_) + # Typing hint + else: + try: + from typing import get_origin, get_args, Union + except ImportError: + # We cannot process the typing hint in that version of Python, so + # we assume the input is correctly typed. It's not ideal but we + # cannot do much more than that. + return True + else: + combinator = get_origin(type_) + args = get_args(type_) + if combinator == Union: + return any(map(lambda type_: _isinstance(x, type_), args)) + else: + raise TypeError(f'Cannot handle type hint: {type_}') + + class GenericContainerMetaBase(type): """ Base class for the metaclass of generic containers. @@ -52,9 +75,16 @@ class GenericContainerMetaBase(type): types = type_ if isinstance(type_, Sequence) else [type_] def make_name(self_getter, sub_getter): + def _sub_getter(type_): + try: + return sub_getter(type_) + # type hints like typing.Union don't have a name we can introspect, + # but it can be pretty-printed + except AttributeError: + return str(type_) return '{}[{}]'.format( self_getter(cls), - ','.join(sub_getter(type_) for type_ in types) + ','.join(_sub_getter(type_) for type_ in types) ) NewClass.__name__ = make_name( @@ -107,10 +137,10 @@ class GenericMappingMeta(GenericContainerMetaBase, type(Mapping)): k_type, v_type = cls._type for k, v in instance.items(): - if not isinstance(k, k_type): + if not _isinstance(k, k_type): raise TypeError(f'Key "{k}" of type {type(k).__qualname__} should be of type {k_type.__qualname__}', k) - if not isinstance(v, v_type): + if not _isinstance(v, v_type): raise TypeError(f'Value of {type(v).__qualname__} key "{k}" should be of type {v_type.__qualname__}', k) @@ -128,7 +158,7 @@ class GenericSequenceMeta(GenericContainerMetaBase, type(Sequence)): type_ = cls._type for i, x in enumerate(instance): - if not isinstance(x, type_): + if not _isinstance(x, type_): raise TypeError(f'Item #{i} "{x}" of type {type(x).__qualname__} should be of type {type_.__qualname__}', i) class GenericSortedSequenceMeta(GenericSequenceMeta): -- GitLab From 317a3c00526cc9ad3a8ee6de4187bd2d7464ade3 Mon Sep 17 00:00:00 2001 From: Douglas Raillard Date: Tue, 23 May 2023 10:13:54 +0100 Subject: [PATCH 2/5] lisa._assets.kmodules.sched_tp: Change subsystem of ftrace events FEATURE Group ftrace events we create under the "lisa" subsystem, so that they are more easily discoverable. --- lisa/_assets/kmodules/sched_tp/ftrace_events.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lisa/_assets/kmodules/sched_tp/ftrace_events.h b/lisa/_assets/kmodules/sched_tp/ftrace_events.h index 6bae72509..2f7eb089f 100644 --- a/lisa/_assets/kmodules/sched_tp/ftrace_events.h +++ b/lisa/_assets/kmodules/sched_tp/ftrace_events.h @@ -1,6 +1,6 @@ /* SPDX-License-Identifier: GPL-2.0 */ #undef TRACE_SYSTEM -#define TRACE_SYSTEM sched +#define TRACE_SYSTEM lisa #define MAX_SPAN_SIZE 128 -- GitLab From 664407ffa0a72f747336a7f5f88f6e0f0122cc4c Mon Sep 17 00:00:00 2001 From: Douglas Raillard Date: Tue, 23 May 2023 10:16:06 +0100 Subject: [PATCH 3/5] lisa._assets.kmodules.sched_tp: Add "lisa__" prefix to all event names FEATURE Add a "lisa__" prefix to all event names, so that they will not clash with any existing events in the target's kernel. --- .../_assets/kmodules/sched_tp/ftrace_events.h | 36 ++++++------- lisa/_assets/kmodules/sched_tp/pixel6.c | 2 +- lisa/_assets/kmodules/sched_tp/tp.c | 52 +++++++++---------- 3 files changed, 45 insertions(+), 45 deletions(-) diff --git a/lisa/_assets/kmodules/sched_tp/ftrace_events.h b/lisa/_assets/kmodules/sched_tp/ftrace_events.h index 2f7eb089f..f98366774 100644 --- a/lisa/_assets/kmodules/sched_tp/ftrace_events.h +++ b/lisa/_assets/kmodules/sched_tp/ftrace_events.h @@ -27,7 +27,7 @@ #define RBL_LOAD_STR "runnable" #endif -TRACE_EVENT(sched_pelt_cfs, +TRACE_EVENT(lisa__sched_pelt_cfs, TP_PROTO(int cpu, char *path, const struct sched_avg *avg), @@ -56,7 +56,7 @@ TRACE_EVENT(sched_pelt_cfs, __entry->RBL_LOAD_ENTRY,__entry->util, __entry->update_time) ); -DECLARE_EVENT_CLASS(sched_pelt_rq_template, +DECLARE_EVENT_CLASS(lisa__sched_pelt_rq_template, TP_PROTO(int cpu, const struct sched_avg *avg), @@ -83,19 +83,19 @@ DECLARE_EVENT_CLASS(sched_pelt_rq_template, __entry->RBL_LOAD_ENTRY,__entry->util, __entry->update_time) ); -DEFINE_EVENT(sched_pelt_rq_template, sched_pelt_rt, +DEFINE_EVENT(lisa__sched_pelt_rq_template, lisa__sched_pelt_rt, TP_PROTO(int cpu, const struct sched_avg *avg), TP_ARGS(cpu, avg)); -DEFINE_EVENT(sched_pelt_rq_template, sched_pelt_dl, +DEFINE_EVENT(lisa__sched_pelt_rq_template, lisa__sched_pelt_dl, TP_PROTO(int cpu, const struct sched_avg *avg), TP_ARGS(cpu, avg)); -DEFINE_EVENT(sched_pelt_rq_template, sched_pelt_irq, +DEFINE_EVENT(lisa__sched_pelt_rq_template, lisa__sched_pelt_irq, TP_PROTO(int cpu, const struct sched_avg *avg), TP_ARGS(cpu, avg)); -TRACE_EVENT(sched_pelt_se, +TRACE_EVENT(lisa__sched_pelt_se, TP_PROTO(int cpu, char *path, char *comm, int pid, const struct sched_avg *avg), @@ -128,7 +128,7 @@ TRACE_EVENT(sched_pelt_se, __entry->load, __entry->RBL_LOAD_ENTRY,__entry->util, __entry->update_time) ); -TRACE_EVENT(sched_overutilized, +TRACE_EVENT(lisa__sched_overutilized, TP_PROTO(int overutilized, char *span), @@ -149,7 +149,7 @@ TRACE_EVENT(sched_overutilized, ); #if LINUX_VERSION_CODE >= KERNEL_VERSION(5,9,0) -TRACE_EVENT(sched_update_nr_running, +TRACE_EVENT(lisa__sched_update_nr_running, TP_PROTO(int cpu, int change, unsigned int nr_running), @@ -170,7 +170,7 @@ TRACE_EVENT(sched_update_nr_running, TP_printk("cpu=%d change=%d nr_running=%d", __entry->cpu, __entry->change, __entry->nr_running) ); -TRACE_EVENT(sched_util_est_se, +TRACE_EVENT(lisa__sched_util_est_se, TP_PROTO(int cpu, char *path, char *comm, int pid, const struct sched_avg *avg), @@ -202,7 +202,7 @@ TRACE_EVENT(sched_util_est_se, __entry->enqueued, __entry->ewma, __entry->util) ); -TRACE_EVENT(sched_util_est_cfs, +TRACE_EVENT(lisa__sched_util_est_cfs, TP_PROTO(int cpu, char *path, const struct sched_avg *avg), @@ -232,7 +232,7 @@ TRACE_EVENT(sched_util_est_cfs, #ifdef CONFIG_UCLAMP_TASK -TRACE_EVENT_CONDITION(uclamp_util_se, +TRACE_EVENT_CONDITION(lisa__uclamp_util_se, TP_PROTO(bool is_task, struct task_struct *p, struct rq *rq), @@ -267,7 +267,7 @@ TRACE_EVENT_CONDITION(uclamp_util_se, __entry->uclamp_min, __entry->uclamp_max) ); -TRACE_EVENT_CONDITION(uclamp_util_cfs, +TRACE_EVENT_CONDITION(lisa__uclamp_util_cfs, TP_PROTO(bool is_root, struct rq *rq, struct cfs_rq *cfs_rq), @@ -297,14 +297,14 @@ TRACE_EVENT_CONDITION(uclamp_util_cfs, __entry->uclamp_min, __entry->uclamp_max) ); #else -#define trace_uclamp_util_se(is_task, p, rq) while(false) {} -#define trace_uclamp_util_se_enabled() false -#define trace_uclamp_util_cfs(is_root, cpu, cfs_rq) while(false) {} -#define trace_uclamp_util_cfs_enabled() false +#define trace_lisa__uclamp_util_se(is_task, p, rq) while(false) {} +#define trace_lisa__uclamp_util_se_enabled() false +#define trace_lisa__uclamp_util_cfs(is_root, cpu, cfs_rq) while(false) {} +#define trace_lisa__uclamp_util_cfs_enabled() false #endif /* CONFIG_UCLAMP_TASK */ #if LINUX_VERSION_CODE >= KERNEL_VERSION(5,10,0) && (defined(CONFIG_ARM64) || defined(CONFIG_ARM)) -TRACE_EVENT(sched_cpu_capacity, +TRACE_EVENT(lisa__sched_cpu_capacity, TP_PROTO(struct rq *rq), @@ -335,7 +335,7 @@ TRACE_EVENT(sched_cpu_capacity, #define PIXEL6_EMETER_CHAN_NAME_MAX_SIZE 64 -TRACE_EVENT(pixel6_emeter, +TRACE_EVENT(lisa__pixel6_emeter, TP_PROTO(unsigned long ts, unsigned int device, unsigned int chan, char *chan_name, unsigned long value), TP_ARGS(ts, device, chan, chan_name, value), diff --git a/lisa/_assets/kmodules/sched_tp/pixel6.c b/lisa/_assets/kmodules/sched_tp/pixel6.c index 5ce37e673..1cbf110ee 100644 --- a/lisa/_assets/kmodules/sched_tp/pixel6.c +++ b/lisa/_assets/kmodules/sched_tp/pixel6.c @@ -233,7 +233,7 @@ int process_sample(int nr, sample_t sample) { /* pr_info("parsed: device=%u chan=%u, ts=%lu chan_name=%s value=%lu\n", sample.device, sample.chan, */ /* sample.ts, sample.chan_name, sample.value); */ - trace_pixel6_emeter(sample.ts, sample.device, sample.chan, sample.chan_name, sample.value); + trace_lisa__pixel6_emeter(sample.ts, sample.device, sample.chan, sample.chan_name, sample.value); return nr + 1; } diff --git a/lisa/_assets/kmodules/sched_tp/tp.c b/lisa/_assets/kmodules/sched_tp/tp.c index 097cf1730..bf524fe9c 100644 --- a/lisa/_assets/kmodules/sched_tp/tp.c +++ b/lisa/_assets/kmodules/sched_tp/tp.c @@ -49,15 +49,15 @@ static inline void _trace_se(struct sched_entity *se, static void sched_pelt_cfs_probe(struct feature *feature, struct cfs_rq *cfs_rq) { - _trace_cfs(cfs_rq, trace_sched_pelt_cfs); + _trace_cfs(cfs_rq, trace_lisa__sched_pelt_cfs); } -DEFINE_TP_EVENT_FEATURE(sched_pelt_cfs, pelt_cfs_tp, sched_pelt_cfs_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_pelt_cfs, pelt_cfs_tp, sched_pelt_cfs_probe); static void uclamp_util_cfs_probe(struct feature *feature, struct cfs_rq *cfs_rq) { bool __maybe_unused is_root_rq = ((struct cfs_rq *)&rq_of(cfs_rq)->cfs == cfs_rq); - trace_uclamp_util_cfs(is_root_rq, rq_of(cfs_rq), cfs_rq); + trace_lisa__uclamp_util_cfs(is_root_rq, rq_of(cfs_rq), cfs_rq); } -DEFINE_TP_EVENT_FEATURE(uclamp_util_cfs, pelt_cfs_tp, uclamp_util_cfs_probe); +DEFINE_TP_EVENT_FEATURE(lisa__uclamp_util_cfs, pelt_cfs_tp, uclamp_util_cfs_probe); static void sched_pelt_rt_probe(struct feature *feature, struct rq *rq) { @@ -67,9 +67,9 @@ static void sched_pelt_rt_probe(struct feature *feature, struct rq *rq) if (!avg) return; - trace_sched_pelt_rt(cpu, avg); + trace_lisa__sched_pelt_rt(cpu, avg); } -DEFINE_TP_EVENT_FEATURE(sched_pelt_rt, pelt_rt_tp, sched_pelt_rt_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_pelt_rt, pelt_rt_tp, sched_pelt_rt_probe); static void sched_pelt_dl_probe(struct feature *feature, struct rq *rq) { @@ -79,9 +79,9 @@ static void sched_pelt_dl_probe(struct feature *feature, struct rq *rq) if (!avg) return; - trace_sched_pelt_dl(cpu, avg); + trace_lisa__sched_pelt_dl(cpu, avg); } -DEFINE_TP_EVENT_FEATURE(sched_pelt_dl, pelt_dl_tp, sched_pelt_dl_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_pelt_dl, pelt_dl_tp, sched_pelt_dl_probe); static void sched_pelt_irq_probe(struct feature *feature, struct rq *rq) { @@ -91,70 +91,70 @@ static void sched_pelt_irq_probe(struct feature *feature, struct rq *rq) if (!avg) return; - trace_sched_pelt_irq(cpu, avg); + trace_lisa__sched_pelt_irq(cpu, avg); } -DEFINE_TP_EVENT_FEATURE(sched_pelt_irq, pelt_irq_tp, sched_pelt_irq_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_pelt_irq, pelt_irq_tp, sched_pelt_irq_probe); static void sched_pelt_se_probe(struct feature *feature, struct sched_entity *se) { - _trace_se(se, trace_sched_pelt_se); + _trace_se(se, trace_lisa__sched_pelt_se); } -DEFINE_TP_EVENT_FEATURE(sched_pelt_se, pelt_se_tp, sched_pelt_se_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_pelt_se, pelt_se_tp, sched_pelt_se_probe); static void uclamp_util_se_probe(struct feature *feature, struct sched_entity *se) { struct cfs_rq __maybe_unused *cfs_rq = get_se_cfs_rq(se); - trace_uclamp_util_se(entity_is_task(se), + trace_lisa__uclamp_util_se(entity_is_task(se), container_of(se, struct task_struct, se), rq_of(cfs_rq)); } -DEFINE_TP_EVENT_FEATURE(uclamp_util_se, pelt_se_tp, uclamp_util_se_probe); +DEFINE_TP_EVENT_FEATURE(lisa__uclamp_util_se, pelt_se_tp, uclamp_util_se_probe); static void sched_overutilized_probe(struct feature *feature, struct root_domain *rd, bool overutilized) { - if (trace_sched_overutilized_enabled()) { + if (trace_lisa__sched_overutilized_enabled()) { char span[SPAN_SIZE]; cpumap_print_to_pagebuf(false, span, sched_tp_rd_span(rd)); - trace_sched_overutilized(overutilized, span); + trace_lisa__sched_overutilized(overutilized, span); } } -DEFINE_TP_EVENT_FEATURE(sched_overutilized, sched_overutilized_tp, sched_overutilized_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_overutilized, sched_overutilized_tp, sched_overutilized_probe); #if LINUX_VERSION_CODE >= KERNEL_VERSION(5,9,0) static void sched_update_nr_running_probe(struct feature *feature, struct rq *rq, int change) { - if (trace_sched_update_nr_running_enabled()) { + if (trace_lisa__sched_update_nr_running_enabled()) { int cpu = sched_tp_rq_cpu(rq); int nr_running = sched_tp_rq_nr_running(rq); - trace_sched_update_nr_running(cpu, change, nr_running); + trace_lisa__sched_update_nr_running(cpu, change, nr_running); } } -DEFINE_TP_EVENT_FEATURE(sched_update_nr_running, sched_update_nr_running_tp, sched_update_nr_running_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_update_nr_running, sched_update_nr_running_tp, sched_update_nr_running_probe); static void sched_util_est_cfs_probe(struct feature *feature, struct cfs_rq *cfs_rq) { - _trace_cfs(cfs_rq, trace_sched_util_est_cfs); + _trace_cfs(cfs_rq, trace_lisa__sched_util_est_cfs); } -DEFINE_TP_EVENT_FEATURE(sched_util_est_cfs, sched_util_est_cfs_tp, sched_util_est_cfs_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_util_est_cfs, sched_util_est_cfs_tp, sched_util_est_cfs_probe); static void sched_util_est_se_probe(struct feature *feature, struct sched_entity *se) { - _trace_se(se, trace_sched_util_est_se); + _trace_se(se, trace_lisa__sched_util_est_se); } -DEFINE_TP_EVENT_FEATURE(sched_util_est_se, sched_util_est_se_tp, sched_util_est_se_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_util_est_se, sched_util_est_se_tp, sched_util_est_se_probe); #endif #if LINUX_VERSION_CODE >= KERNEL_VERSION(5,10,0) && (defined(CONFIG_ARM64) || defined(CONFIG_ARM)) static void sched_cpu_capacity_probe(struct feature *feature, struct rq *rq) { - trace_sched_cpu_capacity(rq); + trace_lisa__sched_cpu_capacity(rq); } -DEFINE_TP_EVENT_FEATURE(sched_cpu_capacity, sched_cpu_capacity_tp, sched_cpu_capacity_probe); +DEFINE_TP_EVENT_FEATURE(lisa__sched_cpu_capacity, sched_cpu_capacity_tp, sched_cpu_capacity_probe); #endif static int init_tp(struct feature *_) -- GitLab From 9c88c3eca2bba2bb8eb5c4df9382ad28ed5ebedf Mon Sep 17 00:00:00 2001 From: Douglas Raillard Date: Tue, 23 May 2023 10:23:09 +0100 Subject: [PATCH 4/5] lisa.trace: Add Trace(..., namespaces=("lisa", None)) parameter FEATURE Add support for event namespacing, which avoids name clashes while allowing backward compatibility. The namespaces to lookup are set on Trace() constructor and can be overridden in Trace.df_event(namespaces=[...]). The full event name looked up in a given namespace is __. Each namespace specified will be tried in order until there is a match. None is a special namespace that adds no prefix. Note that setting the ftrace event subsystem is not enough to isolate events, as they still live in a single "C source namespace" given that the trace_* functions do not take the subsystem into account. --- lisa/_kmod.py | 32 +++ lisa/datautils.py | 76 ++++--- lisa/trace.py | 515 +++++++++++++++++++++++++++++++++------------- 3 files changed, 447 insertions(+), 176 deletions(-) diff --git a/lisa/_kmod.py b/lisa/_kmod.py index ac069b510..54a67027c 100644 --- a/lisa/_kmod.py +++ b/lisa/_kmod.py @@ -1585,6 +1585,14 @@ class KmodSrc(Loggable): } self._mod_name = name + @property + def code_files(self): + return { + name: content + for name, content in self.src.items() + if name.endswith('.c') or name.endswith('.h') + } + @property def c_files(self): return { @@ -2037,6 +2045,30 @@ class FtraceDynamicKmod(DynamicKmod): if m )) + @property + @memoized + def possible_events(self): + """ + Ftrace events possibly defined in that module. + + Note that this is based on crude source code analysis so it's expected + to be a superset of the actually defined events. + """ + decomment = re.compile(rb'^.*//.*?$|/\*.*?\*/', flags=re.MULTILINE) + + # We match trace_lisa__XXX tokens, as these are the events that are + # actually used inside the module. + find_event = re.compile(rb'\btrace_(lisa__.*?)\b') + def find_events(code): + code = decomment.sub(b'', code) + return map(bytes.decode, find_event.findall(code)) + + return sorted({ + possible_event + for code in self.src.code_files.values() + for possible_event in find_events(code) + }) + class LISAFtraceDynamicKmod(FtraceDynamicKmod): """ diff --git a/lisa/datautils.py b/lisa/datautils.py index 424ac3988..a4011e256 100644 --- a/lisa/datautils.py +++ b/lisa/datautils.py @@ -1650,39 +1650,49 @@ class SignalDesc: The hand-coded list is used first, and then some generic heuristics are used to detect per-cpu and per-task signals. """ - try: - return cls._SIGNALS_MAP[event] - except KeyError: - if not fields: - return [cls(event, fields=[])] - else: - fields = set(fields) - # At most one set of each group will be taken - default_field_sets = [ - [ - {'comm', 'pid'}, - {'pid'}, - {'comm'}, - ], - [ - {'cpu'}, - {'cpu_id'}, - ], - ] - - selected = [] - for field_set_group in default_field_sets: - # Select at most one field set per group - for field_set in field_set_group: - # if fields is a non-strict superset of field_set - if fields >= field_set: - selected.append(field_set) - break - - return [ - cls(event, fields=field_set) - for field_set in selected - ] + + # For backward compatibility, so that we still get signal descriptors + # for traces before the events from the lisa module got renamed to + # lisa__ + from lisa.trace import Trace + events = Trace._expand_namespaces(event, namespaces=('lisa', None)) + + for event in events: + try: + return cls._SIGNALS_MAP[event] + except KeyError: + continue + + if not fields: + return [cls(event, fields=[])] + else: + fields = set(fields) + # At most one set of each group will be taken + default_field_sets = [ + [ + {'comm', 'pid'}, + {'pid'}, + {'comm'}, + ], + [ + {'cpu'}, + {'cpu_id'}, + ], + ] + + selected = [] + for field_set_group in default_field_sets: + # Select at most one field set per group + for field_set in field_set_group: + # if fields is a non-strict superset of field_set + if fields >= field_set: + selected.append(field_set) + break + + return [ + cls(event, fields=field_set) + for field_set in selected + ] @SeriesAccessor.register_accessor diff --git a/lisa/trace.py b/lisa/trace.py index fe6d81516..610d709f8 100644 --- a/lisa/trace.py +++ b/lisa/trace.py @@ -44,6 +44,7 @@ import subprocess import itertools import functools import fnmatch +from typing import Union import numpy as np import pandas as pd @@ -53,7 +54,7 @@ import pyarrow.parquet import devlib -from lisa.utils import Loggable, HideExekallID, memoized, lru_memoized, deduplicate, take, deprecate, nullcontext, measure_time, checksum, newtype, groupby, PartialInit, kwargs_forwarded_to, kwargs_dispatcher, ComposedContextManager, get_nested_key +from lisa.utils import Loggable, HideExekallID, memoized, lru_memoized, deduplicate, take, deprecate, nullcontext, measure_time, checksum, newtype, groupby, PartialInit, kwargs_forwarded_to, kwargs_dispatcher, ComposedContextManager, get_nested_key, bothmethod from lisa.conf import SimpleMultiSrcConf, LevelKeyDesc, KeyDesc, TopLevelKeyDesc, Configurable from lisa._generic import TypedList from lisa.datautils import SignalDesc, df_add_delta, df_deduplicate, df_window, df_window_signals, series_convert @@ -831,6 +832,18 @@ class TxtTraceParserBase(TraceParserBase): @classmethod def _resolve_event_parsers(cls, event_parsers, default_event_parser_cls): default_event_parser_cls = default_event_parser_cls or cls.DEFAULT_EVENT_PARSER_CLS + event_descs = list(cls.EVENT_DESCS.items() or []) + + # Hack so that we use the format of the "lisa__" event even for + # non-LISA events. This allows compatibility with old traces where + # events generated by LISA were not namespaced with the prefix. + extra_descs = [ + (event[len('lisa__'):], desc) + for event, desc in event_descs + if event.startswith('lisa__') + ] + event_descs = event_descs + extra_descs + event_parsers = { **{ event: ( @@ -838,7 +851,7 @@ class TxtTraceParserBase(TraceParserBase): if isinstance(desc, EventParserBase) else default_event_parser_cls(event=event, **desc) ) - for event, desc in cls.EVENT_DESCS.items() or [] + for event, desc in event_descs }, **{ parser.event: parser @@ -1442,7 +1455,7 @@ class TxtTraceParser(TxtTraceParserBase): 'prev_cpu': _KERNEL_DTYPE['cpu'], }, ), - 'sched_cpu_capacity': dict( + 'lisa__sched_cpu_capacity': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'capacity': _KERNEL_DTYPE['util'], @@ -1450,7 +1463,7 @@ class TxtTraceParser(TxtTraceParserBase): 'capacity_curr': _KERNEL_DTYPE['util'], }, ), - 'sched_pelt_cfs': dict( + 'lisa__sched_pelt_cfs': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'load': _KERNEL_DTYPE['util'], @@ -1460,7 +1473,7 @@ class TxtTraceParser(TxtTraceParserBase): 'update_time': _KERNEL_DTYPE['timestamp'], }, ), - 'sched_pelt_se': dict( + 'lisa__sched_pelt_se': dict( fields={ 'comm': _KERNEL_DTYPE['comm'], 'cpu': _KERNEL_DTYPE['cpu'], @@ -1481,13 +1494,13 @@ class TxtTraceParser(TxtTraceParserBase): 'prio': _KERNEL_DTYPE['prio'], }, ), - 'sched_overutilized': dict( + 'lisa__sched_overutilized': dict( fields={ 'overutilized': 'bool', 'span': 'string', }, ), - 'sched_pelt_dl': dict( + 'lisa__sched_pelt_dl': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'load': _KERNEL_DTYPE['util'], @@ -1495,7 +1508,7 @@ class TxtTraceParser(TxtTraceParserBase): 'util': _KERNEL_DTYPE['util'], }, ), - 'sched_pelt_irq': dict( + 'lisa__sched_pelt_irq': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'load': _KERNEL_DTYPE['util'], @@ -1503,7 +1516,7 @@ class TxtTraceParser(TxtTraceParserBase): 'util': _KERNEL_DTYPE['util'], }, ), - 'sched_pelt_rt': dict( + 'lisa__sched_pelt_rt': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'load': _KERNEL_DTYPE['util'], @@ -1518,7 +1531,7 @@ class TxtTraceParser(TxtTraceParserBase): 'prio': _KERNEL_DTYPE['prio'], }, ), - 'sched_util_est_cfs': dict( + 'lisa__sched_util_est_cfs': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'path': _KERNEL_DTYPE['cgroup_path'], @@ -1527,7 +1540,7 @@ class TxtTraceParser(TxtTraceParserBase): 'util': _KERNEL_DTYPE['util'], }, ), - 'sched_util_est_se': dict( + 'lisa__sched_util_est_se': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'comm': _KERNEL_DTYPE['comm'], @@ -1556,7 +1569,7 @@ class TxtTraceParser(TxtTraceParserBase): 'target_cpu': _KERNEL_DTYPE['cpu'], }, ), - 'uclamp_util_cfs': dict( + 'lisa__uclamp_util_cfs': dict( fields={ 'cpu': _KERNEL_DTYPE['cpu'], 'uclamp_avg': _KERNEL_DTYPE['util'], @@ -1565,7 +1578,7 @@ class TxtTraceParser(TxtTraceParserBase): 'util_avg': _KERNEL_DTYPE['util'], }, ), - 'uclamp_util_se': dict( + 'lisa__uclamp_util_se': dict( fields={ 'comm': _KERNEL_DTYPE['comm'], 'cpu': _KERNEL_DTYPE['cpu'], @@ -2266,6 +2279,12 @@ class _AvailableTraceEventsSet: self._trace = trace def __contains__(self, event): + return self.contains(event) + + def contains(self, event, namespaces=None): + return any(map(self._contains, self._trace._expand_namespaces(event, namespaces))) + + def _contains(self, event): trace = self._trace if trace._strict_events and not trace._is_meta_event(event): @@ -2275,7 +2294,7 @@ class _AvailableTraceEventsSet: if event not in trace._parseable_events: # If the trace file is not accessible anymore, we will get an OSError with contextlib.suppress(MissingTraceEventError, OSError): - trace.df_event(event=event, raw=True) + trace.df_event(event=event, raw=True, namespaces=[]) return trace._parseable_events.setdefault(event, False) @@ -3264,6 +3283,14 @@ class Trace(Loggable, TraceBase): .. seealso:: :meth:`df_event` for event formats accepted. :type events: TraceEventCheckerBase or list(str) or None + :param events_namespaces: List of namespaces of the requested events. Each + namespace will be tried in order until the event is found. The + ``None`` namespace can be used to specify no namespace. An empty + list is treated as ``[None]`` The full event name is formed with + ``__``. + :type events_namespaces: list(str or None) + + :param strict_events: When ``True``, all the events specified in ``events`` have to be present, and any other events will be assumed to not be present. This allows early failure and avoid the cost of lazy detection @@ -3459,6 +3486,7 @@ class Trace(Loggable, TraceBase): enable_swap=True, max_swap_size=None, write_swap=True, + events_namespaces=('lisa', None), ): super().__init__() trace_path = str(trace_path) if trace_path else None @@ -3547,10 +3575,28 @@ class Trace(Loggable, TraceBase): else: events = AndTraceEventChecker.from_events(events) + self.events_namespaces = events_namespaces self.events = events # Pre-load the selected events if events: - self._load_cache_raw_df(events, write_swap=True, allow_missing_events=not strict_events) + preload_events = AndTraceEventChecker.from_events( + event_ + for event in events + for event_ in self._expand_namespaces(event) + ) + df_map = self._load_cache_raw_df(preload_events, write_swap=True, allow_missing_events=True) + + missing_events = { + event + for event in events + if not (df_map.keys() & set(self._expand_namespaces(event, events_namespaces))) + } + + if strict_events and missing_events: + raise MissingTraceEventError( + missing_events, + available_events=self.available_events, + ) # Register what we currently have self.plat_info = plat_info @@ -3558,6 +3604,32 @@ class Trace(Loggable, TraceBase): # the Trace is almost fully initialized self.plat_info = plat_info.add_trace_src(self) + @bothmethod + def _expand_namespaces(self_or_cls, event, namespaces=None): + if not isinstance(self_or_cls, type): + namespaces = self_or_cls.events_namespaces if namespaces is None else namespaces + + namespaces = namespaces or (None,) + def expand(event, namespace): + if self_or_cls._is_meta_event(event): + prefix, _ = event.split('@', 1) + return [ + f'{prefix}@{source_}' + for source in self_or_cls.get_event_sources(event) + for source_ in expand(source, namespace) + ] + else: + return [f'{namespace}__{event}'] + + return [ + event_ + for namespace in namespaces + for event_ in ( + expand(event, namespace) + if namespace + else [event] + ) + ] _CACHEABLE_METADATA = { 'time-range', @@ -3663,8 +3735,12 @@ class Trace(Loggable, TraceBase): checked_events = self.available_events max_cpu = max( - int(self.df_event(e)['__cpu'].max()) - for e in checked_events + int(df['__cpu'].max()) + for df in ( + self.df_event(event, namespaces=[]) + for event in checked_events + ) + if '__cpu' in df.columns ) count = max_cpu + 1 self.logger.debug(f"Estimated CPU count from trace: {count}") @@ -3813,7 +3889,7 @@ class Trace(Loggable, TraceBase): def _get_time_range(self, parser=None): return self._get_cacheable_metadata('time-range', parser) - def df_event(self, event, raw=None, window=None, signals=None, signals_init=True, compress_signals_init=False, write_swap=None): + def df_event(self, event, raw=None, window=None, signals=None, signals_init=True, compress_signals_init=False, write_swap=None, namespaces=None): """ Get a dataframe containing all occurrences of the specified trace event in the parsed trace. @@ -3857,6 +3933,11 @@ class Trace(Loggable, TraceBase): :type event: str + :param namespaces: List of namespaces of the requested event. See + :class:`lisa.trace.Trace` ``events_namespaces`` parameters for the + format. A ``None`` value defaults to the trace's namespace. + :type namespaces: list(str or None) or None + :param window: Return a dataframe sliced to fit the given window (in seconds). Note that ``signals_init=True`` will result in including more rows than what you might expect. @@ -3890,7 +3971,26 @@ class Trace(Loggable, TraceBase): time it takes to write it to the cache. :type write_swap: bool """ + call = functools.partial( + self._df_event, + raw=raw, + window=window, + signals=signals, + signals_init=signals_init, + compress_signals_init=compress_signals_init, + write_swap=write_swap, + ) + + for event_ in self._expand_namespaces(event, namespaces): + try: + return call(event=event_) + except MissingTraceEventError as e: + last_excep = e + + raise last_excep + + def _df_event(self, event, raw, window, signals, signals_init, compress_signals_init, write_swap): sanitization_f = self._sanitization_functions.get(event) # Make sure no `None` value flies around in the cache, since it's @@ -3974,7 +4074,7 @@ class Trace(Loggable, TraceBase): # Do not even bother loading the event if we know it cannot be # there. This avoids some OSError in case the trace file has # disappeared - if self._strict_events and not self._is_meta_event(event) and event not in self.available_events: + if self._strict_events and not self._is_meta_event(event) and not self.available_events.contains(event, namespaces=[]): raise MissingTraceEventError([event], available_events=self.available_events) if write_swap is None: @@ -4183,7 +4283,7 @@ class Trace(Loggable, TraceBase): # dataframes one by one for source_event, specs in groupby(meta_specs, key=itemgetter(2)): try: - df = self.df_event(source_event) + df = self.df_event(source_event, namespaces=[]) except MissingTraceEventError: pass else: @@ -4247,7 +4347,7 @@ class Trace(Loggable, TraceBase): # to load them from there as well for event in get_missing(df_map): with contextlib.suppress(MissingTraceEventError): - df_map[event] = self.df_event(event, raw=True) + df_map[event] = self.df_event(event, raw=True, namespaces=[]) return { events_map[event]: df @@ -4311,7 +4411,7 @@ class Trace(Loggable, TraceBase): mapping_df_list = [] def _load(event, name_col, pid_col): - df = self.df_event(event) + df = self.df_event(event, namespaces=[]) # Get a Time column df = df.reset_index() @@ -4323,11 +4423,12 @@ class Trace(Loggable, TraceBase): mapping_df.rename({name_col: 'name', pid_col: 'pid'}, axis=1, inplace=True) mapping_df_list.append(mapping_df) - events = set() + missing = [] def load(event, *args, **kwargs): - events.add(event) - if event in self.available_events: + try: _load(event, *args, **kwargs) + except MissingTraceEventError as e: + missing.append(e.missing_events) load('task_rename', 'oldcomm', 'pid') load('task_rename', 'newcomm', 'pid') @@ -4336,7 +4437,8 @@ class Trace(Loggable, TraceBase): load('sched_switch', 'next_comm', 'next_pid') if not mapping_df_list: - raise MissingTraceEventError(sorted(events), available_events=self.available_events) + missing = OrTraceEventChecker.from_events(events=missing) + raise MissingTraceEventError(missing, available_events=self.available_events) df = pd.concat(mapping_df_list) # Sort by order of appearance @@ -4357,7 +4459,7 @@ class Trace(Loggable, TraceBase): def _task_pid_map(self): return self._get_task_maps()[1] - def has_events(self, events): + def has_events(self, events, namespaces=None): """ Returns True if the specified event is present in the parsed trace, False otherwise. @@ -4365,22 +4467,19 @@ class Trace(Loggable, TraceBase): :param events: trace event name or list of trace events :type events: str or list(str) or TraceEventCheckerBase """ + if isinstance(events, str): - return events in self.available_events - elif isinstance(events, TraceEventCheckerBase): - try: - events.check_events(self.available_events) - except MissingTraceEventError: - return False - else: - return True + events = [events] + + if not isinstance(events, TraceEventCheckerBase): + events = AndTraceEventChecker.from_events(events=events) + + try: + events.check_events(self.available_events, namespaces=namespaces) + except MissingTraceEventError: + return False else: - # Check each event independently in case they have not been parsed - # yet. - return all( - event in self.available_events - for event in events - ) + return True def get_view(self, window, **kwargs): return TraceView(self, window, **kwargs) @@ -4657,7 +4756,7 @@ class Trace(Loggable, TraceBase): return df - @_sanitize_event('sched_overutilized') + @_sanitize_event('lisa__sched_overutilized') def _sanitize_sched_overutilized(self, event, df, aspects): # pylint: disable=unused-argument,no-self-use copied = False @@ -4806,14 +4905,15 @@ class TraceEventCheckerBase(abc.ABC, Loggable, Sequence): :type check: bool """ - def __init__(self, check=True): + def __init__(self, check=True, checkers=None): self.check = check + self.checkers = checkers or [] @abc.abstractmethod - def _check_events(self, event_set): + def _check_events(self, check, event_set): pass - def check_events(self, event_set, check_optional=False): + def check_events(self, event_set, check_optional=False, namespaces=None): """ Check that certain trace events are available in the given set of events. @@ -4830,7 +4930,17 @@ class TraceEventCheckerBase(abc.ABC, Loggable, Sequence): checker = self.map(rewrite) else: checker = self - return checker._check_events(event_set) + + def check(event): + if isinstance(event_set, _AvailableTraceEventsSet): + return event_set.contains(event, namespaces=namespaces) + else: + return any( + event in event_set + for event in Trace._expand_namespaces(event, namespaces) + ) + + return checker._check_events(check=check, event_set=event_set) @abc.abstractmethod def get_all_events(self): @@ -4848,6 +4958,20 @@ class TraceEventCheckerBase(abc.ABC, Loggable, Sequence): with the result. """ + def expand_namespaces(self, namespaces=None): + """ + Build a :class:`TraceEventCheckerBase` that will fixup the event names + to take into account the given namespaces. + """ + def fixup(checker): + if isinstance(checker, TraceEventChecker): + return OrTraceEventChecker.from_events( + Trace._expand_namespaces(checker.event, namespaces=namespaces) + ) + else: + return checker + return self.map(fixup) + def __call__(self, f): """ Decorator for methods that require some given trace events @@ -4996,8 +5120,8 @@ class TraceEventChecker(TraceEventCheckerBase): def get_all_events(self): return {self.event} - def _check_events(self, event_set): - if self.event not in event_set: + def _check_events(self, check, event_set): + if not check(self.event): raise MissingTraceEventError(self, available_events=event_set) def _str_internal(self, style=None, wrapped=True): @@ -5007,6 +5131,35 @@ class TraceEventChecker(TraceEventCheckerBase): def map(self, f): return f(self) +class EmptyTraceEventChecker(TraceEventCheckerBase): + """ + Check for no event at all. + + :param check: Check that the listed events are present in the + ``self.trace`` attribute of the instance on which the decorated + method is applied. If no such attribute is found, no check will be + done. + :type check: bool + """ + + def __init__(self, check=True): + super().__init__(check=check) + + def __bool__(self): + return False + + def get_all_events(self): + return {} + + def _check_events(self, check, event_set): + return True + + def _str_internal(self, style=None, wrapped=True): + return '' + + def map(self, f): + return f(self) + class AssociativeTraceEventChecker(TraceEventCheckerBase): """ @@ -5118,14 +5271,14 @@ class OrTraceEventChecker(AssociativeTraceEventChecker): def __init__(self, event_checkers=None, **kwargs): super().__init__('or', event_checkers, **kwargs) - def _check_events(self, event_set): + def _check_events(self, check, event_set): if not self.checkers: return failed_checker_set = set() for checker in self.checkers: try: - checker.check_events(event_set) + checker._check_events(check=check, event_set=event_set) except MissingTraceEventError as e: failed_checker_set.add(e.missing_events) else: @@ -5143,7 +5296,7 @@ class _OptionalTraceEventCheckerBase(AssociativeTraceEventChecker): def __init__(self, event_checkers=None, **kwargs): super().__init__(',', event_checkers, prefix_str=self._PREFIX_STR, **kwargs) - def _check_events(self, event_set): + def _check_events(self, check, event_set): return @@ -5184,14 +5337,14 @@ class AndTraceEventChecker(AssociativeTraceEventChecker): def __init__(self, event_checkers=None, **kwargs): super().__init__('and', event_checkers, **kwargs) - def _check_events(self, event_set): + def _check_events(self, check, event_set): if not self.checkers: return failed_checker_set = set() for checker in self.checkers: try: - checker.check_events(event_set) + checker._check_events(check=check, event_set=event_set) except MissingTraceEventError as e: failed_checker_set.add(e.missing_events) @@ -5284,9 +5437,10 @@ class MissingTraceEventError(RuntimeError, ValueError): self.available_events = sorted(available_events or []) def __str__(self): - if self.available_events: + available = self.available_events + if available: available = '. Available events are: {}'.format( - ', '.join(sorted(self.available_events))) + ', '.join(sorted(available))) else: available = '' @@ -5303,6 +5457,7 @@ class FtraceConf(SimpleMultiSrcConf, HideExekallID): """ STRUCTURE = TopLevelKeyDesc('ftrace-conf', 'FTrace configuration', ( KeyDesc('events', 'FTrace events to trace', [TypedList[str], TraceEventCheckerBase]), + KeyDesc('event-namespaces', 'FTrace events namespaces to use. See Trace namespace constructor parameter.', [TypedList[Union[str, None], None]]), KeyDesc('functions', 'FTrace functions to trace', [TypedList[str]]), KeyDesc('buffer-size', 'FTrace buffer size', [int]), KeyDesc('trace-clock', 'Clock used while tracing (see "trace_clock" in ftrace.txt kernel doc)', [str, None]), @@ -5350,15 +5505,24 @@ class FtraceConf(SimpleMultiSrcConf, HideExekallID): if key == 'functions': return sorted(set(val) | set(self.get(key, []))) + elif key == 'event-namespaces': + # We already applied the namespaces to the events so the result + # can be cleanly merged according to the original meaning. + return [] elif key == 'events': if not isinstance(val, TraceEventCheckerBase): val = AndTraceEventChecker.from_events(val) if optional_events: val = OptionalTraceEventChecker([val]) + val = val.expand_namespaces(namespaces=conf.get('event-namespaces')) + self_val = self.get(key, []) if not isinstance(self_val, TraceEventCheckerBase): self_val = AndTraceEventChecker.from_events(self_val) + + self_val = val.expand_namespaces(namespaces=self.get('event-namespaces')) + return AndTraceEventChecker([val, self_val]) elif key == 'buffer-size': return max(val, self.get(key, 0)) @@ -5530,85 +5694,134 @@ class FtraceCollector(CollectorBase, Configurable): TOOLS = ['trace-cmd'] _COMPOSITION_ORDER = 0 - def __init__(self, target, *, events=None, functions=None, buffer_size=10240, output_path=None, autoreport=False, trace_clock=None, saved_cmdlines_nr=8192, tracer=None, kmod_auto_load=True, **kwargs): + def __init__(self, target, *, events=None, functions=None, buffer_size=10240, output_path=None, autoreport=False, trace_clock=None, saved_cmdlines_nr=8192, tracer=None, kmod_auto_load=True, events_namespaces=('lisa', None), **kwargs): + + kconfig = target.plat_info['kernel']['config'] + if not kconfig.get('FTRACE'): + raise ValueError("The target's kernel needs CONFIG_FTRACE=y kconfig enabled") + + tracing_path = devlib.FtraceCollector.find_tracing_path(target) + target_available_events = set(self._target_available_events(target, tracing_path)) + + kmod = target.get_kmod(LISAFtraceDynamicKmod) + # Get the events possibly defined in the module. Note that it's a + # superset of the events actually defined as this is based on pretty + # crude filtering of the source files, rather than analyzing the events + # actually defined in the .ko after it has been compiled. + kmod_available_events = set(kmod.possible_events) + + # Events provided by the module are namespaced and therefore should + # never overlap with the target, so we never want to provide it via the + # module if it already exists on the target. + kmod_available_events -= target_available_events + if events is None: - events = AndTraceEventChecker([]) + events = EmptyTraceEventChecker() elif isinstance(events, TraceEventCheckerBase): pass else: events = AndTraceEventChecker.from_events(set(events)) - meta_events = { - event - for event in events.get_all_events() - if Trace._is_meta_event(event) - } - - tracing_path = devlib.FtraceCollector.find_tracing_path(target) - available_events = self._target_available_events(target, tracing_path) - # trace-cmd start complains if given these events, even though they are # valid avoided = { 'funcgraph_entry', 'funcgraph_exit', 'print', 'bprint', 'bputs', } + + def is_pattern(s): + return '*' in s or '?' in s or '[' in s or ']' in s + def rewrite(checker): if isinstance(checker, TraceEventChecker): - # Expand each possibly meta event into the actual underlying - # event, while pruning the events we don't want trace-cmd to - # see - checker = OrTraceEventChecker( - TraceEventChecker(event) - for _event in Trace.get_event_sources(checker.event) - # Handle patterns such as "sched_*" - for event in ( - fnmatch.filter( - available_events, - _event - # If there is no match, just use the initial name and - # let the rest of the code handle the missing events - ) or [_event] - ) - if event not in avoided + def process(event): + # Make fnmatch pattern optional + if is_pattern(event): + return OptionalTraceEventChecker.from_events([event]) + else: + return TraceEventChecker(event) + + # Turn meta events into their source event + return OrTraceEventChecker( + map(process, Trace.get_event_sources(checker.event)) ) - # Assume that we want to be able to call the functions in all the - # ways they support, so we need to collect all the events they are - # interested in. elif isinstance(checker, DynamicTraceEventChecker): - checker = AndTraceEventChecker(checker.checkers) - - return checker + return AndTraceEventChecker(checker.checkers) + else: + return checker - def find_all_missing(checker, available_events): + meta_events = { + event + for event in events.get_all_events() + if Trace._is_meta_event(event) + } + events = events.map(rewrite) + events_checker = events.expand_namespaces(namespaces=events_namespaces) + self.logger.debug(f'Will try to collect events: {events_checker}') + + def trim(checker, namespace, events): + """ + Prune from checkers that have been satisfied already. + """ + namespaced_checker = checker.expand_namespaces(namespaces=[namespace]) try: - checker.check_events(available_events, check_optional=True) - except MissingTraceEventError as e: - return set(e.missing_events.get_all_events()) + namespaced_checker.check_events(events, check_optional=True) + except MissingTraceEventError: + return checker else: - return set() + return EmptyTraceEventChecker() - events = events.map(rewrite) - events_checker = events + def wildcard(available_events, event): + return fnmatch.filter( + available_events, + event + ) - try: - events_checker.check_events(available_events) - except MissingTraceEventError as e: - missing_events_checker = e.missing_events - else: - missing_events_checker = OptionalTraceEventChecker([]) + satisfied = set() + remaining_events = events + events = set() + namespaces = events_namespaces or [None] + available_events = target_available_events | kmod_available_events + for namespace in namespaces: + namespaced_events = { + event: { + event_ + for event_ in Trace._expand_namespaces(event, namespaces=[namespace]) + for event_ in wildcard(available_events, event_) + } + for event in remaining_events.get_all_events() + } - missing_events = set(missing_events_checker.get_all_events()) - # Find all the missing events, and only keep the ones that were - # optional and have been previously ignored - missing_optional_events = find_all_missing(events_checker, available_events) - missing_events - events = available_events & events.get_all_events() + for base, namespaced in namespaced_events.items(): + found = available_events & namespaced + events.update(found) + if found: + satisfied.add(base) + + # Patterns will be preserved until the end since they will never be + # in found_events. + remaining_events = remaining_events.map( + functools.partial( + trim, + namespace=namespace, + events=events + ) + ) + + def remove_pattern(checker): + if isinstance(checker, TraceEventChecker) and is_pattern(checker.event): + return EmptyTraceEventChecker() + else: + return checker + + # Remove wildcard patterns as they would make checking fail. + events_checker = events_checker.map(remove_pattern) meta_events = { event for event in meta_events if any( - event in events or event in avoided + event in satisfied or event in avoided for event in Trace.get_event_sources(event) ) } @@ -5627,10 +5840,6 @@ class FtraceCollector(CollectorBase, Configurable): ) self.check_init_param(**kwargs) - kconfig = target.plat_info['kernel']['config'] - if not kconfig.get('FTRACE'): - raise ValueError("The target's kernel needs CONFIG_FTRACE=y kconfig enabled") - if functions and not kconfig.get('FUNCTION_TRACER'): raise ValueError(f"The target's kernel needs CONFIG_FUNCTION_TRACER=y kconfig enabled in order to trace functions: {functions}") @@ -5639,51 +5848,70 @@ class FtraceCollector(CollectorBase, Configurable): # If some events are not already available on that kernel, look them up # in custom modules - needed_from_kmod = missing_events | missing_optional_events + needed_from_kmod = kmod_available_events & events + kmod_defined_events = set() kmod_cm = None - if needed_from_kmod and kmod_auto_load: - self.logger.info(f'Building kernel module to try to provide the following events that are not currently available on the target: {", ".join(sorted(needed_from_kmod))}') - try: - provided, kmod_cm = self._get_kmod( - target, - available_events=available_events, - needed_events=needed_from_kmod, - ) - except Exception as e: - msg = f'Could not build the kernel module needed for required events ({", ".join(sorted(needed_from_kmod - missing_optional_events))}) and optional events ({", ".join(sorted(missing_optional_events))})' - if missing_events: - self.logger.error(msg) - raise MissingTraceEventError( - sorted(needed_from_kmod), - available_events=available_events, - msg=f'Ftrace events are missing in the kernel: {{missing_events}}{{available}}. Kernel module build was attempted to provide missing events but failed. Use kmod_auto_load=False if you want to disable automatic module building: {e}', - ) from e + if needed_from_kmod: + # If anything wrong happens, we will be restricted to the events + # already available. + events = events & target_available_events + + if kmod_auto_load: + self.logger.info(f'Building kernel module to try to provide the following events that are not currently available on the target: {", ".join(sorted(needed_from_kmod))}') + try: + kmod_defined_events, provided, kmod_cm = self._get_kmod( + target, + target_available_events=target_available_events, + needed_events=needed_from_kmod, + ) + except Exception as e: + try: + events_checker.check_events(events) + except MissingTraceEventError as e: + raise MissingTraceEventError( + e.missing_events, + available_events=target_available_events, + msg='Ftrace events are missing in the kernel: {missing_events}{available}. Kernel module build was attempted to provide missing events but failed' + ) from e + + try: + events_checker.check_events(events, check_optional=True) + except MissingTraceEventError as e: + self.logger.error(f'Could not build the kernel module to provide optional events: {e}. Use kmod_auto_load=False to disable automatic module build.') else: - self.logger.error(f'{msg}: {e}') + # Module build went well, we add the events effectively + # provided by the module + events = events | provided else: - events.update(provided) + try: + events_checker.check_events(events) + except MissingTraceEventError as e: + raise MissingTraceEventError( + e.missing_events, + available_events=target_available_events, + msg='Ftrace events are missing in the kernel: {missing_events}{available}. Use kmod_auto_load=True to enable automatic module build to provide these events.', + ) self._kmod_cm = kmod_cm + ############################################ + # Final checks after we enabled all we could + ############################################ + try: - missing_events_checker.check_events(events) + events_checker.check_events(events) except MissingTraceEventError as e: - if kmod_auto_load: - setup_help = '' - else: - setup_help = '. Enable kmod_auto_load=True to attempt setting them up' - raise MissingTraceEventError( e.missing_events, - available_events=e.available_events, - msg='Ftrace events are missing in the kernel{setup_help}: {missing_events}{available}', + available_events=target_available_events | kmod_defined_events, + msg='Ftrace events are missing: {missing_events}{available}', ) try: events_checker.check_events(events, check_optional=True) except MissingTraceEventError as e: - self.logger.info(f'Optional events not found in the kernel: {str(e)}') + self.logger.info(f'Optional events missing: {str(e)}') self.events = sorted(events | meta_events) if not self.events: @@ -5715,16 +5943,17 @@ class FtraceCollector(CollectorBase, Configurable): super().__init__(collector, output_path=output_path) @classmethod - def _get_kmod(cls, target, available_events, needed_events): + def _get_kmod(cls, target, target_available_events, needed_events): kmod = target.get_kmod(LISAFtraceDynamicKmod) defined_events = set(kmod.defined_events) needed = needed_events & defined_events if needed: - overlapping = defined_events & available_events + overlapping = defined_events & target_available_events if overlapping: raise ValueError(f'Events defined in {mod.src.mod_name} ({", ".join(needed)}) are needed but some events overlap with the ones already provided by the kernel: {", ".join(overlapping)}') else: return ( + defined_events, needed, functools.partial( kmod.run, @@ -5734,7 +5963,7 @@ class FtraceCollector(CollectorBase, Configurable): ) ) else: - return (set(), None) + return (defined_events, set(), None) @contextlib.contextmanager def _make_cm(self, record=True): -- GitLab From 148bbbc14098d9f71f355528a5d2f77a1a8c881d Mon Sep 17 00:00:00 2001 From: Douglas Raillard Date: Wed, 24 May 2023 12:27:47 +0100 Subject: [PATCH 5/5] lisa.trace: Improve MissingTraceEventError display FEATURE Show the closest matches before the list of available events. --- lisa/trace.py | 19 ++++++++++++++++--- 1 file changed, 16 insertions(+), 3 deletions(-) diff --git a/lisa/trace.py b/lisa/trace.py index 610d709f8..001095343 100644 --- a/lisa/trace.py +++ b/lisa/trace.py @@ -45,6 +45,7 @@ import itertools import functools import fnmatch from typing import Union +from difflib import get_close_matches import numpy as np import pandas as pd @@ -5438,13 +5439,25 @@ class MissingTraceEventError(RuntimeError, ValueError): def __str__(self): available = self.available_events + missing = self.missing_events + if available: - available = '. Available events are: {}'.format( - ', '.join(sorted(available))) + closest = { + matches[0] + for matches in ( + get_close_matches(event, available, n=1) + for event in missing + ) + if matches + } + available = '. Closest available matches are: {}. Available events are: {}'.format( + ', '.join(sorted(closest)), + ', '.join(sorted(available)) + ) else: available = '' - return self._template.format(missing_events=self.missing_events, available=available) + return self._template.format(missing_events=missing, available=available) class FtraceConf(SimpleMultiSrcConf, HideExekallID): -- GitLab