| // Copyright 2018 The Fuchsia Authors. All rights reserved. |
| // Use of this source code is governed by a BSD-style license that can be |
| // found in the LICENSE file. |
| |
| #include <fuchsia/debugdata/cpp/fidl.h> |
| #include <fuchsia/diagnostics/cpp/fidl.h> |
| #include <fuchsia/diagnostics/test/cpp/fidl.h> |
| #include <fuchsia/logger/cpp/fidl.h> |
| #include <fuchsia/sys/cpp/fidl.h> |
| #include <lib/async-loop/cpp/loop.h> |
| #include <lib/async-loop/default.h> |
| #include <lib/async/cpp/task.h> |
| #include <lib/fdio/directory.h> |
| #include <lib/fdio/fd.h> |
| #include <lib/fdio/fdio.h> |
| #include <lib/fidl/cpp/interface_ptr.h> |
| #include <lib/fit/function.h> |
| #include <lib/sys/cpp/file_descriptor.h> |
| #include <lib/sys/cpp/service_directory.h> |
| #include <lib/sys/cpp/termination_reason.h> |
| #include <lib/sys/cpp/testing/enclosing_environment.h> |
| #include <lib/syslog/cpp/macros.h> |
| #include <lib/vfs/cpp/service.h> |
| #include <lib/zx/time.h> |
| #include <stdio.h> |
| #include <zircon/assert.h> |
| #include <zircon/errors.h> |
| #include <zircon/status.h> |
| #include <zircon/syscalls.h> |
| #include <zircon/types.h> |
| |
| #include <memory> |
| #include <sstream> |
| #include <string> |
| #include <vector> |
| |
| #include "lib/fidl/cpp/interface_request.h" |
| #include "lib/zx/object_traits.h" |
| #include "src/lib/files/file.h" |
| #include "src/lib/files/glob.h" |
| #include "src/lib/fxl/strings/string_printf.h" |
| #include "src/sys/run_test_component/component.h" |
| #include "src/sys/run_test_component/log_collector.h" |
| #include "src/sys/run_test_component/run_test_component.h" |
| #include "src/sys/run_test_component/sys_tests.h" |
| #include "src/sys/run_test_component/test_metadata.h" |
| |
| using fuchsia::sys::TerminationReason; |
| |
| namespace { |
| constexpr char kEnvPrefix[] = "test_env_"; |
| const uint64_t kMillisInSec = 1000UL; |
| const uint64_t kMicrosInSec = 1000000UL; |
| const uint64_t kNanosInSec = 1000000000UL; |
| |
| const std::string max_severity_config_path = |
| "/pkgfs/packages/config-data/0/meta/data/run_test_component"; |
| |
| void PrintUsage() { |
| fprintf(stderr, R"( |
| Usage: run_test_component [--realm-label=<label>] [--timeout=<seconds>] [--min-severity-logs=string] [--max-log-severity=string] <test_url>|<test_matcher> -- [arguments...] |
| |
| *test_url* takes the form of component manifest URL which uniquely |
| identifies a test component. Example: |
| fuchsia-pkg://fuchsia.com/component_hello_world#meta/hello.cmx |
| |
| if *test_matcher* is provided, this tool will use component index |
| to find matching component. If multiple urls are found, it will |
| print corresponding component URLs and exit. If there is only |
| one match, it will generate a component URL and execute the test. |
| |
| example: |
| run_test_component run_test_component_unit |
| will match fuchsia-pkg://fuchsia.com/run_test_component_unittests#meta/run_test_component_unittests.cmx and run it. |
| |
| By default each test component will be run in an environment with |
| transient storage and a randomly-generated identifier, ensuring that |
| the tests have no persisted side-effects. If --realm-label is |
| specified then the test will run in a persisted realm with that label, |
| allowing files to be provide to, or retrieve from, the test, e.g. for |
| diagnostic purposes. |
| |
| If --timeout is specified, test would be killed in <timeout> secs and |
| run_test_component will exit with -ZX_ERR_TIMED_OUT. |
| |
| If --max-log-severity is passed, then the test will fail if it produces logs with higher severity. |
| Allowed values: TRACE, DEBUG, INFO, WARN, ERROR, FATAL. |
| For more information see: https://fuchsia.dev/fuchsia-src/development/diagnostics/test_and_logs#restricting_log_severity |
| |
| By default when installing log listener, all logs are collected. To filter |
| by higher severity please pass severity: TRACE, DEBUG, INFO, WARN, ERROR, FATAL. |
| example: run-test-component --min-severity-logs=WARN <url> |
| )"); |
| } |
| |
| bool ConnectToSysEnvironment(zx::channel request) { |
| std::string current_env; |
| files::ReadFileToString("/hub/name", ¤t_env); |
| std::string svc_path = "/hub/svc"; |
| |
| if (current_env == "app") { |
| files::Glob glob("/hub/r/sys/*/svc"); |
| if (glob.size() != 1) { |
| fprintf(stderr, "Cannot run test. Something wrong with hub."); |
| return false; |
| } |
| svc_path = *(glob.begin()); |
| } else if (current_env != "sys") { |
| fprintf(stderr, |
| "Cannot run test in sys environment as this utility was " |
| "started in '%s' environment", |
| current_env.c_str()); |
| return false; |
| } |
| |
| // launch test |
| zx::channel h1, h2; |
| zx_status_t status; |
| if ((status = zx::channel::create(0, &h1, &h2)) != ZX_OK) { |
| fprintf(stderr, "Cannot create channel, status: %d", status); |
| return false; |
| } |
| if ((status = fdio_service_connect(svc_path.c_str(), h1.release())) != ZX_OK) { |
| fprintf(stderr, "Cannot connect to %s, status: %d", svc_path.c_str(), status); |
| return false; |
| } |
| |
| if ((status = fdio_service_connect_at(h2.get(), fuchsia::sys::Environment::Name_, |
| request.release())) != ZX_OK) { |
| fprintf(stderr, "Cannot connect to env service, status: %d", status); |
| return false; |
| } |
| return true; |
| } |
| |
| std::string join_tags(std::vector<std::string> tags) { |
| std::ostringstream stream; |
| for (size_t i = 0; i < tags.size(); ++i) { |
| if (i != 0) { |
| stream << ","; |
| } |
| stream << tags[i]; |
| } |
| return stream.str(); |
| } |
| |
| std::string log_level(int32_t severity) { |
| switch (severity) { |
| case syslog::LOG_TRACE: |
| return "TRACE"; |
| case syslog::LOG_DEBUG: |
| return "DEBUG"; |
| case syslog::LOG_INFO: |
| return "INFO"; |
| case syslog::LOG_WARNING: |
| return "WARNING"; |
| case syslog::LOG_ERROR: |
| return "ERROR"; |
| case syslog::LOG_FATAL: |
| return "FATAL"; |
| } |
| if (severity > syslog::LOG_DEBUG && severity < syslog::LOG_INFO) { |
| std::ostringstream stream; |
| stream << "VLOG(" << -(syslog::LOG_INFO - severity) << ")"; |
| return stream.str(); |
| } |
| return "INVALID"; |
| } |
| |
| std::unique_ptr<run::Component> launch_archivist(const fuchsia::sys::LauncherPtr& launcher, |
| async_dispatcher_t* dispatcher) { |
| fuchsia::sys::LaunchInfo launch_info{ |
| .url = |
| "fuchsia-pkg://fuchsia.com/archivist-for-embedding#meta/" |
| "archivist-for-embedding.cmx", |
| }; |
| launch_info.arguments.emplace({"--v1", "no-log-connector"}); |
| |
| return run::Component::Launch(launcher, std::move(launch_info), dispatcher); |
| } |
| |
| void print_log_message(const std::shared_ptr<fuchsia::logger::LogMessage>& log) { |
| auto time = log->time; |
| printf("[%05ld.%06ld][%ld][%ld][%s] %s: %s\n", time / kNanosInSec, |
| (time / kMillisInSec) % kMicrosInSec, log->pid, log->tid, join_tags(log->tags).c_str(), |
| log_level(log->severity).c_str(), log->msg.c_str()); |
| } |
| |
| void print_dropped_log_count(const std::shared_ptr<fuchsia::logger::LogMessage>& log) { |
| auto time = log->time; |
| printf("[%05ld.%06ld][%ld][%ld][%s] WARNING: Dropped logs count: %u\n", time / kNanosInSec, |
| (time / kMillisInSec) % kMicrosInSec, log->pid, log->tid, join_tags(log->tags).c_str(), |
| log->dropped_logs); |
| } |
| |
| } // namespace |
| |
| int main(int argc, const char** argv) { |
| // Services which we get from /svc. They might be different depending on in which shell this |
| // binary is launched from, so can't use it to create underlying environment. |
| auto namespace_services = sys::ServiceDirectory::CreateFromNamespace(); |
| async::Loop loop(&kAsyncLoopConfigAttachToCurrentThread); |
| |
| auto parse_result = run::ParseArgs(namespace_services, argc, argv); |
| if (parse_result.error) { |
| if (parse_result.error_msg != "") { |
| fprintf(stderr, "%s\n", parse_result.error_msg.c_str()); |
| } |
| PrintUsage(); |
| return 1; |
| } |
| |
| if (parse_result.matching_urls.size() > 1) { |
| fprintf(stderr, "Found multiple matching components. Did you mean?\n"); |
| for (auto url : parse_result.matching_urls) { |
| fprintf(stderr, "%s\n", url.c_str()); |
| } |
| return 1; |
| } else if (parse_result.matching_urls.size() == 1) { |
| fprintf(stdout, "Found one matching component. Running: %s\n", |
| parse_result.matching_urls[0].c_str()); |
| } |
| std::string program_name = parse_result.launch_info.url; |
| |
| // We make a request to the resolver API to ensure that the on-disk package |
| // data is up to date before continuing to try and parse the CMX file. |
| // TODO(raggi): replace this with fuchsia.pkg.Resolver, once it is stable. |
| fuchsia::sys::LoaderSyncPtr loader; |
| zx_status_t status = namespace_services->Connect<fuchsia::sys::Loader>(loader.NewRequest()); |
| if (status != ZX_OK) { |
| fprintf(stderr, "connect to %s failed: %s. Can not continue.\n", fuchsia::sys::Loader::Name_, |
| zx_status_get_string(status)); |
| return 1; |
| } |
| fuchsia::sys::PackagePtr pkg; |
| status = loader->LoadUrl(program_name, &pkg); |
| |
| if (status != ZX_OK) { |
| fprintf(stderr, "Failed to load %s: %s\n", program_name.c_str(), zx_status_get_string(status)); |
| return 1; |
| } |
| |
| if (!pkg) { |
| fprintf(stderr, "Got no package for %s\n", program_name.c_str()); |
| return 1; |
| } |
| |
| if (!pkg->data) { |
| fprintf(stderr, "Got no package metadata for %s\n", program_name.c_str()); |
| return 1; |
| } |
| |
| uint64_t size = pkg->data->size; |
| std::string cmx_str(size, ' '); |
| status = pkg->data->vmo.read(cmx_str.data(), 0, size); |
| if (status != ZX_OK) { |
| fprintf(stderr, "error reading cmx file from vmo %s: %s\n", program_name.c_str(), |
| zx_status_get_string(status)); |
| return 1; |
| } |
| |
| run::TestMetadata test_metadata; |
| if (!test_metadata.ParseFromString(cmx_str, program_name)) { |
| fprintf(stderr, "Error parsing cmx %s: %s\n", program_name.c_str(), |
| test_metadata.error_str().c_str()); |
| return 1; |
| } |
| |
| fuchsia::sys::EnvironmentPtr parent_env; |
| fuchsia::sys::LauncherPtr launcher; |
| std::unique_ptr<sys::testing::EnclosingEnvironment> diagnostics_enclosing_env; |
| std::unique_ptr<sys::testing::EnclosingEnvironment> enclosing_env; |
| |
| std::vector<std::shared_ptr<fuchsia::logger::LogMessage>> restricted_logs; |
| auto max_severity_allowed = parse_result.max_log_severity; |
| bool restrict_logs = max_severity_allowed != syslog::LOG_FATAL; |
| |
| auto log_collector = std::make_unique<run::LogCollector>( |
| [dispather = loop.dispatcher(), restrict_logs, max_severity_allowed, |
| &restricted_logs](fuchsia::logger::LogMessage log) { |
| static std::map<uint64_t, uint32_t> dropped_logs_map; |
| auto log_wrapper = std::make_shared<fuchsia::logger::LogMessage>(std::move(log)); |
| |
| if (restrict_logs && log_wrapper->severity > max_severity_allowed) { |
| restricted_logs.push_back(log_wrapper); |
| } |
| if (log_wrapper->dropped_logs > 0) { |
| auto dropped_logs = |
| dropped_logs_map[log_wrapper->pid]; // default initializer will set it |
| // to zero if key is not found. |
| if (log_wrapper->dropped_logs > dropped_logs) { |
| dropped_logs_map[log_wrapper->pid] = log_wrapper->dropped_logs; |
| print_dropped_log_count(log_wrapper); |
| } |
| } |
| async::PostTask(dispather, [log = std::move(log_wrapper)]() mutable { |
| print_log_message(log); |
| fflush(stdout); |
| }); |
| }); |
| |
| std::unique_ptr<run::Component> archivist_component = nullptr; |
| |
| if (run::should_run_in_sys(parse_result.launch_info.url)) { |
| if (test_metadata.HasServices()) { |
| fprintf(stderr, |
| "Cannot run this test in sys/root environment as it defines " |
| "services in its '%s' facets\n", |
| run::kFuchsiaTest); |
| return 1; |
| } |
| if (!ConnectToSysEnvironment(parent_env.NewRequest().TakeChannel())) { |
| return 1; |
| } |
| |
| parent_env->GetLauncher(launcher.NewRequest()); |
| } else { |
| namespace_services->Connect(parent_env.NewRequest()); |
| |
| // Our bots run tests in zircon shell which do not have all required services, so create the |
| // test environment from `parent_env` (i.e. the sys environment) instead of the services in |
| // the namespace. But pass DebugData from the namespace because it is not available in |
| // `parent_env`. |
| sys::testing::EnvironmentServices::ParentOverrides parent_overrides; |
| parent_overrides.debug_data_publisher_service_ = |
| std::make_shared<vfs::Service>([namespace_services = namespace_services]( |
| zx::channel channel, async_dispatcher_t* /*unused*/) { |
| namespace_services->Connect(fuchsia::debugdata::Publisher::Name_, std::move(channel)); |
| }); |
| |
| auto test_env_services = sys::testing::EnvironmentServices::CreateWithParentOverrides( |
| parent_env, std::move(parent_overrides)); |
| auto services = test_metadata.TakeServices(); |
| bool collect_logs = true; |
| bool offer_collected_logs = true; |
| bool offer_diagnostics_archive = true; |
| for (auto& service : services) { |
| test_env_services->AddServiceWithLaunchInfo(std::move(service.second), service.first); |
| if (service.first == fuchsia::logger::LogSink::Name_) { |
| // don't add log sink service if test component is injecting it. |
| collect_logs = false; |
| } |
| if (service.first == fuchsia::logger::Log::Name_) { |
| // don't add log service if test component is injecting it. |
| offer_collected_logs = false; |
| } |
| if (service.first == fuchsia::diagnostics::ArchiveAccessor::Name_) { |
| // don't add ArchiveAccessor if test component is injecting it. |
| offer_diagnostics_archive = false; |
| } |
| } |
| |
| auto& requested_system_services = test_metadata.system_services(); |
| for (auto& service : requested_system_services) { |
| if (service == fuchsia::logger::LogSink::Name_) { |
| // don't add log sink service if test component is using system service. |
| collect_logs = false; |
| } |
| if (service == fuchsia::logger::Log::Name_) { |
| // don't add log service if test component is using system service. |
| offer_collected_logs = false; |
| } |
| if (service == fuchsia::diagnostics::ArchiveAccessor::Name_) { |
| // don't add ArchiveAccessor if test component is using system service. |
| offer_diagnostics_archive = false; |
| } |
| } |
| |
| // Compute a common random suffix for the environments created to run the test. |
| uint32_t env_rand_suffix; |
| zx_cprng_draw(&env_rand_suffix, sizeof(env_rand_suffix)); |
| |
| if (collect_logs || offer_collected_logs || offer_diagnostics_archive) { |
| // create a nested diagnostics realm and launch the archivist if it'll be used |
| std::string env_label = fxl::StringPrintf("%s%08x", "diagnostics_", env_rand_suffix); |
| diagnostics_enclosing_env = sys::testing::EnclosingEnvironment::Create( |
| std::move(env_label), parent_env, sys::testing::EnvironmentServices::Create(parent_env), |
| fuchsia::sys::EnvironmentOptions{.inherit_parent_services = true, |
| .use_parent_runners = true, |
| .delete_storage_on_death = true}); |
| |
| archivist_component = |
| launch_archivist(diagnostics_enclosing_env->launcher_ptr(), loop.dispatcher()); |
| } |
| if (collect_logs) { |
| ZX_ASSERT(archivist_component != nullptr); |
| test_env_services->AddService<fuchsia::logger::LogSink>( |
| [archivist_svc = archivist_component->svc()]( |
| fidl::InterfaceRequest<fuchsia::logger::LogSink> request) { |
| archivist_svc->Connect(std::move(request)); |
| }); |
| } |
| if (offer_collected_logs) { |
| ZX_ASSERT(archivist_component != nullptr); |
| test_env_services->AddService<fuchsia::logger::Log>( |
| [archivist_svc = |
| archivist_component->svc()](fidl::InterfaceRequest<fuchsia::logger::Log> request) { |
| archivist_svc->Connect(std::move(request)); |
| }); |
| } |
| if (offer_diagnostics_archive) { |
| ZX_ASSERT(archivist_component != nullptr); |
| test_env_services->AddService<fuchsia::diagnostics::ArchiveAccessor>( |
| [archivist_svc = archivist_component->svc()]( |
| fidl::InterfaceRequest<fuchsia::diagnostics::ArchiveAccessor> request) { |
| archivist_svc->Connect(std::move(request)); |
| }); |
| } |
| |
| auto& system_services = test_metadata.system_services(); |
| for (auto& service : system_services) { |
| test_env_services->AllowParentService(service); |
| } |
| |
| // By default run tests in a realm with a random name and transient storage. |
| // Callers may specify a static realm label through which to exchange files |
| // with the test component. |
| std::string env_label = std::move(parse_result.realm_label); |
| fuchsia::sys::EnvironmentOptions env_opt; |
| if (env_label.empty()) { |
| env_label = fxl::StringPrintf("%s%08x", kEnvPrefix, env_rand_suffix); |
| env_opt.delete_storage_on_death = true; |
| } |
| |
| enclosing_env = sys::testing::EnclosingEnvironment::Create( |
| env_label, parent_env, std::move(test_env_services), std::move(env_opt)); |
| |
| if (collect_logs) { |
| ZX_ASSERT(archivist_component != nullptr); |
| // this will launch the service and also collect logs. |
| auto log_ptr = archivist_component->svc()->Connect<fuchsia::logger::Log>(); |
| |
| fidl::InterfaceHandle<fuchsia::logger::LogListenerSafe> log_listener; |
| auto options = std::make_unique<fuchsia::logger::LogFilterOptions>(); |
| options->min_severity = |
| static_cast<fuchsia::logger::LogLevelFilter>(parse_result.min_log_severity); |
| |
| log_collector->Bind(log_listener.NewRequest(), loop.dispatcher()); |
| log_ptr->ListenSafe(std::move(log_listener), std::move(options)); |
| } |
| |
| launcher = enclosing_env->launcher_ptr(); |
| printf("Running test in realm: %s\n", env_label.c_str()); |
| } |
| |
| auto test_component = |
| run::Component::Launch(launcher, std::move(parse_result.launch_info), loop.dispatcher()); |
| |
| int ret_code = 1; |
| |
| bool timed_out = false; |
| std::unique_ptr<async::TaskClosure> timeout_task; |
| |
| if (parse_result.timeout > 0) { |
| timeout_task = std::make_unique<async::TaskClosure>( |
| [&test_component, &program_name, &loop, &timed_out, &ret_code]() { |
| test_component->controller()->Kill(); |
| timed_out = true; |
| ret_code = -ZX_ERR_TIMED_OUT; |
| fprintf(stderr, "%s canceled due to timeout.\n", program_name.c_str()); |
| loop.Quit(); |
| }); |
| |
| timeout_task->PostDelayed(loop.dispatcher(), zx::sec(parse_result.timeout)); |
| } |
| |
| test_component->controller().events().OnTerminated = |
| [&ret_code, &program_name, &loop, &timed_out](int64_t return_code, |
| TerminationReason termination_reason) { |
| // component was killed due to timeout, don't collect results. |
| if (timed_out) { |
| return; |
| } |
| if (termination_reason != TerminationReason::EXITED) { |
| fprintf(stderr, "%s: %s\n", program_name.c_str(), |
| sys::HumanReadableTerminationReason(termination_reason).c_str()); |
| } |
| |
| ret_code = static_cast<int>(return_code); |
| |
| loop.Quit(); |
| }; |
| |
| loop.Run(); |
| loop.ResetQuit(); |
| |
| // make sure timeout is not executed after test finishes. |
| if (timeout_task && timeout_task->is_pending()) { |
| timeout_task->Cancel(); |
| } |
| |
| // Wait and process all messages in the queue. |
| loop.RunUntilIdle(); |
| |
| if (archivist_component) { |
| ZX_ASSERT(enclosing_env); |
| ZX_ASSERT(log_collector); |
| enclosing_env->Kill([&loop]() { loop.Quit(); }); |
| |
| loop.Run(); |
| loop.ResetQuit(); |
| |
| // collect all logs |
| log_collector->NotifyOnUnBind([&loop]() { loop.Quit(); }); |
| |
| auto archivist_ptr = |
| archivist_component->svc()->Connect<fuchsia::diagnostics::test::Controller>(); |
| archivist_ptr->Stop(); |
| loop.Run(); |
| loop.ResetQuit(); |
| |
| // now that archivist is dead, make sure to collect its output |
| loop.RunUntilIdle(); |
| } |
| |
| if (!restricted_logs.empty() && ret_code == 0) { |
| printf("\nTest %s produced unexpected high-severity logs:\n", program_name.c_str()); |
| printf("----------------xxxxx----------------\n"); |
| for (const auto& log : restricted_logs) { |
| print_log_message(log); |
| } |
| printf("----------------xxxxx----------------\n"); |
| printf( |
| "Failing this test. See: " |
| "https://fuchsia.dev/fuchsia-src/development/diagnostics/" |
| "test_and_logs#restricting_log_severity" |
| "\n"); |
| fflush(stdout); |
| ret_code = 1; |
| } |
| |
| return ret_code; |
| } |