Skip to content

time builtin: align output columns on rare cases #6726

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
krobelus merged 1 commit into from
Mar 14, 2020
Merged

time builtin: align output columns on rare cases #6726

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
33 changes: 33 additions & 0 deletions src/fish_tests.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
#include <algorithm>
#include <array>
#include <atomic>
#include <chrono>
#include <cmath>
#include <cstring>
#include <cwchar>
Expand Down Expand Up @@ -72,6 +73,7 @@
#include "redirection.h"
#include "screen.h"
#include "signal.h"
#include "timer.h"
#include "tnode.h"
#include "tokenizer.h"
#include "topic_monitor.h"
Expand Down Expand Up @@ -5641,6 +5643,36 @@ static void test_topic_monitor_torture() {
for (auto &t : threads) t.join();
}

static void test_timer_format() {
say(L"Testing timer format");
auto t1 = timer_snapshot_t::take();
t1.cpu_fish.ru_utime.tv_usec = 0;
t1.cpu_fish.ru_stime.tv_usec = 0;
t1.cpu_children.ru_utime.tv_usec = 0;
t1.cpu_children.ru_stime.tv_usec = 0;
auto t2 = t1;
t2.cpu_fish.ru_utime.tv_usec = 999995;
t2.cpu_fish.ru_stime.tv_usec = 999994;
t2.cpu_children.ru_utime.tv_usec = 1000;
t2.cpu_children.ru_stime.tv_usec = 500;
t2.wall += std::chrono::microseconds(500);
auto expected =
LR"(
________________________________________________________
Executed in 500.00 micros fish external
usr time 1.00 secs 1.00 secs 1.00 millis
sys time 1.00 secs 1.00 secs 0.50 millis
)"; // (a) (b) (c)
// (a) remaining columns should align even if there are different units
// (b) carry to the next unit when it would overflow %6.2F
// (c) carry to the next unit when the larger one exceeds 1000
std::wstring actual = timer_snapshot_t::print_delta(t1, t2, true);
if (actual != expected) {
err(L"Failed to format timer snapshot\n\Expected: %ls\nActual:%ls\n", expected,
actual.c_str());
}
}

/// Main test.
int main(int argc, char **argv) {
UNUSED(argc);
Expand Down Expand Up @@ -5770,6 +5802,7 @@ int main(int argc, char **argv) {
if (should_test_function("normalize")) test_normalize_path();
if (should_test_function("topics")) test_topic_monitor();
if (should_test_function("topics")) test_topic_monitor_torture();
if (should_test_function("timer_format")) test_timer_format();
// history_tests_t::test_history_speed();

say(L"Encountered %d errors in low-level tests", err_count);
Expand Down
24 changes: 13 additions & 11 deletions src/timer.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -101,9 +101,9 @@ wcstring timer_snapshot_t::print_delta(timer_snapshot_t t1, timer_snapshot_t t2,
auto get_unit = [](int64_t micros) {
if (micros > 900 * 1E6) {
return tunit::minutes;
} else if (micros > 1 * 1E6) {
} else if (micros >= 999995) {
return tunit::seconds;
} else if (micros > 1E3) {
} else if (micros >= 1000) {
return tunit::milliseconds;
} else {
return tunit::microseconds;
Expand Down Expand Up @@ -179,18 +179,20 @@ wcstring timer_snapshot_t::print_delta(timer_snapshot_t t1, timer_snapshot_t t2,
auto child_usr_time = convert(child_usr_micros, child_unit);
auto child_sys_time = convert(child_sys_micros, child_unit);

auto column2_unit_len =
std::max(strlen(unit_short_name(wall_unit)), strlen(unit_short_name(cpu_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"\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));
wall_time, column2_unit_len, unit_short_name(wall_unit),
strlen(unit_short_name(fish_unit)) + 7, "fish", "external", //
usr_time, column2_unit_len, unit_short_name(cpu_unit), fish_usr_time, //
unit_short_name(fish_unit), child_usr_time, unit_short_name(child_unit),
sys_time, column2_unit_len, unit_short_name(cpu_unit), fish_sys_time,
unit_short_name(fish_unit), child_sys_time, unit_short_name(child_unit));
}

return output;
Expand Down