diff --git a/CHANGELOG.md b/CHANGELOG.md index 8e24c3baad6..819090eadfe 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/) a ### Changed +- CCF-owned fatal termination paths now all emit flushed diagnostics to stderr, while recoverable logs and fatal-severity-only entries remain on stdout. See [Logging](doc/build_apps/logging.rst) (#8690). - CCF consensus protocol tracing now uses `ccf.cft` for the Fluentd tag (#8657). - `observability.fluentd` now accepts an array of independent sinks, and configurable delivery behaviour. See [Observability Export](doc/operations/configuration.rst#observability-export) for more details (#8666). diff --git a/doc/build_apps/logging.rst b/doc/build_apps/logging.rst index 18abd28174f..225194874c1 100644 --- a/doc/build_apps/logging.rst +++ b/doc/build_apps/logging.rst @@ -1,7 +1,14 @@ Logging ======= -.. note:: The experimental :doc:`Rust SDK ` does not expose this logging API. Output from Rust's ``print!`` and ``eprint!`` macros is visible to the host, so it must not contain confidential data. +CCF-generated log records are written to stdout at every severity, including ``fail`` and ``fatal``. +The ``fatal`` severity label alone does not mean that the node will terminate or that the message will be written to stderr. +CCF writes a flushed diagnostic to stderr when a fatal path terminates the node or process; recoverable errors and ordinary log records remain on stdout. + +This contract covers diagnostics produced by CCF itself. +Applications and dependencies may write directly to stderr, and runtime-generated diagnostics such as assertion failures, uncaught C++ exceptions, or Rust panic hooks may also appear there. +Those outputs are outside CCF's guarantee and must not contain confidential data. +The experimental :doc:`Rust SDK ` does not expose the CCF logging API, so output from Rust's ``print!`` and ``eprint!`` macros is visible to the host and must not contain confidential data. To add your own lines to the node's output you should use the ``CCF_APP_*`` macros defined in ``ccf/ds/logger.h``: diff --git a/src/ds/files.h b/src/ds/files.h index c45ef9ba692..0cec78443f7 100644 --- a/src/ds/files.h +++ b/src/ds/files.h @@ -3,6 +3,7 @@ #pragma once #include "ccf/ds/nonstd.h" +#include "ds/internal_logger.h" #include #include @@ -101,7 +102,8 @@ namespace files { return {}; } - std::cerr << "Could not open file " << file << std::endl; + ccf::logger::write_fatal_diagnostic( + fmt::format("Could not open file {}", file)); exit(-1); // NOLINT(concurrency-mt-unsafe) } @@ -113,7 +115,8 @@ namespace files if (!optional && !f) { - std::cerr << "Could not read file " << file << std::endl; + ccf::logger::write_fatal_diagnostic( + fmt::format("Could not read file {}", file)); exit(-1); // NOLINT(concurrency-mt-unsafe) } return data; diff --git a/src/ds/internal_logger.h b/src/ds/internal_logger.h index 4016fc51fb4..7a634a0e310 100644 --- a/src/ds/internal_logger.h +++ b/src/ds/internal_logger.h @@ -4,12 +4,22 @@ #include "ccf/ds/logger.h" +#include +#include + // Defines the LOG_*_FMT macros that should be used for logging by // framework-internal components. Alternatively, replace with macros which add a // system-specific tag. namespace ccf::logger { + inline void write_fatal_diagnostic(std::string_view message) + { + // A single insertion keeps concurrent diagnostics on separate lines, since + // std::cerr is synchronised with stdio and each write takes its lock. + std::cerr << fmt::format("Fatal error: {}\n", message) << std::flush; + } + #define LOG_TRACE_FMT CCF_LOG_FMT(TRACE, "") #define LOG_DEBUG_FMT CCF_LOG_FMT(DEBUG, "") #define LOG_INFO_FMT CCF_LOG_FMT(INFO, "") diff --git a/src/ds/test/logger.cpp b/src/ds/test/logger.cpp index 55072efafb8..947043eae96 100644 --- a/src/ds/test/logger.cpp +++ b/src/ds/test/logger.cpp @@ -9,8 +9,10 @@ #include #include #include +#include #include #include +#include #include #include #include @@ -94,6 +96,54 @@ class ScopedLoggerConfig } }; +class ScopedCerrCapture +{ + std::ostringstream captured; + std::streambuf* previous = std::cerr.rdbuf(captured.rdbuf()); + +public: + ScopedCerrCapture() = default; + ScopedCerrCapture(const ScopedCerrCapture&) = delete; + ScopedCerrCapture& operator=(const ScopedCerrCapture&) = delete; + + ~ScopedCerrCapture() + { + std::cerr.rdbuf(previous); + } + + std::string str() const + { + return captured.str(); + } +}; + +class ScopedCoutCapture +{ + std::ostringstream captured; + std::streambuf* previous = std::cout.rdbuf(captured.rdbuf()); + +public: + ScopedCoutCapture() = default; + ScopedCoutCapture(const ScopedCoutCapture&) = delete; + ScopedCoutCapture& operator=(const ScopedCoutCapture&) = delete; + + ~ScopedCoutCapture() + { + std::cout.rdbuf(previous); + } + + void clear() + { + captured.str(""); + captured.clear(); + } + + std::string str() const + { + return captured.str(); + } +}; + #ifndef CCF_CFT_TRACING TEST_CASE("Logger timestamp retains microsecond precision") { @@ -257,6 +307,38 @@ TEST_CASE("Framework logging macros") ccf::logger::config::loggers().clear(); } +TEST_CASE("Only explicit fatal diagnostics write to stderr") +{ + const ScopedLoggerConfig restore_config; + ccf::logger::config::level() = ccf::LoggerLevel::TRACE; + ScopedCoutCapture captured_out; + ScopedCerrCapture captured_err; + + const auto check_console_logger = [&](auto logger) { + auto& loggers = ccf::logger::config::loggers(); + loggers.clear(); + loggers.emplace_back(std::move(logger)); + captured_out.clear(); + + LOG_INFO_FMT("Recoverable information"); + LOG_FAIL_FMT("Recoverable failure"); + LOG_FATAL_FMT("Fatal severity label without termination"); + + CHECK(captured_err.str().empty()); + const auto output = captured_out.str(); + CHECK(output.contains("Recoverable information")); + CHECK(output.contains("Recoverable failure")); + CHECK(output.contains("Fatal severity label without termination")); + }; + + check_console_logger(std::make_unique()); + check_console_logger(std::make_unique()); + captured_out.clear(); + ccf::logger::write_fatal_diagnostic("Node terminated"); + CHECK(captured_out.str().empty()); + CHECK(captured_err.str() == "Fatal error: Node terminated\n"); +} + TEST_CASE("Application logging macros") { std::vector logs; diff --git a/src/host/run.cpp b/src/host/run.cpp index bebb40c1640..c51dfbb6c69 100644 --- a/src/host/run.cpp +++ b/src/host/run.cpp @@ -246,6 +246,8 @@ namespace ccf catch (const std::exception& e) { LOG_FAIL_FMT("Exception in ccf::run: {}", e.what()); + ccf::logger::write_fatal_diagnostic( + "Enclave runtime thread failed; see stdout logs for details"); throw; } @@ -416,8 +418,10 @@ namespace ccf } catch (const std::exception& e) { - LOG_FATAL_FMT( + const auto message = fmt::format( "Invalid address for RPC interface {}: {}. Exiting.", name, e.what()); + LOG_FATAL_FMT("{}", message); + ccf::logger::write_fatal_diagnostic(message); return static_cast(CLI::ExitCodes::ValidationError); } } @@ -434,9 +438,11 @@ namespace ccf files::exists(config.ledger.directory) && !fs::is_empty(config.ledger.directory)) { - LOG_FATAL_FMT( + const auto message = fmt::format( "On start, ledger directory should not exist or be empty ({})", config.ledger.directory); + LOG_FATAL_FMT("{}", message); + ccf::logger::write_fatal_diagnostic(message); return static_cast(CLI::ExitCodes::ValidationError); } @@ -447,10 +453,12 @@ namespace ccf files::exists(readonly_ledger_directory) && !fs::is_empty(readonly_ledger_directory)) { - LOG_FATAL_FMT( + const auto message = fmt::format( "On start, read-only ledger directories should not exist or be " "empty ({})", readonly_ledger_directory); + LOG_FATAL_FMT("{}", message); + ccf::logger::write_fatal_diagnostic(message); return static_cast(CLI::ExitCodes::ValidationError); } } @@ -459,7 +467,9 @@ namespace ccf config.command.type != StartType::Join && config.command.type != StartType::Recover) { - LOG_FATAL_FMT("Start command should be start|join|recover. Exiting."); + constexpr auto message = "Start command should be start|join|recover."; + LOG_FATAL_FMT("{} Exiting.", message); + ccf::logger::write_fatal_diagnostic(message); return static_cast(CLI::ExitCodes::ValidationError); } @@ -471,6 +481,8 @@ namespace ccf { LOG_FAIL_FMT( "2TX reconfiguration is experimental, disabled in release mode"); + ccf::logger::write_fatal_diagnostic( + "2TX reconfiguration is disabled in release mode"); return CreateNodeStatus::ReconfigurationMethodNotSupported; } @@ -525,11 +537,21 @@ namespace ccf // Startup diagnostics are safe here: no runtime thread has executed, // and locally generated secrets will be discarded. LOG_FAIL_FMT("Error starting node: {}", e.what()); + ccf::logger::write_fatal_diagnostic( + "Node startup failed; see stdout logs for details"); return failure_status; } run_enclave_threads(config, *enclave); - runtime_control->throw_if_fatal_error(); + try + { + runtime_control->throw_if_fatal_error(); + } + catch (const std::exception& e) + { + LOG_FAIL_FMT("Exception in ccf::run: {}", e.what()); + return CreateNodeStatus::InternalError; + } return std::nullopt; } @@ -552,11 +574,13 @@ namespace ccf #endif } - int run(int argc, char** argv) // NOLINT(bugprone-exception-escape) + // NOLINTNEXTLINE(misc-use-anonymous-namespace) + static int run_impl(int argc, char** argv) { if (signal(SIGPIPE, SIG_IGN) == SIG_ERR) { LOG_FAIL_FMT("Failed to ignore SIGPIPE"); + ccf::logger::write_fatal_diagnostic("Failed to ignore SIGPIPE"); return 1; } @@ -703,6 +727,7 @@ namespace ccf catch (const std::logic_error& e) { LOG_FATAL_FMT("{}. Exiting.", e.what()); + ccf::logger::write_fatal_diagnostic(e.what()); return static_cast(CLI::ExitCodes::ValidationError); } @@ -769,6 +794,7 @@ namespace ccf catch (const std::logic_error& e) { LOG_FATAL_FMT("{}. Exiting.", e.what()); + ccf::logger::write_fatal_diagnostic(e.what()); return static_cast(CLI::ExitCodes::ValidationError); } @@ -777,6 +803,8 @@ namespace ccf { LOG_FATAL_FMT( "PID file {} already exists. Exiting.", pid_file_path.string()); + ccf::logger::write_fatal_diagnostic( + fmt::format("PID file {} already exists", pid_file_path.string())); return static_cast(CLI::ExitCodes::FileError); } @@ -797,6 +825,9 @@ namespace ccf catch (const std::exception& e) { LOG_FAIL_FMT("Exception in ccf::run: {}", e.what()); + ccf::logger::write_fatal_diagnostic( + "Unhandled exception while running the node; see stdout logs for " + "details"); inner_ret = CreateNodeStatus::InternalError; } @@ -821,6 +852,8 @@ namespace ccf { LOG_FAIL_FMT( "Failed to close uv loop cleanly: {}", uv_err_name(loop_close_rc)); + ccf::logger::write_fatal_diagnostic(fmt::format( + "Failed to close the host event loop: {}", uv_err_name(loop_close_rc))); // walk loop to diagnose unclosed handles auto cb = [](uv_handle_t* handle, void* arg) { (void)arg; @@ -835,4 +868,25 @@ namespace ccf return inner_ret.value_or(loop_close_rc); } + + int run(int argc, char** argv) // NOLINT(bugprone-exception-escape) + { + try + { + return run_impl(argc, argv); + } + catch (const std::exception& e) + { + LOG_FAIL_FMT("Unhandled exception in ccf::run: {}", e.what()); + ccf::logger::write_fatal_diagnostic( + fmt::format("Unhandled exception in CCF node: {}", e.what())); + return CreateNodeStatus::InternalError; + } + catch (...) + { + LOG_FAIL_FMT("Unhandled exception in ccf::run"); + ccf::logger::write_fatal_diagnostic("Unhandled exception in CCF node"); + return CreateNodeStatus::InternalError; + } + } } diff --git a/src/host/runtime_control.h b/src/host/runtime_control.h index fe68d5b8675..1df9b8002fe 100644 --- a/src/host/runtime_control.h +++ b/src/host/runtime_control.h @@ -7,7 +7,6 @@ #include "uv/proxy.h" #include -#include #include #include #include @@ -76,7 +75,7 @@ namespace asynchost if (!fatal_error.has_value()) { fatal_error = message; - std::cerr << message << std::endl << std::flush; + ccf::logger::write_fatal_diagnostic(message); } } diff --git a/src/host/socket.h b/src/host/socket.h index 7a0b7ce7e6b..99b83cbd6e8 100644 --- a/src/host/socket.h +++ b/src/host/socket.h @@ -75,13 +75,17 @@ namespace asynchost /// Failure loggers for when things go wrong, fataly virtual void on_resolve_failed() { - LOG_FATAL_FMT("{} {} resolve failed", conn_name, name); + const auto message = fmt::format("{} {} resolve failed", conn_name, name); + LOG_FATAL_FMT("{}", message); + ccf::logger::write_fatal_diagnostic(message); abort(); } virtual void on_listen_failed() { - LOG_FATAL_FMT("{} {} listen failed", conn_name, name); + const auto message = fmt::format("{} {} listen failed", conn_name, name); + LOG_FATAL_FMT("{}", message); + ccf::logger::write_fatal_diagnostic(message); abort(); } }; diff --git a/src/host/test/runtime_control.cpp b/src/host/test/runtime_control.cpp index 7fdcc49b609..fd2aa7b85e1 100644 --- a/src/host/test/runtime_control.cpp +++ b/src/host/test/runtime_control.cpp @@ -9,6 +9,32 @@ #define DOCTEST_CONFIG_IMPLEMENT_WITH_MAIN #include #include +#include +#include + +namespace +{ + class ScopedCerrCapture + { + std::ostringstream captured; + std::streambuf* previous = std::cerr.rdbuf(captured.rdbuf()); + + public: + ScopedCerrCapture() = default; + ScopedCerrCapture(const ScopedCerrCapture&) = delete; + ScopedCerrCapture& operator=(const ScopedCerrCapture&) = delete; + + ~ScopedCerrCapture() + { + std::cerr.rdbuf(previous); + } + + std::string str() const + { + return captured.str(); + } + }; +} TEST_CASE("Runtime control" * doctest::test_suite("runtime_control")) { @@ -22,24 +48,30 @@ TEST_CASE("Runtime control" * doctest::test_suite("runtime_control")) SUBCASE("`request_restart()` requests enclave shutdown") { + const ScopedCerrCapture stderr_output; runtime_control->request_restart(); REQUIRE(enclave_stop_request_count == 1); REQUIRE_NOTHROW(runtime_control->throw_if_fatal_error()); + CHECK(stderr_output.str().empty()); } SUBCASE("`report_stopped()` stops the host loop") { + const ScopedCerrCapture stderr_output; runtime_control->report_stopped(); uv_run(uv_default_loop(), UV_RUN_NOWAIT); REQUIRE(enclave_stop_request_count == 0); REQUIRE_NOTHROW(runtime_control->throw_if_fatal_error()); + CHECK(stderr_output.str().empty()); } SUBCASE( "`report_fatal_error()` requests enclave shutdown and preserves the " "error") { + const ScopedCerrCapture stderr_output; runtime_control->report_fatal_error("join failed"); + CHECK(stderr_output.str() == "Fatal error: join failed\n"); runtime_control->report_stopped(); uv_run(uv_default_loop(), UV_RUN_NOWAIT); REQUIRE(enclave_stop_request_count == 1); diff --git a/src/node/node_state.h b/src/node/node_state.h index 5c32fc11c51..ef60ad62ca1 100644 --- a/src/node/node_state.h +++ b/src/node/node_state.h @@ -1001,7 +1001,8 @@ namespace ccf status, std::string(data.begin(), data.end())); LOG_FAIL_FMT("{}", error_msg); - runtime_control.report_fatal_error(error_msg); + runtime_control.report_fatal_error(fmt::format( + "Join request to {} returned HTTP status {}", target_address, status)); } void handle_join_unexpected_status_unsafe( @@ -1024,9 +1025,8 @@ namespace ccf else { LOG_FAIL_FMT( - "An error occurred while joining the network: {} {}{}", + "An error occurred while joining the network: HTTP status {}{}", status, - ccf::http_status_str(status), data.empty() ? "" : fmt::format(" '{}'", std::string(data.begin(), data.end()))); @@ -1124,7 +1124,8 @@ namespace ccf "node gracefully...", e.what()); LOG_FAIL_FMT("{}", error_msg); - runtime_control.report_fatal_error(error_msg); + runtime_control.report_fatal_error( + "Failed to install startup snapshot"); return; } } diff --git a/src/node/rpc/frontend.h b/src/node/rpc/frontend.h index f089c05ca6e..8a551924015 100644 --- a/src/node/rpc/frontend.h +++ b/src/node/rpc/frontend.h @@ -1101,6 +1101,8 @@ namespace ccf // Better to abort. LOG_DEBUG_FMT("Failed to serialise: {}", e.what()); LOG_FATAL_FMT("Failed to serialise"); + ccf::logger::write_fatal_diagnostic( + "Failed to serialise committed transaction"); abort(); } catch (const std::exception& e) diff --git a/src/node/rpc/test/frontend_test.cpp b/src/node/rpc/test/frontend_test.cpp index f5bd00d8b86..15885b08d72 100644 --- a/src/node/rpc/test/frontend_test.cpp +++ b/src/node/rpc/test/frontend_test.cpp @@ -31,6 +31,14 @@ using namespace ccf; using namespace std; +TEST_CASE("Unknown client HTTP status codes remain usable in diagnostics") +{ + const auto status = static_cast(471); + + CHECK(ccf::is_http_status_client_error(status)); + CHECK(fmt::format("HTTP status {}", status) == "HTTP status 471"); +} + template class TSimpleFrontend : public RpcFrontend { diff --git a/src/tasks/test/basic_tasks.cpp b/src/tasks/test/basic_tasks.cpp index ca7f23eaf5d..a7c73be922d 100644 --- a/src/tasks/test/basic_tasks.cpp +++ b/src/tasks/test/basic_tasks.cpp @@ -6,10 +6,15 @@ #include "tasks/task_system.h" #include "tasks/worker.h" +#include #include #include #include +#include +#include +#include #include +#include #define FMT_HEADER_ONLY #include @@ -434,8 +439,74 @@ namespace exception_handling_test }; } +class ScopedTaskCerrCapture +{ + std::ostringstream captured; + std::streambuf* previous = std::cerr.rdbuf(captured.rdbuf()); + +public: + ScopedTaskCerrCapture() = default; + ScopedTaskCerrCapture(const ScopedTaskCerrCapture&) = delete; + ScopedTaskCerrCapture& operator=(const ScopedTaskCerrCapture&) = delete; + + ~ScopedTaskCerrCapture() + { + std::cerr.rdbuf(previous); + } + + std::string str() const + { + return captured.str(); + } +}; + +void expect_aborting_task_diagnostic( + ccf::tasks::BaseTask& task, const std::string& expected_diagnostic) +{ + int stderr_pipe[2]; + REQUIRE(pipe(stderr_pipe) == 0); + + const auto child = fork(); + REQUIRE(child >= 0); + if (child == 0) + { + close(stderr_pipe[0]); + if (dup2(stderr_pipe[1], STDERR_FILENO) == -1) + { + _exit(EXIT_FAILURE); + } + close(stderr_pipe[1]); + + const rlimit no_core_dump{0, 0}; + if (setrlimit(RLIMIT_CORE, &no_core_dump) != 0) + { + _exit(EXIT_FAILURE); + } + ccf::tasks::try_do_task(task); + _exit(EXIT_SUCCESS); + } + + close(stderr_pipe[1]); + std::string diagnostic; + char buffer[256]; + ssize_t count = 0; + while ((count = read(stderr_pipe[0], buffer, sizeof(buffer))) > 0) + { + diagnostic.append(buffer, static_cast(count)); + } + close(stderr_pipe[0]); + + int status = 0; + REQUIRE(waitpid(child, &status, 0) == child); + REQUIRE(WIFSIGNALED(status)); + CHECK(WTERMSIG(status) == SIGABRT); + CHECK(diagnostic.contains(expected_diagnostic)); +} + TEST_CASE("Exception handling" * doctest::test_suite("basic_tasks")) { + ScopedTaskCerrCapture captured_stderr; + // Custom logger that captures log messages for assertion struct CapturingLogger : public ccf::logger::AbstractLogger { @@ -508,6 +579,7 @@ TEST_CASE("Exception handling" * doctest::test_suite("basic_tasks")) // With CCF_TASK_EXCEPTION_NO_ABORT, the worker loop continues after // exceptions, so the success task should have run REQUIRE(success_task_ran.load()); + CHECK(captured_stderr.str().empty()); // Verify that fatal messages were logged for both exception types REQUIRE(logger_ptr->contains( @@ -534,3 +606,15 @@ TEST_CASE("Exception handling" * doctest::test_suite("basic_tasks")) [logger_ptr](const auto& l) { return l.get() == logger_ptr; }), loggers.end()); } + +TEST_CASE( + "Aborting task exceptions write a fatal diagnostic" * + doctest::test_suite("basic_tasks")) +{ + exception_handling_test::ThrowsException throws_exception; + expect_aborting_task_diagnostic( + throws_exception, "Fatal error: Task failed with an exception"); + exception_handling_test::ThrowsUnknown throws_unknown; + expect_aborting_task_diagnostic( + throws_unknown, "Fatal error: Task failed with an unknown exception"); +} diff --git a/src/tasks/worker.cpp b/src/tasks/worker.cpp index c4f6526fa2d..d8c3b273bd6 100644 --- a/src/tasks/worker.cpp +++ b/src/tasks/worker.cpp @@ -283,6 +283,8 @@ extern "C" reinterpret_cast(dlsym(RTLD_NEXT, "__cxa_throw")); if (real_cxa_throw == nullptr) { + ccf::logger::write_fatal_diagnostic( + "Failed to resolve the C++ exception runtime handler"); std::abort(); } diff --git a/src/tasks/worker.h b/src/tasks/worker.h index 57c94ab5823..b193b7c3a3b 100644 --- a/src/tasks/worker.h +++ b/src/tasks/worker.h @@ -36,6 +36,7 @@ namespace ccf::tasks "{} task failed with exception: {}", task.get_name(), e.what())); if (abort_on_throw) { + ccf::logger::write_fatal_diagnostic("Task failed with an exception"); std::abort(); } } @@ -45,6 +46,8 @@ namespace ccf::tasks fmt::format("{} task failed with unknown exception", task.get_name())); if (abort_on_throw) { + ccf::logger::write_fatal_diagnostic( + "Task failed with an unknown exception"); std::abort(); } } diff --git a/tests/code_update.py b/tests/code_update.py index a4175d05641..a9ae40ad9c3 100644 --- a/tests/code_update.py +++ b/tests/code_update.py @@ -514,6 +514,9 @@ def test_start_node_with_mismatched_host_data(network, args): ) except (TimeoutError, RuntimeError): LOG.info("As expected, node with invalid security policy failed to startup") + network.ignore_error_pattern_on_shutdown( + "Fatal error: Node startup failed; see stdout logs for details" + ) else: raise AssertionError("Node startup unexpectedly succeeded") @@ -599,6 +602,16 @@ def register_signed_statement(node, signed_statement): return transparent_statement +def check_join_failure_diagnostic(join_error): + """Check that a rejected joiner reported a fatal stderr diagnostic that + does not include the join response body.""" + _, err_path = join_error.node.get_logs() + with open(err_path, "r", encoding="utf-8") as f: + err = f.read() + assert "Fatal error: Join request to" in err, err + assert "host data is not authorised" not in err, err + + def assert_node_join_fails(network, args): """Create a node and assert that joining the network raises HostDataNotFound.""" new_node = network.create_node() @@ -609,6 +622,7 @@ def assert_node_join_fails(network, args): assert ( "host data is not authorised" in e.error_line ), f"Expected 'host data is not authorised' in error, got: {e.error_line}" + check_join_failure_diagnostic(e) else: raise AssertionError("Node join unexpectedly succeeded") @@ -800,8 +814,9 @@ def test_add_node_with_untrusted_host_data(network, args): new_node = network.create_node() try: network.join_node(new_node, args.package, args, timeout=3, from_snapshot=False) - except infra.network.HostDataNotFound: + except infra.network.HostDataNotFound as e: LOG.info("As expected, node with untrusted host data failed to join") + check_join_failure_diagnostic(e) else: raise AssertionError("Node join unexpectedly succeeded") diff --git a/tests/e2e_operations.py b/tests/e2e_operations.py index 548d3c21d48..f2626df1ebd 100644 --- a/tests/e2e_operations.py +++ b/tests/e2e_operations.py @@ -3132,6 +3132,9 @@ def run_empty_ledger_dir_check(args): network.start(args, ledger_dir=tmp_dir) except Exception as start_error: LOG.debug(f"Ignoring expected network start failure: {start_error}") + network.ignore_error_pattern_on_shutdown( + "On start, ledger directory should not exist or be empty" + ) # Check that the node has failed with the expected error message if not primary.check_log_for_error_message( diff --git a/tests/infra/network.py b/tests/infra/network.py index 48e59c15b13..612758086ed 100644 --- a/tests/infra/network.py +++ b/tests/infra/network.py @@ -168,7 +168,13 @@ def log_errors( try: with open(err_path, "r", errors="replace", encoding="utf-8") as lines: fatal_error_lines = [ - line for line in lines if not line.startswith("[ perf record:") + line + for line in lines + if not line.startswith("[ perf record:") + and not ( + ignore_error_patterns is not None + and any(pattern in line for pattern in ignore_error_patterns) + ) ] if fatal_error_lines: LOG.error(f"Contents of {err_path}:\n{''.join(fatal_error_lines)}")