From 77656cd130c8a34f0e4d70fece0501dc0ca6a63b Mon Sep 17 00:00:00 2001 From: Douglas RAILLARD Date: Tue, 19 Mar 2019 20:01:31 +0100 Subject: [PATCH 1/4] Squashed 'external/devlib/' changes from 8871fe3c..8512f116 8512f116 trace: Add DmesgCollector be8b87d5 module/sched: Fix/simplify procfs packing behaviour d76c2d63 module/sched: Make get_capacities() work with hotplugged CPUs 8bfa0502 module/sched: SchedProcFSData: Don't assume SD name is always present git-subtree-dir: external/devlib git-subtree-split: 8512f116fc5de214fd73cacf474b3109323a5754 --- devlib/module/sched.py | 28 +++--- devlib/trace/dmesg.py | 187 +++++++++++++++++++++++++++++++++++++++++ 2 files changed, 204 insertions(+), 11 deletions(-) create mode 100644 devlib/trace/dmesg.py diff --git a/devlib/module/sched.py b/devlib/module/sched.py index 0f35fc141..ce99d6d36 100644 --- a/devlib/module/sched.py +++ b/devlib/module/sched.py @@ -52,6 +52,12 @@ class SchedProcFSNode(object): _re_procfs_node = re.compile(r"(?P.*\D)(?P\d+)$") + PACKABLE_ENTRIES = [ + "cpu", + "domain", + "group" + ] + @staticmethod def _ends_with_digits(node): if not isinstance(node, basestring): @@ -71,18 +77,19 @@ class SchedProcFSNode(object): """ :returns: The name of the procfs node """ - return re.search(SchedProcFSNode._re_procfs_node, node).group("name") + match = re.search(SchedProcFSNode._re_procfs_node, node) + if match: + return match.group("name") - @staticmethod - def _packable(node, entries): + return node + + @classmethod + def _packable(cls, node): """ :returns: Whether it makes sense to pack a node into a common entry """ return (SchedProcFSNode._ends_with_digits(node) and - any([SchedProcFSNode._ends_with_digits(x) and - SchedProcFSNode._node_digits(x) != SchedProcFSNode._node_digits(node) and - SchedProcFSNode._node_name(x) == SchedProcFSNode._node_name(node) - for x in entries])) + SchedProcFSNode._node_name(node) in cls.PACKABLE_ENTRIES) @staticmethod def _build_directory(node_name, node_data): @@ -119,7 +126,7 @@ class SchedProcFSNode(object): # Find which entries can be packed into a common entry packables = { node : SchedProcFSNode._node_name(node) + "s" - for node in list(nodes.keys()) if SchedProcFSNode._packable(node, list(nodes.keys())) + for node in list(nodes.keys()) if SchedProcFSNode._packable(node) } self._dyn_attrs = {} @@ -228,7 +235,7 @@ class SchedProcFSData(SchedProcFSNode): # Even if we have a CPU entry, it can be empty (e.g. hotplugged out) # Make sure some data is there for cpu in cpus: - if target.file_exists(target.path.join(path, cpu, "domain0", "name")): + if target.file_exists(target.path.join(path, cpu, "domain0", "flags")): return True return False @@ -423,7 +430,6 @@ class SchedModule(Module): int ) - @memoized def get_capacities(self, default=None): """ :param default: Default capacity value to find if no data is @@ -434,7 +440,7 @@ class SchedModule(Module): :raises RuntimeError: Raised when no capacity information is found and 'default' is None """ - cpus = list(range(self.target.number_of_cpus)) + cpus = self.target.list_online_cpus() capacities = {} sd_info = self.get_sd_info() diff --git a/devlib/trace/dmesg.py b/devlib/trace/dmesg.py new file mode 100644 index 000000000..a9f80c7c1 --- /dev/null +++ b/devlib/trace/dmesg.py @@ -0,0 +1,187 @@ +# Copyright 2019 ARM Limited +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +from __future__ import division +import re +from itertools import takewhile +from datetime import timedelta + +from devlib.trace import TraceCollector + + +class KernelLogEntry(object): + """ + Entry of the kernel ring buffer. + + :param facility: facility the entry comes from + :type facility: str + + :param level: log level + :type level: str + + :param timestamp: Timestamp of the entry + :type timestamp: datetime.timedelta + + :param msg: Content of the entry + :type msg: str + """ + + _TIMESTAMP_MSG_REGEX = re.compile(r'\[(.*?)\] (.*)') + + def __init__(self, facility, level, timestamp, msg): + self.facility = facility + self.level = level + self.timestamp = timestamp + self.msg = msg + + @classmethod + def from_str(cls, line): + """ + Parses a "dmesg --decode" output line, formatted as following: + kern :err : [3618282.310743] nouveau 0000:01:00.0: systemd-logind[988]: nv50cal_space: -16 + + Or the more basic output: + [3618282.310743] nouveau 0000:01:00.0: systemd-logind[988]: nv50cal_space: -16 + + """ + + def parse_timestamp_msg(line): + match = cls._TIMESTAMP_MSG_REGEX.match(line.strip()) + if not match: + raise ValueError('dmesg entry format not recognized: {}'.format(line)) + timestamp, msg = match.groups() + return timestamp, msg + + # If we can parse the timestamp directly, that is a basic line + try: + timestamp, msg = parse_timestamp_msg(line) + except ValueError: + facility, level, remainder = line.split(':', 2) + timestamp, msg = parse_timestamp_msg(remainder) + facility = facility.strip() + level = level.strip() + else: + facility = None + level = None + + return cls( + facility=facility, + level=level, + timestamp=timedelta(seconds=float(timestamp.strip())), + msg=msg.strip(), + ) + + def __str__(self): + if self.facility and self.level: + prefix = '{facility}:{level}:'.format( + facility=self.facility, + level=self.level, + ) + else: + prefix = '' + + return '{prefix}[{timestamp}] {msg}'.format( + timestamp=self.timestamp.total_seconds(), + msg=self.msg, + prefix=prefix, + ) + + +class DmesgCollector(TraceCollector): + """ + Dmesg output collector. + + :param level: Minimum log level to enable. All levels that are more + critical will be collected as well. + :type level: str + + :param facility: Facility to record, see dmesg --help for the list. + :type level: str + + .. warning:: If BusyBox dmesg is used, facility and level will be ignored, + and the parsed entries will also lack that information. + """ + + # taken from "dmesg --help" + # This list needs to be ordered by priority + LOG_LEVELS = [ + "emerg", # system is unusable + "alert", # action must be taken immediately + "crit", # critical conditions + "err", # error conditions + "warn", # warning conditions + "notice", # normal but significant condition + "info", # informational + "debug", # debug-level messages + ] + + def __init__(self, target, level=LOG_LEVELS[-1], facility='kern'): + super(DmesgCollector, self).__init__(target) + + if level not in self.LOG_LEVELS: + raise ValueError('level needs to be one of: {}'.format( + ', '.join(self.LOG_LEVELS) + )) + self.level = level + + # Check if dmesg is the BusyBox one, or the one from util-linux. + # Note: BusyBox dmesg does not support -h, but will still print the + # help with an exit code of 1 + self.basic_dmesg = 'BusyBox' in self.target.execute('dmesg -h', + check_exit_code=False) + self.reset() + + @property + def entries(self): + return self._parse_entries(self.dmesg_out) + + @classmethod + def _parse_entries(cls, dmesg_out): + if not dmesg_out: + return [] + else: + return [ + KernelLogEntry.from_str(line) + for line in dmesg_out.splitlines() + ] + + def reset(self): + self.dmesg_out = None + + def start(self): + self.reset() + # Empty the dmesg ring buffer + self.target.execute('dmesg -c') + + def stop(self): + levels_list = list(takewhile( + lambda level: level != self.level, + self.LOG_LEVELS + )) + levels_list.append(self.level) + if self.basic_dmesg: + cmd = 'dmesg' + else: + cmd = 'dmesg --facility={facility} --force-prefix --decode --level={levels}'.format( + levels=','.join(levels_list), + facility=self.facility, + ) + + self.dmesg_out = self.target.execute(cmd) + + def get_trace(self, outfile): + with open(outfile, 'wt') as f: + f.write(self.dmesg_out + '\n') + -- GitLab From f12419da6e25b61e61600ef92febb6cd21c7133b Mon Sep 17 00:00:00 2001 From: Douglas RAILLARD Date: Thu, 14 Mar 2019 16:29:02 +0000 Subject: [PATCH 2/4] buildroot: Add util-linux package This gives a number of utilities, among them the real "dmesg" that supports more options than the BusyBox one. --- tools/buildroot_config | 2 ++ 1 file changed, 2 insertions(+) diff --git a/tools/buildroot_config b/tools/buildroot_config index b4e9e43ba..765acc212 100644 --- a/tools/buildroot_config +++ b/tools/buildroot_config @@ -21,4 +21,6 @@ BR2_PACKAGE_WPA_SUPPLICANT_WPA_CLIENT_SO=y BR2_PACKAGE_WPA_SUPPLICANT_PASSPHRASE=y BR2_TARGET_ROOTFS_CPIO=y BR2_TARGET_ROOTFS_CPIO_XZ=y +BR2_PACKAGE_UTIL_LINUX=y +BR2_PACKAGE_UTIL_LINUX_BINARIES=y # BR2_TARGET_ROOTFS_TAR is not set -- GitLab From b6cff87b895c85387a8bd8b67a56cf7d64deddc6 Mon Sep 17 00:00:00 2001 From: Douglas RAILLARD Date: Thu, 14 Mar 2019 15:47:47 +0000 Subject: [PATCH 3/4] lisa.tests: Collect dmesg output --- lisa/tests/base.py | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/lisa/tests/base.py b/lisa/tests/base.py index f60b386ed..53c856a33 100644 --- a/lisa/tests/base.py +++ b/lisa/tests/base.py @@ -26,6 +26,7 @@ from collections.abc import Mapping from inspect import signature, Parameter from devlib.target import KernelVersion +from devlib.trace.dmesg import DmesgCollector from lisa.analysis.tasks import TasksAnalysis from lisa.trace import Trace, requires_events @@ -577,11 +578,14 @@ class RTATestBundle(TestBundle, abc.ABC): profile, res_dir=res_dir) trace_path = os.path.join(res_dir, "trace.dat") + dmesg_path = os.path.join(res_dir, "dmesg.log") ftrace_coll = ftrace_coll or FtraceCollector.from_conf(target, cls.ftrace_conf) + dmesg_coll = DmesgCollector(target) - with ftrace_coll, target.freeze_userspace(): + with dmesg_coll, ftrace_coll, target.freeze_userspace(): wload.run() ftrace_coll.get_trace(trace_path) + dmesg_coll.get_trace(dmesg_path) return trace_path @classmethod -- GitLab From c77e7288f2a5457c137802450030493a49cc3fe0 Mon Sep 17 00:00:00 2001 From: Douglas RAILLARD Date: Thu, 14 Mar 2019 15:59:11 +0000 Subject: [PATCH 4/4] lisa.tests: un-hardcode trace path Make sure the same name is used everywhere for trace and dmesg log files in the res_dir. --- lisa/tests/base.py | 16 ++++++++++++---- 1 file changed, 12 insertions(+), 4 deletions(-) diff --git a/lisa/tests/base.py b/lisa/tests/base.py index 53c856a33..f16a219d6 100644 --- a/lisa/tests/base.py +++ b/lisa/tests/base.py @@ -357,6 +357,15 @@ class RTATestBundle(TestBundle, abc.ABC): :type rtapp_profile: dict """ + TRACE_PATH = 'trace.dat' + """ + Path to the ``trace-cmd`` trace.dat file in the result directory. + """ + DMESG_PATH = 'dmesg.log' + """ + Path to the dmesg log in the result directory. + """ + ftrace_conf = FtraceConf({ "events" : [ "sched_switch", @@ -418,8 +427,7 @@ class RTATestBundle(TestBundle, abc.ABC): allows updating the underlying path before it is actually loaded to match a different folder structure. """ - path = os.path.join(self.res_dir, 'trace.dat') - + path = os.path.join(self.res_dir, self.TRACE_PATH) trace = Trace(path, self.plat_info, events=self.ftrace_conf["events"]) return trace.get_view(self.trace_window(trace)) @@ -577,8 +585,8 @@ class RTATestBundle(TestBundle, abc.ABC): wload = RTA.by_profile(target, "rta_{}".format(cls.__name__.lower()), profile, res_dir=res_dir) - trace_path = os.path.join(res_dir, "trace.dat") - dmesg_path = os.path.join(res_dir, "dmesg.log") + trace_path = os.path.join(res_dir, cls.TRACE_PATH) + dmesg_path = os.path.join(res_dir, cls.DMESG_PATH) ftrace_coll = ftrace_coll or FtraceCollector.from_conf(target, cls.ftrace_conf) dmesg_coll = DmesgCollector(target) -- GitLab