diff --git a/repos/os/src/app/trace_logger/README b/repos/os/src/app/trace_logger/README index fac5e4341b..3074091fa1 100644 --- a/repos/os/src/app/trace_logger/README +++ b/repos/os/src/app/trace_logger/README @@ -33,9 +33,15 @@ policy.label: This is a short description of the tags and attributes: :config.verbose: - Optional. Toggles wether the trace_logger shall log debugging information. + Optional. Toggles whether the trace_logger shall log debugging information. If enabled, even inactive trace subjects appear in the log. +:config.sc_time: + Optionally log scheduling-context execution time in addition to the + thread-context. This may be relevant on kernel platforms that do not + schedule threads on their own CPU share only but implement some kind of + donation scheme, for example, NOVA. + :config.session_ram: Optional. Amount of RAM donated to the trace session. diff --git a/repos/os/src/app/trace_logger/config.xsd b/repos/os/src/app/trace_logger/config.xsd index c854de69d5..5f37b62c59 100644 --- a/repos/os/src/app/trace_logger/config.xsd +++ b/repos/os/src/app/trace_logger/config.xsd @@ -37,8 +37,7 @@ - - + diff --git a/repos/os/src/app/trace_logger/main.cc b/repos/os/src/app/trace_logger/main.cc index fbb0abdb67..57cefc1c3c 100644 --- a/repos/os/src/app/trace_logger/main.cc +++ b/repos/os/src/app/trace_logger/main.cc @@ -12,11 +12,6 @@ * under the terms of the GNU Affero General Public License version 3. */ -/* local includes */ -#include -#include -#include - /* Genode includes */ #include #include @@ -26,6 +21,11 @@ #include #include #include +#include + +/* local includes */ +#include +#include using namespace Genode; using Thread_name = String<40>; @@ -45,6 +45,7 @@ class Main size_t session_arg_buffer; unsigned session_parent_levels; bool verbose; + bool sc_time; Microseconds period_us; size_t default_buf_sz; Policy_name default_policy_name; @@ -208,7 +209,8 @@ class Main log("\nReport ", _report_id++, "\n"); Monitor::Level_of_detail const detail { .state = _config.verbose, - .active_only = !_config.verbose }; + .active_only = !_config.verbose, + .sc_time = _config.sc_time }; _print_monitors(_heap, monitors, detail); } @@ -216,7 +218,10 @@ class Main Main(Env &env) : _env(env) { - _update_monitors(); + /* + * We skip the initial monitor update as the periodic timeout triggers + * the update immediately for the first time. + */ } }; @@ -230,7 +235,9 @@ Main::Config Main::Config::from_xml(Xml_node const &config) Number_of_bytes(1024*4)), .session_parent_levels = config.attribute_value("session_parent_levels", 0u), .verbose = config.attribute_value("verbose", false), - .period_us = read_sec_attr(config, "period_sec", 5), + .sc_time = config.attribute_value("sc_time", false), + .period_us = Microseconds(config.attribute_value("period_sec", 5) + * 1'000'000), .default_buf_sz = config.attribute_value("default_buffer", Number_of_bytes(4*1024)), .default_policy_name = config.attribute_value("default_policy", @@ -293,11 +300,14 @@ void Main::_print_monitors(Allocator &alloc, Monitor_tree const &monitors, pds.for_each([&] (Pd const &pd) { unsigned const state_width = detail.state ? fmt.state + 1 : 0; + unsigned const sc_width = detail.sc_time + ? fmt.total_sc + fmt.total_tc + 21 : 0; unsigned const table_width = fmt.thread_name + fmt.affinity + state_width - + fmt.total_cpu - + fmt.recent_cpu + + fmt.total_tc + + fmt.recent_tc + + sc_width + 26; unsigned const pd_width = (unsigned)pd.label.length() + 6; unsigned const excess_width = table_width - min(table_width, pd_width); diff --git a/repos/os/src/app/trace_logger/monitor.cc b/repos/os/src/app/trace_logger/monitor.cc index b762525c3e..7828141a03 100644 --- a/repos/os/src/app/trace_logger/monitor.cc +++ b/repos/os/src/app/trace_logger/monitor.cc @@ -112,17 +112,12 @@ Monitor::Monitor(Trace::Connection &trace, void Monitor::update_info(Trace::Subject_info const &info) { - try { - uint64_t const last_execution_time = - _info.execution_time().thread_context; + _recent_exec_time = { + info.execution_time().thread_context - _info.execution_time().thread_context, + info.execution_time().scheduling_context - _info.execution_time().scheduling_context + }; - _info = info; - - _recent_exec_time = - _info.execution_time().thread_context - last_execution_time; - } - catch (Trace::Nonexistent_subject) { - warning("Cannot update subject info: Nonexistent_subject"); } + _info = info; } @@ -138,8 +133,10 @@ void Monitor::apply_formatting(Formatting &formatting) const expand(formatting.thread_name, Quoted_name{_info.thread_name()}); expand(formatting.affinity, Formatted_affinity{_info.affinity()}); expand(formatting.state, Subject_info::state_name(_info.state())); - expand(formatting.total_cpu, _info.execution_time().thread_context); - expand(formatting.recent_cpu, _recent_exec_time); + expand(formatting.total_tc, _info.execution_time().thread_context); + expand(formatting.recent_tc, _recent_exec_time.thread_context); + expand(formatting.total_sc, _info.execution_time().scheduling_context); + expand(formatting.recent_sc, _recent_exec_time.scheduling_context); } @@ -152,12 +149,16 @@ void Monitor::print(Formatting fmt, Level_of_detail detail) /* print general subject information */ typedef Trace::Subject_info Subject_info; Subject_info::State const state = _info.state(); + log(" Thread ", Left_aligned(fmt.thread_name, Quoted_name{_info.thread_name()}), " ", Left_aligned(fmt.affinity, Formatted_affinity{_info.affinity()}), " ", Conditional(detail.state, Left_aligned(fmt.state + 1, Subject_info::state_name(state))), - "total:", Left_aligned(fmt.total_cpu, _info.execution_time().thread_context), " " - "recent:", _recent_exec_time); + "total:", Left_aligned(fmt.total_tc, _info.execution_time().thread_context), " " + "recent:", Left_aligned(fmt.recent_tc, _recent_exec_time.thread_context), + Conditional(detail.sc_time, String<80>( + " total_sc:", Left_aligned(fmt.total_sc, _info.execution_time().scheduling_context), + " recent_sc:", _recent_exec_time.scheduling_context))); /* print all buffer entries that we haven't yet printed */ _buffer.for_each_new_entry([&] (Trace::Buffer::Entry entry) { diff --git a/repos/os/src/app/trace_logger/monitor.h b/repos/os/src/app/trace_logger/monitor.h index 3f7a6bab96..411d1092b0 100644 --- a/repos/os/src/app/trace_logger/monitor.h +++ b/repos/os/src/app/trace_logger/monitor.h @@ -57,14 +57,14 @@ class Monitor : public Monitor_base, Trace_buffer _buffer; unsigned long _report_id { 0 }; Genode::Trace::Subject_info _info { }; - unsigned long long _recent_exec_time { 0 }; + Genode::Trace::Execution_time _recent_exec_time { }; char _curr_entry_data[MAX_ENTRY_LENGTH]; public: struct Formatting { - unsigned thread_name, affinity, state, total_cpu, recent_cpu; + unsigned thread_name, affinity, state, total_tc, recent_tc, total_sc, recent_sc; }; Monitor(Genode::Trace::Connection &trace, @@ -76,7 +76,7 @@ class Monitor : public Monitor_base, */ void apply_formatting(Formatting &) const; - struct Level_of_detail { bool state, active_only; }; + struct Level_of_detail { bool state, active_only, sc_time; }; void print(Formatting, Level_of_detail); @@ -101,7 +101,9 @@ class Monitor : public Monitor_base, bool recently_active() const { - return (_recent_exec_time != 0) || !_buffer.empty(); + return _recent_exec_time.thread_context + || _recent_exec_time.scheduling_context + || !_buffer.empty(); } }; diff --git a/repos/os/src/app/trace_logger/target.mk b/repos/os/src/app/trace_logger/target.mk index 788e2a360c..7a2595dcfc 100644 --- a/repos/os/src/app/trace_logger/target.mk +++ b/repos/os/src/app/trace_logger/target.mk @@ -1,5 +1,5 @@ TARGET = trace_logger INC_DIR += $(PRG_DIR) -SRC_CC = main.cc monitor.cc policy.cc xml_node.cc +SRC_CC = main.cc monitor.cc policy.cc CONFIG_XSD = config.xsd LIBS += base diff --git a/repos/os/src/app/trace_logger/xml_node.cc b/repos/os/src/app/trace_logger/xml_node.cc deleted file mode 100644 index b2dbee1552..0000000000 --- a/repos/os/src/app/trace_logger/xml_node.cc +++ /dev/null @@ -1,29 +0,0 @@ -/* - * \brief Genode XML nodes plus local utilities - * \author Martin Stein - * \date 2016-08-19 - */ - -/* - * Copyright (C) 2016-2017 Genode Labs GmbH - * - * This file is part of the Genode OS framework, which is distributed - * under the terms of the GNU Affero General Public License version 3. - */ - -/* local includes */ -#include - -using namespace Genode; - - -Microseconds Genode::read_sec_attr(Xml_node const node, - char const *name, - uint64_t const default_sec) -{ - uint64_t sec = node.attribute_value(name, (uint64_t)0); - if (!sec) { - sec = default_sec; - } - return Microseconds(sec * 1000 * 1000); -} diff --git a/repos/os/src/app/trace_logger/xml_node.h b/repos/os/src/app/trace_logger/xml_node.h deleted file mode 100644 index 33cf34647c..0000000000 --- a/repos/os/src/app/trace_logger/xml_node.h +++ /dev/null @@ -1,29 +0,0 @@ -/* - * \brief Genode XML nodes plus local utilities - * \author Martin Stein - * \date 2016-08-19 - */ - -/* - * Copyright (C) 2016-2017 Genode Labs GmbH - * - * This file is part of the Genode OS framework, which is distributed - * under the terms of the GNU Affero General Public License version 3. - */ - -#ifndef _XML_NODE_H_ -#define _XML_NODE_H_ - -/* Genode includes */ -#include -#include - - -namespace Genode { - - Microseconds read_sec_attr(Xml_node const node, - char const *name, - uint64_t const default_sec); -} - -#endif /* _XML_NODE_H_ */