mirror of
https://github.com/fish-shell/fish-shell.git
synced 2025-02-21 18:14:09 +08:00
Convert time
to a job decorator
This commit is contained in:
parent
ca18d88138
commit
664d6fb132
@ -117,7 +117,7 @@ SET(FISH_SRCS
|
||||
src/signal.cpp src/tinyexpr.cpp src/tnode.cpp src/tokenizer.cpp src/utf8.cpp src/util.cpp
|
||||
src/wcstringutil.cpp src/wgetopt.cpp src/wildcard.cpp src/wutil.cpp
|
||||
src/future_feature_flags.cpp src/redirection.cpp src/topic_monitor.cpp
|
||||
src/flog.cpp src/trace.cpp src/builtin_time.cpp
|
||||
src/flog.cpp src/trace.cpp src/timer.cpp
|
||||
)
|
||||
|
||||
# Header files are just globbed.
|
||||
|
@ -61,7 +61,6 @@
|
||||
#include "builtin_status.h"
|
||||
#include "builtin_string.h"
|
||||
#include "builtin_test.h"
|
||||
#include "builtin_time.h"
|
||||
#include "builtin_ulimit.h"
|
||||
#include "builtin_wait.h"
|
||||
#include "common.h"
|
||||
@ -388,7 +387,6 @@ static const builtin_data_t builtin_datas[] = {
|
||||
{L"string", &builtin_string, N_(L"Manipulate strings")},
|
||||
{L"switch", &builtin_generic, N_(L"Conditionally execute a block of commands")},
|
||||
{L"test", &builtin_test, N_(L"Test a condition")},
|
||||
{L"time", &builtin_time, N_(L"Time the execution of a job")},
|
||||
{L"true", &builtin_true, N_(L"Return a successful result")},
|
||||
{L"ulimit", &builtin_ulimit, N_(L"Set or get the shells resource usage limits")},
|
||||
{L"wait", &builtin_wait, N_(L"Wait for background processes completed")},
|
||||
|
@ -1,237 +0,0 @@
|
||||
// Functions for executing the time builtin.
|
||||
#include "config.h" // IWYU pragma: keep
|
||||
|
||||
#include <cerrno>
|
||||
#include <ctime>
|
||||
#include <chrono>
|
||||
#include <cstddef>
|
||||
|
||||
#include "builtin.h"
|
||||
#include "common.h"
|
||||
#include "exec.h"
|
||||
#include "fallback.h" // IWYU pragma: keep
|
||||
#include "io.h"
|
||||
#include "parser.h"
|
||||
#include "proc.h"
|
||||
#include "wgetopt.h"
|
||||
#include "wutil.h" // IWYU pragma: keep
|
||||
|
||||
#include <algorithm>
|
||||
#include <string.h>
|
||||
#include <sys/types.h>
|
||||
#include <sys/time.h>
|
||||
#include <sys/resource.h>
|
||||
|
||||
// Measuring time is always complicated with many caveats. Quite apart from the typical
|
||||
// gotchas faced by developers attempting to choose between monotonic vs non-monotonic and system vs
|
||||
// cpu clocks, the fact that we are executing as a shell further complicates matters: we can't just
|
||||
// observe the elapsed CPU time, because that does not reflect the total execution time for both
|
||||
// ourselves (internal shell execution time and the time it takes for builtins and functions to
|
||||
// execute) and any external processes we spawn.
|
||||
|
||||
// It would be nice to use the C++1 type-safe <chrono> interfaces to measure elapsed time, but that
|
||||
// unfortunately is underspecified with regards to user/system time and only provides means of
|
||||
// querying guaranteed monotonicity and resolution for the various clocks. It can be used to measure
|
||||
// elapsed wall time nicely, but if we would like to provide information more useful for
|
||||
// benchmarking and tuning then we must turn to either clock_gettime(2), with extensions for thread-
|
||||
// and process-specific elapsed CPU time, or times(3) for a standard interface to overall process
|
||||
// and child user/system time elapsed between snapshots. At least on some systems, times(3) has been
|
||||
// deprecated in favor of getrusage(2), which offers a wider variety of metrics coalesced for SELF,
|
||||
// THREAD, or CHILDREN.
|
||||
|
||||
// With regards to the C++11 `<chrono>` interface, there are three different time sources (clocks)
|
||||
// that we can use portably: `system_clock`, `steady_clock`, and `high_resolution_clock`; with
|
||||
// different properties and guarantees. While the obvious difference is the direct tradeoff between
|
||||
// period and resolution (higher resolution equals ability to measure smaller time differences more
|
||||
// accurately, but at the cost of rolling over more frequently), but unfortunately it is not as
|
||||
// simple as starting two clocks and going with the highest resolution that hasn't rolled over.
|
||||
// `system_clock` is out because it is always subject to interference due to adjustments from NTP
|
||||
// servers or super users (as it reflects the "actual" time), but `high_resolution_clock` may or may
|
||||
// not be aliased to `system_clock` or `steady_clock`. In practice, there's likely no need to worry
|
||||
// about this too much, a survey <http://howardhinnant.github.io/clock_survey.html> of the different
|
||||
// libraries indicates that `high_resolution_clock` is either an alias for `steady_clock` (in which
|
||||
// case it offers no greater resolution) or it is an alias for `system_clock` (in which case, even
|
||||
// when it offers a greater resolution than `steady_clock` it is not fit for use).
|
||||
|
||||
static int64_t micros(struct timeval t) {
|
||||
return (static_cast<int64_t>(t.tv_usec) + static_cast<int64_t>(t.tv_sec * 1E6));
|
||||
};
|
||||
|
||||
template <typename D1, typename D2>
|
||||
static int64_t micros(const std::chrono::duration<D1, D2> &d) {
|
||||
return std::chrono::duration_cast<std::chrono::microseconds>(d).count();
|
||||
};
|
||||
|
||||
// Linux makes available CLOCK_MONOTONIC_RAW, which is monotonic even in the presence of NTP
|
||||
// adjustments.
|
||||
#ifdef CLOCK_MONOTONIC_RAW
|
||||
#define CLOCK_SRC CLOCK_MONOTONIC_RAW
|
||||
#else
|
||||
#define CLOCK_SRC CLOCK_MONOTONIC
|
||||
#endif
|
||||
|
||||
/// Implementation of time builtin.
|
||||
int builtin_time(parser_t &parser, io_streams_t &streams, wchar_t **argv) {
|
||||
int argc = builtin_count_args(argv);
|
||||
|
||||
bool verbose = false;
|
||||
// In the future, we can consider accepting more command-line arguments to dictate the behavior
|
||||
// of the `time` builtin and what it measures or reports.
|
||||
if (argc > 1 && (argv[1] == wcstring(L"-h") || argv[1] == wcstring(L"--help"))) {
|
||||
streams.out.append(L"time <command or expression>\n");
|
||||
streams.out.append(L"Measures the elapsed wall, system, and user clocks in the execution of"
|
||||
L" the given command or expression");
|
||||
return 0;
|
||||
}
|
||||
if (argc > 1 && (argv[1] == wcstring(L"-v") || argv[1] == wcstring(L"--verbose"))) {
|
||||
verbose = true;
|
||||
argc -= 1;
|
||||
argv += 1;
|
||||
}
|
||||
|
||||
wcstring new_cmd;
|
||||
for (int i = 1; i < argc; ++i) {
|
||||
if (i > 1) new_cmd += L' ';
|
||||
new_cmd += argv[i];
|
||||
}
|
||||
|
||||
int status = STATUS_CMD_OK;
|
||||
if (argc > 1) {
|
||||
struct rusage fish_usage[2];
|
||||
struct rusage child_usage [2];
|
||||
|
||||
// Start counters
|
||||
getrusage(RUSAGE_SELF, &fish_usage[0]);
|
||||
getrusage(RUSAGE_CHILDREN, &child_usage[0]);
|
||||
auto wall_start = std::chrono::steady_clock::now();
|
||||
|
||||
if (parser.eval(std::move(new_cmd), *streams.io_chain, block_type_t::TOP) !=
|
||||
eval_result_t::ok) {
|
||||
status = STATUS_CMD_ERROR;
|
||||
} else {
|
||||
status = parser.get_last_status();
|
||||
}
|
||||
|
||||
// Stop counters
|
||||
getrusage(RUSAGE_SELF, &fish_usage[1]);
|
||||
getrusage(RUSAGE_CHILDREN, &child_usage[1]);
|
||||
auto wall_end = std::chrono::steady_clock::now();
|
||||
|
||||
int64_t fish_sys_micros = micros(fish_usage[1].ru_stime) - micros(fish_usage[0].ru_stime);
|
||||
int64_t fish_usr_micros = micros(fish_usage[1].ru_utime) - micros(fish_usage[0].ru_utime);
|
||||
int64_t child_sys_micros = micros(child_usage[1].ru_stime) - micros(child_usage[0].ru_stime);
|
||||
int64_t child_usr_micros = micros(child_usage[1].ru_utime) - micros(child_usage[0].ru_utime);
|
||||
|
||||
// The result from getrusage is not necessarily realtime, it may be cached a few
|
||||
// microseconds behind. In the event that execution completes extremely quickly or there is
|
||||
// no data (say, we are measuring external execution time but no external processes have
|
||||
// been launched), it can incorrectly appear to be negative.
|
||||
fish_sys_micros = std::max(int64_t(0), fish_sys_micros);
|
||||
fish_usr_micros = std::max(int64_t(0), fish_usr_micros);
|
||||
child_sys_micros = std::max(int64_t(0), child_sys_micros);
|
||||
child_usr_micros = std::max(int64_t(0), child_usr_micros);
|
||||
|
||||
int64_t net_sys_micros = fish_sys_micros + child_sys_micros;
|
||||
int64_t net_usr_micros = fish_usr_micros + child_usr_micros;
|
||||
int64_t net_wall_micros = micros(wall_end - wall_start);
|
||||
|
||||
enum class tunit {
|
||||
minutes,
|
||||
seconds,
|
||||
milliseconds,
|
||||
microseconds,
|
||||
};
|
||||
|
||||
auto get_unit = [](int64_t micros) {
|
||||
if (micros > 900 * 1E6) {
|
||||
return tunit::minutes;
|
||||
} else if (micros > 1 * 1E6) {
|
||||
return tunit::seconds;
|
||||
} else if (micros > 1E3) {
|
||||
return tunit::milliseconds;
|
||||
} else {
|
||||
return tunit::microseconds;
|
||||
}
|
||||
};
|
||||
|
||||
auto unit_name = [](tunit unit) {
|
||||
switch (unit) {
|
||||
case tunit::minutes: return "minutes";
|
||||
case tunit::seconds: return "seconds";
|
||||
case tunit::milliseconds: return "milliseconds";
|
||||
case tunit::microseconds: return "microseconds";
|
||||
}
|
||||
// GCC does not recognize the exhaustive switch above
|
||||
return "";
|
||||
};
|
||||
|
||||
auto unit_short_name = [](tunit unit) {
|
||||
switch (unit) {
|
||||
case tunit::minutes: return "mins";
|
||||
case tunit::seconds: return "secs";
|
||||
case tunit::milliseconds: return "millis";
|
||||
case tunit::microseconds: return "micros";
|
||||
}
|
||||
// GCC does not recognize the exhaustive switch above
|
||||
return "";
|
||||
};
|
||||
|
||||
auto convert = [](int64_t micros, tunit unit) {
|
||||
switch (unit) {
|
||||
case tunit::minutes: return micros / 1.0E6 / 60.0;
|
||||
case tunit::seconds: return micros / 1.0E6;
|
||||
case tunit::milliseconds: return micros / 1.0E3;
|
||||
case tunit::microseconds: return micros / 1.0;
|
||||
}
|
||||
// GCC does not recognize the exhaustive switch above
|
||||
return 0.0;
|
||||
};
|
||||
|
||||
auto wall_unit = get_unit(net_wall_micros);
|
||||
auto cpu_unit = get_unit((net_sys_micros + net_usr_micros) / 2);
|
||||
auto wall_time = convert(net_wall_micros, wall_unit);
|
||||
auto usr_time = convert(net_usr_micros, cpu_unit);
|
||||
auto sys_time = convert(net_sys_micros, cpu_unit);
|
||||
|
||||
if (!verbose) {
|
||||
streams.err.append_format(
|
||||
L"\n_______________________________" \
|
||||
L"\nExecuted in %6.2F %s" \
|
||||
L"\n usr time %6.2F %s" \
|
||||
L"\n sys time %6.2F %s" \
|
||||
L"\n\n",
|
||||
wall_time, unit_name(wall_unit),
|
||||
usr_time, unit_name(cpu_unit),
|
||||
sys_time, unit_name(cpu_unit)
|
||||
);
|
||||
} else {
|
||||
auto fish_unit = get_unit((fish_sys_micros + fish_usr_micros) / 2);
|
||||
auto child_unit = get_unit((child_sys_micros + child_usr_micros) / 2);
|
||||
auto fish_usr_time = convert(fish_usr_micros, fish_unit);
|
||||
auto fish_sys_time = convert(fish_sys_micros, fish_unit);
|
||||
auto child_usr_time = convert(child_usr_micros, child_unit);
|
||||
auto child_sys_time = convert(child_sys_micros, child_unit);
|
||||
|
||||
streams.err.append_format(
|
||||
L"\n________________________________________________________" \
|
||||
L"\nExecuted in %6.2F %s %*s %*s " \
|
||||
L"\n usr time %6.2F %s %6.2F %s %6.2F %s " \
|
||||
L"\n sys time %6.2F %s %6.2F %s %6.2F %s " \
|
||||
L"\n\n",
|
||||
wall_time, unit_short_name(wall_unit),
|
||||
strlen(unit_short_name(wall_unit)) - 1, "fish",
|
||||
strlen(unit_short_name(fish_unit)) - 1, "external",
|
||||
usr_time, unit_short_name(cpu_unit),
|
||||
fish_usr_time, unit_short_name(fish_unit),
|
||||
child_usr_time, unit_short_name(child_unit),
|
||||
sys_time, unit_short_name(cpu_unit),
|
||||
fish_sys_time, unit_short_name(fish_unit),
|
||||
child_sys_time, unit_short_name(child_unit)
|
||||
);
|
||||
|
||||
}
|
||||
|
||||
}
|
||||
|
||||
return status;
|
||||
}
|
@ -1,9 +0,0 @@
|
||||
// Prototypes for executing builtin_time function.
|
||||
#ifndef FISH_BUILTIN_TIME_H
|
||||
#define FISH_BUILTIN_TIME_H
|
||||
|
||||
class parser_t;
|
||||
struct io_streams_t;
|
||||
|
||||
int builtin_time(parser_t &parser, io_streams_t &streams, wchar_t **argv);
|
||||
#endif
|
@ -117,6 +117,7 @@ enum parse_keyword_t : uint8_t {
|
||||
parse_keyword_not,
|
||||
parse_keyword_or,
|
||||
parse_keyword_switch,
|
||||
parse_keyword_time,
|
||||
parse_keyword_while,
|
||||
};
|
||||
|
||||
@ -136,6 +137,7 @@ const enum_map<parse_keyword_t> keyword_enum_map[] = {{parse_keyword_exclam, L"!
|
||||
{parse_keyword_not, L"not"},
|
||||
{parse_keyword_or, L"or"},
|
||||
{parse_keyword_switch, L"switch"},
|
||||
{parse_keyword_time, L"time"},
|
||||
{parse_keyword_while, L"while"},
|
||||
{parse_keyword_none, nullptr}};
|
||||
#define keyword_enum_map_len (sizeof keyword_enum_map / sizeof *keyword_enum_map)
|
||||
@ -150,8 +152,13 @@ enum parse_statement_decoration_t {
|
||||
parse_statement_decoration_exec,
|
||||
};
|
||||
|
||||
// Boolean statement types, stored in node tag.
|
||||
enum parse_bool_statement_type_t { parse_bool_none, parse_bool_and, parse_bool_or };
|
||||
// Job decorations, stored in node tag.
|
||||
enum parse_job_decoration_t {
|
||||
parse_job_decoration_none,
|
||||
parse_job_decoration_and,
|
||||
parse_job_decoration_or,
|
||||
parse_job_decoration_time,
|
||||
};
|
||||
|
||||
// Whether a statement is backgrounded.
|
||||
enum parse_optional_background_t { parse_no_background, parse_background };
|
||||
|
@ -43,6 +43,7 @@
|
||||
#include "path.h"
|
||||
#include "proc.h"
|
||||
#include "reader.h"
|
||||
#include "timer.h"
|
||||
#include "tnode.h"
|
||||
#include "tokenizer.h"
|
||||
#include "trace.h"
|
||||
@ -1354,8 +1355,8 @@ eval_result_t parse_execution_context_t::run_job_conjunction(
|
||||
bool skip = false;
|
||||
if (continuation) {
|
||||
// Check the conjunction type.
|
||||
parse_bool_statement_type_t conj = bool_statement_type(continuation);
|
||||
assert((conj == parse_bool_and || conj == parse_bool_or) && "Unexpected conjunction");
|
||||
parse_job_decoration_t conj = bool_statement_type(continuation);
|
||||
assert((conj == parse_job_decoration_and || conj == parse_job_decoration_or) && "Unexpected conjunction");
|
||||
skip = should_skip(conj);
|
||||
}
|
||||
if (!skip) {
|
||||
@ -1367,12 +1368,12 @@ eval_result_t parse_execution_context_t::run_job_conjunction(
|
||||
return result;
|
||||
}
|
||||
|
||||
bool parse_execution_context_t::should_skip(parse_bool_statement_type_t type) const {
|
||||
bool parse_execution_context_t::should_skip(parse_job_decoration_t type) const {
|
||||
switch (type) {
|
||||
case parse_bool_and:
|
||||
case parse_job_decoration_and:
|
||||
// AND. Skip if the last job failed.
|
||||
return parser->get_last_status() != 0;
|
||||
case parse_bool_or:
|
||||
case parse_job_decoration_or:
|
||||
// OR. Skip if the last job succeeded.
|
||||
return parser->get_last_status() == 0;
|
||||
default:
|
||||
@ -1387,6 +1388,7 @@ eval_result_t parse_execution_context_t::run_job_list(tnode_t<Type> job_list,
|
||||
static_assert(Type::token == symbol_job_list || Type::token == symbol_andor_job_list,
|
||||
"Not a job list");
|
||||
|
||||
static std::vector<timer_snapshot_t> active_timers;
|
||||
eval_result_t result = eval_result_t::ok;
|
||||
while (auto job_conj = job_list.template next_in_list<g::job_conjunction>()) {
|
||||
if (auto reason = check_end_execution()) {
|
||||
@ -1396,11 +1398,26 @@ eval_result_t parse_execution_context_t::run_job_list(tnode_t<Type> job_list,
|
||||
|
||||
// Maybe skip the job if it has a leading and/or.
|
||||
// Skipping is treated as success.
|
||||
bool timer_started = false;
|
||||
if (get_decorator(job_conj) == parse_job_decoration_time) {
|
||||
active_timers.emplace_back(timer_snapshot_t::take());
|
||||
timer_started = true;
|
||||
}
|
||||
if (should_skip(get_decorator(job_conj))) {
|
||||
result = eval_result_t::ok;
|
||||
} else {
|
||||
result = this->run_job_conjunction(job_conj, associated_block);
|
||||
}
|
||||
if (timer_started) {
|
||||
auto t1 = std::move(active_timers.back());
|
||||
active_timers.pop_back();
|
||||
auto t2 = timer_snapshot_t::take();
|
||||
|
||||
// Well, this is awkward. By defining `time` as a decorator and not a built-in, there's
|
||||
// no associated stream for its output!
|
||||
auto output = timer_snapshot_t::print_delta(std::move(t1), std::move(t2), true);
|
||||
std::fwprintf(stderr, L"%S\n", output.c_str());
|
||||
}
|
||||
}
|
||||
|
||||
// Returns the result of the last job executed or skipped.
|
||||
|
@ -74,7 +74,7 @@ class parse_execution_context_t {
|
||||
wcstring_list_t *out_args) const;
|
||||
|
||||
/// Return whether we should skip a job with the given bool statement type.
|
||||
bool should_skip(parse_bool_statement_type_t type) const;
|
||||
bool should_skip(parse_job_decoration_t type) const;
|
||||
|
||||
/// Indicates whether a job is a simple block (one block, no redirections).
|
||||
bool job_is_simple_block(tnode_t<grammar::job> job) const;
|
||||
|
@ -210,6 +210,7 @@ DEF_ALT(job_list) {
|
||||
DEF_ALT(job_decorator) {
|
||||
using ands = single<keyword<parse_keyword_and>>;
|
||||
using ors = single<keyword<parse_keyword_or>>;
|
||||
using times = single<keyword<parse_keyword_time>>;
|
||||
using empty = grammar::empty;
|
||||
ALT_BODY(job_decorator, ands, ors, empty);
|
||||
};
|
||||
|
@ -69,21 +69,25 @@ RESOLVE(job_list) {
|
||||
RESOLVE(job_decorator) {
|
||||
// If it's followed by --help, it's not a decoration.
|
||||
if (token2.is_help_argument) {
|
||||
*out_tag = parse_bool_none;
|
||||
*out_tag = parse_job_decoration_none;
|
||||
return production_for<empty>();
|
||||
}
|
||||
|
||||
switch (token1.keyword) {
|
||||
case parse_keyword_and: {
|
||||
*out_tag = parse_bool_and;
|
||||
*out_tag = parse_job_decoration_and;
|
||||
return production_for<ands>();
|
||||
}
|
||||
case parse_keyword_or: {
|
||||
*out_tag = parse_bool_or;
|
||||
*out_tag = parse_job_decoration_or;
|
||||
return production_for<ors>();
|
||||
}
|
||||
case parse_keyword_time: {
|
||||
*out_tag = parse_job_decoration_time;
|
||||
return production_for<times>();
|
||||
}
|
||||
default: {
|
||||
*out_tag = parse_bool_none;
|
||||
*out_tag = parse_job_decoration_none;
|
||||
return production_for<empty>();
|
||||
}
|
||||
}
|
||||
@ -94,10 +98,10 @@ RESOLVE(job_conjunction_continuation) {
|
||||
UNUSED(out_tag);
|
||||
switch (token1.type) {
|
||||
case parse_token_type_andand:
|
||||
*out_tag = parse_bool_and;
|
||||
*out_tag = parse_job_decoration_and;
|
||||
return production_for<andands>();
|
||||
case parse_token_type_oror:
|
||||
*out_tag = parse_bool_or;
|
||||
*out_tag = parse_job_decoration_or;
|
||||
return production_for<orors>();
|
||||
default:
|
||||
return production_for<empty>();
|
||||
|
@ -1079,11 +1079,11 @@ static bool detect_errors_in_backgrounded_job(tnode_t<grammar::job> job,
|
||||
// Try getting the next job's decorator.
|
||||
if (auto next_job_dec = jlist.next_in_list<g::job_decorator>()) {
|
||||
// The next job is indeed a boolean statement.
|
||||
parse_bool_statement_type_t bool_type = bool_statement_type(next_job_dec);
|
||||
if (bool_type == parse_bool_and) {
|
||||
parse_job_decoration_t bool_type = bool_statement_type(next_job_dec);
|
||||
if (bool_type == parse_job_decoration_and) {
|
||||
errored = append_syntax_error(parse_errors, next_job_dec.source_range()->start,
|
||||
BOOL_AFTER_BACKGROUND_ERROR_MSG, L"and");
|
||||
} else if (bool_type == parse_bool_or) {
|
||||
} else if (bool_type == parse_job_decoration_or) {
|
||||
errored = append_syntax_error(parse_errors, next_job_dec.source_range()->start,
|
||||
BOOL_AFTER_BACKGROUND_ERROR_MSG, L"or");
|
||||
}
|
||||
|
192
src/timer.cpp
Normal file
192
src/timer.cpp
Normal file
@ -0,0 +1,192 @@
|
||||
// Functions for executing the time builtin.
|
||||
#include "config.h" // IWYU pragma: keep
|
||||
|
||||
#include <cerrno>
|
||||
#include <ctime>
|
||||
#include <chrono>
|
||||
#include <cstddef>
|
||||
|
||||
#include "common.h"
|
||||
#include "builtin.h"
|
||||
#include "exec.h"
|
||||
#include "fallback.h" // IWYU pragma: keep
|
||||
#include "io.h"
|
||||
#include "parser.h"
|
||||
#include "proc.h"
|
||||
#include "timer.h"
|
||||
#include "wgetopt.h"
|
||||
#include "wutil.h" // IWYU pragma: keep
|
||||
|
||||
#include <algorithm>
|
||||
#include <string.h>
|
||||
|
||||
// Measuring time is always complicated with many caveats. Quite apart from the typical
|
||||
// gotchas faced by developers attempting to choose between monotonic vs non-monotonic and system vs
|
||||
// cpu clocks, the fact that we are executing as a shell further complicates matters: we can't just
|
||||
// observe the elapsed CPU time, because that does not reflect the total execution time for both
|
||||
// ourselves (internal shell execution time and the time it takes for builtins and functions to
|
||||
// execute) and any external processes we spawn.
|
||||
|
||||
// It would be nice to use the C++1 type-safe <chrono> interfaces to measure elapsed time, but that
|
||||
// unfortunately is underspecified with regards to user/system time and only provides means of
|
||||
// querying guaranteed monotonicity and resolution for the various clocks. It can be used to measure
|
||||
// elapsed wall time nicely, but if we would like to provide information more useful for
|
||||
// benchmarking and tuning then we must turn to either clock_gettime(2), with extensions for thread-
|
||||
// and process-specific elapsed CPU time, or times(3) for a standard interface to overall process
|
||||
// and child user/system time elapsed between snapshots. At least on some systems, times(3) has been
|
||||
// deprecated in favor of getrusage(2), which offers a wider variety of metrics coalesced for SELF,
|
||||
// THREAD, or CHILDREN.
|
||||
|
||||
// With regards to the C++11 `<chrono>` interface, there are three different time sources (clocks)
|
||||
// that we can use portably: `system_clock`, `steady_clock`, and `high_resolution_clock`; with
|
||||
// different properties and guarantees. While the obvious difference is the direct tradeoff between
|
||||
// period and resolution (higher resolution equals ability to measure smaller time differences more
|
||||
// accurately, but at the cost of rolling over more frequently), but unfortunately it is not as
|
||||
// simple as starting two clocks and going with the highest resolution that hasn't rolled over.
|
||||
// `system_clock` is out because it is always subject to interference due to adjustments from NTP
|
||||
// servers or super users (as it reflects the "actual" time), but `high_resolution_clock` may or may
|
||||
// not be aliased to `system_clock` or `steady_clock`. In practice, there's likely no need to worry
|
||||
// about this too much, a survey <http://howardhinnant.github.io/clock_survey.html> of the different
|
||||
// libraries indicates that `high_resolution_clock` is either an alias for `steady_clock` (in which
|
||||
// case it offers no greater resolution) or it is an alias for `system_clock` (in which case, even
|
||||
// when it offers a greater resolution than `steady_clock` it is not fit for use).
|
||||
|
||||
static int64_t micros(struct timeval t) {
|
||||
return (static_cast<int64_t>(t.tv_usec) + static_cast<int64_t>(t.tv_sec * 1E6));
|
||||
};
|
||||
|
||||
template <typename D1, typename D2>
|
||||
static int64_t micros(const std::chrono::duration<D1, D2> &d) {
|
||||
return std::chrono::duration_cast<std::chrono::microseconds>(d).count();
|
||||
};
|
||||
|
||||
|
||||
timer_snapshot_t timer_snapshot_t::take() {
|
||||
timer_snapshot_t snapshot;
|
||||
|
||||
getrusage(RUSAGE_SELF, &snapshot.cpu_fish);
|
||||
getrusage(RUSAGE_CHILDREN, &snapshot.cpu_children);
|
||||
snapshot.wall = std::chrono::steady_clock::now();
|
||||
|
||||
return snapshot;
|
||||
}
|
||||
|
||||
wcstring
|
||||
timer_snapshot_t::print_delta(timer_snapshot_t t1, timer_snapshot_t t2, bool verbose /* = true */) {
|
||||
int64_t fish_sys_micros = micros(t2.cpu_fish.ru_stime) - micros(t1.cpu_fish.ru_stime);
|
||||
int64_t fish_usr_micros = micros(t2.cpu_fish.ru_utime) - micros(t1.cpu_fish.ru_utime);
|
||||
int64_t child_sys_micros = micros(t2.cpu_children.ru_stime) - micros(t1.cpu_children.ru_stime);
|
||||
int64_t child_usr_micros = micros(t2.cpu_children.ru_utime) - micros(t1.cpu_children.ru_utime);
|
||||
|
||||
// The result from getrusage is not necessarily realtime, it may be cached a few microseconds
|
||||
// behind. In the event that execution completes extremely quickly or there is no data (say, we
|
||||
// are measuring external execution time but no external processes have been launched), it can
|
||||
// incorrectly appear to be negative.
|
||||
fish_sys_micros = std::max(int64_t(0), fish_sys_micros);
|
||||
fish_usr_micros = std::max(int64_t(0), fish_usr_micros);
|
||||
child_sys_micros = std::max(int64_t(0), child_sys_micros);
|
||||
child_usr_micros = std::max(int64_t(0), child_usr_micros);
|
||||
|
||||
int64_t net_sys_micros = fish_sys_micros + child_sys_micros;
|
||||
int64_t net_usr_micros = fish_usr_micros + child_usr_micros;
|
||||
int64_t net_wall_micros = micros(t2.wall - t1.wall);
|
||||
|
||||
enum class tunit {
|
||||
minutes,
|
||||
seconds,
|
||||
milliseconds,
|
||||
microseconds,
|
||||
};
|
||||
|
||||
auto get_unit = [](int64_t micros) {
|
||||
if (micros > 900 * 1E6) {
|
||||
return tunit::minutes;
|
||||
} else if (micros > 1 * 1E6) {
|
||||
return tunit::seconds;
|
||||
} else if (micros > 1E3) {
|
||||
return tunit::milliseconds;
|
||||
} else {
|
||||
return tunit::microseconds;
|
||||
}
|
||||
};
|
||||
|
||||
auto unit_name = [](tunit unit) {
|
||||
switch (unit) {
|
||||
case tunit::minutes: return "minutes";
|
||||
case tunit::seconds: return "seconds";
|
||||
case tunit::milliseconds: return "milliseconds";
|
||||
case tunit::microseconds: return "microseconds";
|
||||
}
|
||||
// GCC does not recognize the exhaustive switch above
|
||||
return "";
|
||||
};
|
||||
|
||||
auto unit_short_name = [](tunit unit) {
|
||||
switch (unit) {
|
||||
case tunit::minutes: return "mins";
|
||||
case tunit::seconds: return "secs";
|
||||
case tunit::milliseconds: return "millis";
|
||||
case tunit::microseconds: return "micros";
|
||||
}
|
||||
// GCC does not recognize the exhaustive switch above
|
||||
return "";
|
||||
};
|
||||
|
||||
auto convert = [](int64_t micros, tunit unit) {
|
||||
switch (unit) {
|
||||
case tunit::minutes: return micros / 1.0E6 / 60.0;
|
||||
case tunit::seconds: return micros / 1.0E6;
|
||||
case tunit::milliseconds: return micros / 1.0E3;
|
||||
case tunit::microseconds: return micros / 1.0;
|
||||
}
|
||||
// GCC does not recognize the exhaustive switch above
|
||||
return 0.0;
|
||||
};
|
||||
|
||||
auto wall_unit = get_unit(net_wall_micros);
|
||||
auto cpu_unit = get_unit((net_sys_micros + net_usr_micros) / 2);
|
||||
auto wall_time = convert(net_wall_micros, wall_unit);
|
||||
auto usr_time = convert(net_usr_micros, cpu_unit);
|
||||
auto sys_time = convert(net_sys_micros, cpu_unit);
|
||||
|
||||
wcstring output;
|
||||
if (!verbose) {
|
||||
append_format(output,
|
||||
L"\n_______________________________" \
|
||||
L"\nExecuted in %6.2F %s" \
|
||||
L"\n usr time %6.2F %s" \
|
||||
L"\n sys time %6.2F %s" \
|
||||
L"\n",
|
||||
wall_time, unit_name(wall_unit),
|
||||
usr_time, unit_name(cpu_unit),
|
||||
sys_time, unit_name(cpu_unit)
|
||||
);
|
||||
} else {
|
||||
auto fish_unit = get_unit((fish_sys_micros + fish_usr_micros) / 2);
|
||||
auto child_unit = get_unit((child_sys_micros + child_usr_micros) / 2);
|
||||
auto fish_usr_time = convert(fish_usr_micros, fish_unit);
|
||||
auto fish_sys_time = convert(fish_sys_micros, fish_unit);
|
||||
auto child_usr_time = convert(child_usr_micros, child_unit);
|
||||
auto child_sys_time = convert(child_sys_micros, child_unit);
|
||||
|
||||
append_format(output,
|
||||
L"\n________________________________________________________" \
|
||||
L"\nExecuted in %6.2F %s %*s %*s " \
|
||||
L"\n usr time %6.2F %s %6.2F %s %6.2F %s " \
|
||||
L"\n sys time %6.2F %s %6.2F %s %6.2F %s " \
|
||||
L"\n",
|
||||
wall_time, unit_short_name(wall_unit),
|
||||
strlen(unit_short_name(wall_unit)) - 1, "fish",
|
||||
strlen(unit_short_name(fish_unit)) - 1, "external",
|
||||
usr_time, unit_short_name(cpu_unit),
|
||||
fish_usr_time, unit_short_name(fish_unit),
|
||||
child_usr_time, unit_short_name(child_unit),
|
||||
sys_time, unit_short_name(cpu_unit),
|
||||
fish_sys_time, unit_short_name(fish_unit),
|
||||
child_sys_time, unit_short_name(child_unit)
|
||||
);
|
||||
|
||||
}
|
||||
|
||||
return output;
|
||||
};
|
28
src/timer.h
Normal file
28
src/timer.h
Normal file
@ -0,0 +1,28 @@
|
||||
// Prototypes for executing builtin_time function.
|
||||
#ifndef FISH_TIMER_H
|
||||
#define FISH_TIMER_H
|
||||
|
||||
#include <chrono>
|
||||
#include <sys/types.h>
|
||||
#include <sys/time.h>
|
||||
#include <sys/resource.h>
|
||||
|
||||
#include "common.h"
|
||||
|
||||
class parser_t;
|
||||
struct io_streams_t;
|
||||
|
||||
struct timer_snapshot_t {
|
||||
public:
|
||||
struct rusage cpu_fish;
|
||||
struct rusage cpu_children;
|
||||
std::chrono::time_point<std::chrono::steady_clock> wall;
|
||||
|
||||
static timer_snapshot_t take();
|
||||
static wcstring print_delta(timer_snapshot_t t1, timer_snapshot_t t2, bool verbose = false);
|
||||
|
||||
private:
|
||||
timer_snapshot_t() {}
|
||||
};
|
||||
|
||||
#endif
|
@ -46,13 +46,13 @@ enum parse_statement_decoration_t get_decoration(tnode_t<grammar::plain_statemen
|
||||
return decoration;
|
||||
}
|
||||
|
||||
enum parse_bool_statement_type_t bool_statement_type(tnode_t<grammar::job_decorator> stmt) {
|
||||
return static_cast<parse_bool_statement_type_t>(stmt.tag());
|
||||
enum parse_job_decoration_t bool_statement_type(tnode_t<grammar::job_decorator> stmt) {
|
||||
return static_cast<parse_job_decoration_t>(stmt.tag());
|
||||
}
|
||||
|
||||
enum parse_bool_statement_type_t bool_statement_type(
|
||||
enum parse_job_decoration_t bool_statement_type(
|
||||
tnode_t<grammar::job_conjunction_continuation> cont) {
|
||||
return static_cast<parse_bool_statement_type_t>(cont.tag());
|
||||
return static_cast<parse_job_decoration_t>(cont.tag());
|
||||
}
|
||||
|
||||
maybe_t<pipe_or_redir_t> redirection_for_node(tnode_t<grammar::redirection> redirection,
|
||||
@ -118,7 +118,7 @@ bool job_node_is_background(tnode_t<grammar::job> job) {
|
||||
return bg.tag() == parse_background;
|
||||
}
|
||||
|
||||
parse_bool_statement_type_t get_decorator(tnode_t<grammar::job_conjunction> conj) {
|
||||
parse_job_decoration_t get_decorator(tnode_t<grammar::job_conjunction> conj) {
|
||||
using namespace grammar;
|
||||
tnode_t<job_decorator> dec;
|
||||
// We have two possible parents: job_list and andor_job_list.
|
||||
|
@ -233,9 +233,9 @@ maybe_t<wcstring> command_for_plain_statement(tnode_t<grammar::plain_statement>
|
||||
parse_statement_decoration_t get_decoration(tnode_t<grammar::plain_statement> stmt);
|
||||
|
||||
/// Return the type for a boolean statement.
|
||||
enum parse_bool_statement_type_t bool_statement_type(tnode_t<grammar::job_decorator> stmt);
|
||||
parse_job_decoration_t bool_statement_type(tnode_t<grammar::job_decorator> stmt);
|
||||
|
||||
enum parse_bool_statement_type_t bool_statement_type(
|
||||
parse_job_decoration_t bool_statement_type(
|
||||
tnode_t<grammar::job_conjunction_continuation> cont);
|
||||
|
||||
/// Given a redirection node, get the parsed redirection and target of the redirection (file path,
|
||||
@ -256,7 +256,7 @@ bool job_node_is_background(tnode_t<grammar::job>);
|
||||
/// If the conjunction is has a decorator (and/or), return it; otherwise return none. This only
|
||||
/// considers the leading conjunction, e.g. in `and true || false` only the 'true' conjunction will
|
||||
/// return 'and'.
|
||||
parse_bool_statement_type_t get_decorator(tnode_t<grammar::job_conjunction>);
|
||||
parse_job_decoration_t get_decorator(tnode_t<grammar::job_conjunction>);
|
||||
|
||||
/// Return whether the statement is part of a pipeline.
|
||||
/// This doesn't detect e.g. pipelines involving our parent's block statements.
|
||||
|
Loading…
x
Reference in New Issue
Block a user