From ad5de9d4e56c5512c98f4245b06a0fc118ddeff2 Mon Sep 17 00:00:00 2001 From: Timothy Flynn Date: Sat, 30 Nov 2024 08:51:59 -0500 Subject: [PATCH] headless-browser: Add an option to log per-test durations This adds a verbosity option to log the start and end of each test, with the duration taken for the test. To be able to use this option with our exisiting verbosity flag, without cluttering stdout with other data, we add verbosity levels to headless-browser. The level is increased by providing the -v flag on the command line multiple times. --- UI/Headless/Application.cpp | 16 +++++++++++++++- UI/Headless/Application.h | 6 +++++- UI/Headless/Test.cpp | 30 ++++++++++++++++-------------- UI/Headless/Test.h | 1 + 4 files changed, 37 insertions(+), 16 deletions(-) diff --git a/UI/Headless/Application.cpp b/UI/Headless/Application.cpp index b521d389e74..14d060058ee 100644 --- a/UI/Headless/Application.cpp +++ b/UI/Headless/Application.cpp @@ -45,9 +45,23 @@ void Application::create_platform_arguments(Core::ArgsParser& args_parser) args_parser.add_option(is_layout_test_mode, "Enable layout test mode", "layout-test-mode"); args_parser.add_option(rebaseline, "Rebaseline any executed layout or text tests", "rebaseline"); args_parser.add_option(per_test_timeout_in_seconds, "Per-test timeout (default: 30)", "per-test-timeout", 't', "seconds"); - args_parser.add_option(verbose, "Log extra information about test results", "verbose", 'v'); args_parser.add_option(width, "Set viewport width in pixels (default: 800)", "width", 'W', "pixels"); args_parser.add_option(height, "Set viewport height in pixels (default: 600)", "height", 'H', "pixels"); + + args_parser.add_option(Core::ArgsParser::Option { + .argument_mode = Core::ArgsParser::OptionArgumentMode::Optional, + .help_string = "Log extra information about test results (use multiple times for more information)", + .long_name = "verbose", + .short_name = 'v', + .accept_value = [&](StringView value) -> ErrorOr { + if (value.is_empty() && verbosity < NumericLimits::max()) { + ++verbosity; + return true; + } + + return false; + }, + }); } void Application::create_platform_options(WebView::ChromeOptions& chrome_options, WebView::WebContentOptions& web_content_options) diff --git a/UI/Headless/Application.h b/UI/Headless/Application.h index b916acb0512..7ac5874004a 100644 --- a/UI/Headless/Application.h +++ b/UI/Headless/Application.h @@ -44,6 +44,10 @@ public: callback(*web_view); } + static constexpr u8 VERBOSITY_LEVEL_LOG_TEST_DURATION = 1; + static constexpr u8 VERBOSITY_LEVEL_LOG_SLOWEST_TESTS = 2; + static constexpr u8 VERBOSITY_LEVEL_LOG_SKIPPED_TESTS = 3; + int screenshot_timeout { 1 }; ByteString resources_folder; bool dump_failed_ref_tests { false }; @@ -57,7 +61,7 @@ public: ByteString test_glob; bool test_dry_run { false }; bool rebaseline { false }; - bool verbose { false }; + u8 verbosity { 0 }; int per_test_timeout_in_seconds { 30 }; int width { 800 }; int height { 600 }; diff --git a/UI/Headless/Test.cpp b/UI/Headless/Test.cpp index 84800ce4ede..31b5f2bcec2 100644 --- a/UI/Headless/Test.cpp +++ b/UI/Headless/Test.cpp @@ -443,7 +443,8 @@ ErrorOr run_tests(Core::AnonymousBuffer const& theme, Web::DevicePixelSize size_t skipped_count = 0; bool all_tests_ok = true; - bool is_tty = isatty(STDOUT_FILENO); + // Keep clearing and reusing the same line if stdout is a TTY. + bool log_on_one_line = app.verbosity < Application::VERBOSITY_LEVEL_LOG_TEST_DURATION && isatty(STDOUT_FILENO) == 1; outln("Running {} tests...", tests.size()); auto all_tests_complete = Core::Promise::construct(); @@ -462,19 +463,15 @@ ErrorOr run_tests(Core::AnonymousBuffer const& theme, Web::DevicePixelSize auto& test = tests[index]; test.start_time = UnixDateTime::now(); + test.index = index + 1; - if (is_tty) { - // Keep clearing and reusing the same line if stdout is a TTY. - out("\33[2K\r"); + if (log_on_one_line) { + out("\33[2K\r{}/{}: {}", test.index, tests.size(), test.relative_path); + (void)fflush(stdout); + } else { + outln("{}/{}: Start {}", test.index, tests.size(), test.relative_path); } - out("{}/{}: {}", index + 1, tests.size(), test.relative_path); - - if (is_tty) - fflush(stdout); - else - outln(""); - Core::deferred_invoke([&]() mutable { if (s_skipped_tests.contains_slow(test.input_path)) view.on_test_complete({ test, TestResult::Skipped }); @@ -486,6 +483,11 @@ ErrorOr run_tests(Core::AnonymousBuffer const& theme, Web::DevicePixelSize view.test_promise().when_resolved([&, run_next_test](auto result) { result.test.end_time = UnixDateTime::now(); + if (app.verbosity >= Application::VERBOSITY_LEVEL_LOG_TEST_DURATION) { + auto duration = result.test.end_time - result.test.start_time; + outln("{}/{}: Finish {}: {}ms", result.test.index, tests.size(), result.test.relative_path, duration.to_milliseconds()); + } + switch (result.result) { case TestResult::Pass: ++pass_count; @@ -523,7 +525,7 @@ ErrorOr run_tests(Core::AnonymousBuffer const& theme, Web::DevicePixelSize MUST(all_tests_complete->await()); - if (is_tty) + if (log_on_one_line) outln("\33[2K\rDone!"); outln("=========================================================="); @@ -531,13 +533,13 @@ ErrorOr run_tests(Core::AnonymousBuffer const& theme, Web::DevicePixelSize outln("=========================================================="); for (auto const& non_passing_test : non_passing_tests) { - if (non_passing_test.result == TestResult::Skipped && !app.verbose) + if (non_passing_test.result == TestResult::Skipped && app.verbosity < Application::VERBOSITY_LEVEL_LOG_SKIPPED_TESTS) continue; outln("{}: {}", test_result_to_string(non_passing_test.result), non_passing_test.test.relative_path); } - if (app.verbose) { + if (app.verbosity >= Application::VERBOSITY_LEVEL_LOG_SLOWEST_TESTS) { auto tests_to_print = min(10uz, tests.size()); outln("\nSlowest {} tests:", tests_to_print); diff --git a/UI/Headless/Test.h b/UI/Headless/Test.h index 22f112018a1..d7ee5b78531 100644 --- a/UI/Headless/Test.h +++ b/UI/Headless/Test.h @@ -63,6 +63,7 @@ struct Test { UnixDateTime start_time {}; UnixDateTime end_time {}; + size_t index { 0 }; String text {}; bool did_finish_test { false };