diff --git a/CMakeLists.txt b/CMakeLists.txt index 7d9dff233..d7ecadf8c 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -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/flog.cpp src/trace.cpp src/builtin_time.cpp ) # Header files are just globbed. diff --git a/src/builtin.cpp b/src/builtin.cpp index 9eca55180..74a327d5f 100644 --- a/src/builtin.cpp +++ b/src/builtin.cpp @@ -61,6 +61,7 @@ #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" @@ -387,6 +388,7 @@ 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")}, diff --git a/src/builtin_time.cpp b/src/builtin_time.cpp new file mode 100644 index 000000000..3a5267a77 --- /dev/null +++ b/src/builtin_time.cpp @@ -0,0 +1,119 @@ +// Functions for executing the time builtin. +#include "config.h" // IWYU pragma: keep + +#include +#include +#include +#include + +#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 +#include +#include + +// 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 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. + +static uint64_t micros(struct timeval t) { + return (static_cast(t.tv_usec) + static_cast(t.tv_sec * 1E6)); +}; +static uint64_t micros(struct timespec t) { + return (static_cast(t.tv_nsec) / 1E3 + static_cast(t.tv_sec * 1E6)); +}; + +/// 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 \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]; + struct timespec wall[2] {}; + + // Start counters + getrusage(RUSAGE_SELF, &fish_usage[0]); + getrusage(RUSAGE_CHILDREN, &child_usage[0]); + clock_gettime(CLOCK_MONOTONIC, &wall[0]); + + 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]); + clock_gettime(CLOCK_MONOTONIC, &wall[1]); + + + uint64_t fish_sys_micros = micros(fish_usage[1].ru_stime) - micros(fish_usage[0].ru_stime); + uint64_t fish_usr_micros = micros(fish_usage[1].ru_utime) - micros(fish_usage[0].ru_utime); + uint64_t child_sys_micros = micros(child_usage[1].ru_stime) - micros(child_usage[0].ru_stime); + uint64_t child_usr_micros = micros(child_usage[1].ru_utime) - micros(child_usage[0].ru_utime); + + uint64_t net_sys_micros = fish_sys_micros + child_sys_micros; + uint64_t net_usr_micros = fish_usr_micros + child_usr_micros; + uint64_t wall_micros = micros(wall[1]) - micros(wall[0]); + + streams.out.append_format( + L"\n__________________________________" \ + L"\nExecution completed in %f seconds" \ + L"\nuser time %f seconds" \ + L"\nsystem time %f seconds" \ + L"\n\n", + wall_micros / 1.0E6, + net_usr_micros / 1.0E6, + net_sys_micros / 1.0E6 + ); + + } + + return status; +} diff --git a/src/builtin_time.h b/src/builtin_time.h new file mode 100644 index 000000000..97fd171b9 --- /dev/null +++ b/src/builtin_time.h @@ -0,0 +1,9 @@ +// 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