From c42bedffe81372cecc68319c30068e66e8f79ec4 Mon Sep 17 00:00:00 2001 From: Eddy Ashton Date: Fri, 7 Jul 2023 15:13:51 +0100 Subject: [PATCH] Permit Trace+Debug logging in all non-SGX builds (#5375) (cherry picked from commit cd330415053d4ace4d7e89812d0ad2998e9b3745) --- CHANGELOG.md | 6 ++++ CMakeLists.txt | 32 +++++++++++------ cmake/version.cmake | 6 +++- doc/build_apps/logging.rst | 2 +- doc/contribute/build_ccf.rst | 1 - doc/host_config_schema/cchost_config.json | 2 +- edl/ccf.edl | 1 + include/ccf/ds/logger.h | 44 +++++++++++------------ include/ccf/ds/logger_level.h | 13 +++++++ scripts/scan-build.sh | 3 -- src/common/configuration.h | 17 ++++----- src/common/enclave_interface_types.h | 2 ++ src/consensus/aft/test/driver.cpp | 2 +- src/consensus/aft/test/main.cpp | 2 +- src/ds/test/logger_bench.cpp | 8 ++--- src/ds/test/logger_json_test.cpp | 2 +- src/enclave/interface.h | 2 +- src/enclave/main.cpp | 20 +++++++++++ src/enclave/virtual_enclave.h | 3 ++ src/host/configuration.h | 2 +- src/host/enclave.h | 6 ++-- src/host/main.cpp | 16 +++++++++ src/http/test/http_test.cpp | 2 +- src/kv/test/kv_bench.cpp | 10 +++--- src/kv/test/kv_contention.cpp | 2 +- src/node/rpc/gov_logging.h | 2 +- src/node/test/history_bench.cpp | 2 +- tests/infra/e2e_args.py | 12 +++++-- tests/infra/network.py | 1 + tests/infra/remote.py | 22 +++++++++++- 30 files changed, 171 insertions(+), 74 deletions(-) create mode 100644 include/ccf/ds/logger_level.h diff --git a/CHANGELOG.md b/CHANGELOG.md index c98ad0688d51..f98360181f51 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,12 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](http://keepachangelog.com/en/1.0.0/) and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.html). +## [4.0.5] + +[4.0.5]: https://github.com/microsoft/CCF/releases/tag/ccf-4.0.5 + +- Debug logging is now available in non-SGX builds by default, and controlled by a run-time CLI argument (`--enclave-log-level`). On SGX this remains a build-time decision (#5375). + ## [4.0.4] [4.0.4]: https://github.com/microsoft/CCF/releases/tag/ccf-4.0.4 diff --git a/CMakeLists.txt b/CMakeLists.txt index f5efab06bd72..d561aa8fb7f4 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -74,11 +74,25 @@ else() unset(NODES) endif() -option(VERBOSE_LOGGING "Enable verbose, unsafe logging of enclave code" OFF) -set(TEST_HOST_LOGGING_LEVEL "info") +option( + VERBOSE_LOGGING + "Enable verbose, potentially unsafe logging of enclave code. Affects logging level passed at run-time to end-to-end-tests, and compile-time max verbosity on SGX." + OFF +) +set(TEST_LOGGING_LEVEL "info") if(VERBOSE_LOGGING) - set(TEST_HOST_LOGGING_LEVEL "trace") - add_compile_definitions(VERBOSE_LOGGING) + set(TEST_LOGGING_LEVEL "trace") +endif() + +# NB: Toggling VERBOSE_LOGGING on non-SGX platforms causes no build change, so +# should not cause a rebuild +if(COMPILE_TARGET STREQUAL "sgx" AND NOT VERBOSE_LOGGING) + # Disable verbose, unsafe logging of enclave code. On some platforms it is + # safe to build with this logging enabled, and then it can be disabled at + # run-time. However this run-time control is not possible on SGX, so to ensure + # a given MRENCLAVE cannot leak via debug logging it must be removed at + # build-time, with this option. + add_compile_definitions(CCF_DISABLE_VERBOSE_LOGGING) endif() option(USE_NULL_ENCRYPTOR "Turn off encryption of ledger updates - debug only" @@ -275,9 +289,6 @@ target_compile_options( ) target_include_directories(cchost PRIVATE ${CCF_GENERATED_DIR}) -# Host is always built with verbose logging enabled, regardless of CMake option -target_compile_definitions(cchost PRIVATE VERBOSE_LOGGING) - if(COMPILE_TARGET STREQUAL "sgx") target_compile_definitions(cchost PUBLIC PLATFORM_SGX) elseif(COMPILE_TARGET STREQUAL "snp") @@ -434,8 +445,9 @@ set(CCF_NETWORK_TEST_DEFAULT_CONSTITUTION --constitution ${CCF_DIR}/samples/constitutions/default/apply.js ) -set(CCF_NETWORK_TEST_ARGS --host-log-level ${TEST_HOST_LOGGING_LEVEL} - --worker-threads ${WORKER_THREADS} +set(CCF_NETWORK_TEST_ARGS + --host-log-level ${TEST_LOGGING_LEVEL} --enclave-log-level + ${TEST_LOGGING_LEVEL} --worker-threads ${WORKER_THREADS} ) if(COMPILE_TARGET STREQUAL "sgx") @@ -851,7 +863,6 @@ if(BUILD_TESTS) logger_json_test ${CMAKE_CURRENT_SOURCE_DIR}/src/ds/test/logger_json_test.cpp ) - target_compile_definitions(logger_json_test PUBLIC VERBOSE_LOGGING) add_unit_test( kv_test @@ -1108,7 +1119,6 @@ if(BUILD_TESTS) # Picobench benchmarks add_picobench(map_bench SRCS src/ds/test/map_bench.cpp) add_picobench(logger_bench SRCS src/ds/test/logger_bench.cpp) - target_compile_definitions(logger_bench PUBLIC VERBOSE_LOGGING) add_picobench(json_bench SRCS src/ds/test/json_bench.cpp) add_picobench(ring_buffer_bench SRCS src/ds/test/ring_buffer_bench.cpp) add_picobench( diff --git a/cmake/version.cmake b/cmake/version.cmake index 55bf7fa50499..b44770950f94 100644 --- a/cmake/version.cmake +++ b/cmake/version.cmake @@ -5,7 +5,11 @@ unset(CCF_VERSION) unset(CCF_RELEASE_VERSION) unset(CCF_VERSION_SUFFIX) -option(UNSAFE_VERSION "Produce build with unsafe logging levels" OFF) +option( + UNSAFE_VERSION + "Append unsafe suffix to project and targets. Should be used on platforms where log level is determined at build-time, to distinguish builds which are unsafely verbose." + OFF +) set(CCF_PROJECT "ccf_${COMPILE_TARGET}") if(UNSAFE_VERSION) diff --git a/doc/build_apps/logging.rst b/doc/build_apps/logging.rst index 5bef089e0159..7ef2485d1fc8 100644 --- a/doc/build_apps/logging.rst +++ b/doc/build_apps/logging.rst @@ -28,7 +28,7 @@ These logging functions do several things: - Prefix formatted metadata. The produced log line will include a timestamp, the name and line number where the line was produced, and an ``[app]`` tag - Write without an ECALL. The final write must be handled by the host, so writing directly from the enclave would require an expensive ECALL. Instead these macros will queue writes to a ringbuffer for the host to process, so diagnostic logging should not cause significant performance drops -By default, the ``CCF_APP_TRACE`` and ``CCF_APP_DEBUG`` macros are compiled out, to avoid leaking confidential information during execution. To enable these, define ``VERBOSE_LOGGING`` before including ``logger.h`` in your application code. The unsafe build variants of CCF include verbose logging of the framework itself, but this can be used independently of verbose logging in the application code. +The most-verbose lines which are emitted may be restricted at build-time, if required for security on that platform. On SGX, the ``CCF_APP_TRACE`` and ``CCF_APP_DEBUG`` macros are disabled at compile-time, to avoid leaking confidential information during execution. To enable these, define ``VERBOSE_LOGGING`` before including ``logger.h`` in your application code. The unsafe build variants of CCF include verbose logging of the framework itself, but this can be used independently of verbose logging in the application code. .. note:: The app's logging entries will be interleaved (line-by-line) with the framework's logging messages. Filter for entries containing ``[app]`` to extract only application log lines. diff --git a/doc/contribute/build_ccf.rst b/doc/contribute/build_ccf.rst index 8cacba2a71d4..580e368b7d04 100644 --- a/doc/contribute/build_ccf.rst +++ b/doc/contribute/build_ccf.rst @@ -51,7 +51,6 @@ The most common build switches include: * **BUILD_TESTS**: Boolean. Build all tests for CCF. Default to ON. * **SAN**: Boolean. Build unit tests with Address and Undefined behaviour sanitizers enabled. Default to OFF. * **COMPILE_TARGET**: String. Target compilation platform. Defaults to ``sgx``. Supported values are ``sgx``, ``snp``, or ``virtual``. -* **VERBOSE_LOGGING**: Boolean. Enable all logging levels. Default to OFF. Run Tests --------- diff --git a/doc/host_config_schema/cchost_config.json b/doc/host_config_schema/cchost_config.json index 26bdd6254808..8023769fdc70 100644 --- a/doc/host_config_schema/cchost_config.json +++ b/doc/host_config_schema/cchost_config.json @@ -534,7 +534,7 @@ "type": "string", "enum": ["Trace", "Debug", "Info", "Fail", "Fatal"], "default": "Info", - "description": "Logging level for the untrusted host. Note: while it is possible to set the host log level at startup, it is deliberately not possible to change the log level of the enclave without rebuilding it and changing its code identity" + "description": "Logging level for the untrusted host." }, "format": { "type": "string", diff --git a/edl/ccf.edl b/edl/ccf.edl index 7dae8bc96b94..c1d65e04fac0 100644 --- a/edl/ccf.edl +++ b/edl/ccf.edl @@ -25,6 +25,7 @@ enclave { size_t enclave_version_size, [out] size_t* enclave_version_len, StartType start_type, + LoggerLevel enclave_log_level, size_t num_worker_thread, [user_check] void* time_location, ); diff --git a/include/ccf/ds/logger.h b/include/ccf/ds/logger.h index 5f0bf33574a5..2d1d1ce0d02f 100644 --- a/include/ccf/ds/logger.h +++ b/include/ccf/ds/logger.h @@ -3,6 +3,7 @@ #pragma once #include "ccf/ds/enum_formatter.h" +#include "ccf/ds/logger_level.h" #include "ccf/ds/thread_ids.h" #define FMT_HEADER_ONLY @@ -16,22 +17,18 @@ namespace logger { - enum Level - { - TRACE, - DEBUG, // events useful for debugging - INFO, // important events that should be logged even in release mode - FAIL, // survivable failures that should always be logged - FATAL, // fatal errors that may be non-recoverable - MAX_LOG_LEVEL - }; - - static constexpr Level MOST_VERBOSE = static_cast(0); + static constexpr LoggerLevel MOST_VERBOSE = +#ifdef CCF_DISABLE_VERBOSE_LOGGING + LoggerLevel::INFO +#else + LoggerLevel::TRACE +#endif + ; static constexpr const char* LevelNames[] = { "trace", "debug", "info", "fail", "fatal"}; - static constexpr const char* to_string(Level l) + static constexpr const char* to_string(LoggerLevel l) { return LevelNames[static_cast(l)]; } @@ -48,7 +45,7 @@ namespace logger { public: friend struct Out; - Level log_level; + LoggerLevel log_level; std::string tag; std::string file_name; size_t line_number; @@ -58,7 +55,7 @@ namespace logger std::string msg; LogLine( - Level level_, + LoggerLevel level_, std::string_view tag_, std::string_view file_name_, size_t line_number_, @@ -295,14 +292,14 @@ namespace logger } #endif - static inline Level& level() + static inline LoggerLevel& level() { - static Level the_level = MOST_VERBOSE; + static LoggerLevel the_level = MOST_VERBOSE; return the_level; } - static inline bool ok(Level l) + static inline bool ok(LoggerLevel l) { return l >= level(); } @@ -327,7 +324,7 @@ namespace logger } #ifndef INSIDE_ENCLAVE - if (line.log_level == Level::FATAL) + if (line.log_level == LoggerLevel::FATAL) { throw std::logic_error("Fatal: " + format_to_text(line)); } @@ -358,8 +355,9 @@ namespace logger // This allows: // CCF_LOG_OUT(DEBUG, "foo") << "this " << "msg"; #define CCF_LOG_OUT(LVL, TAG) \ - logger::config::ok(logger::LVL) && \ - logger::Out() == logger::LogLine(logger::LVL, TAG, __FILE__, __LINE__) + logger::config::ok(LoggerLevel::LVL) && \ + logger::Out() == \ + logger::LogLine(LoggerLevel::LVL, TAG, __FILE__, __LINE__) // To avoid repeating the (s, ...) args for every macro, we cheat with a curried // macro here by ending the macro with another macro name, which then accepts @@ -382,7 +380,7 @@ namespace logger # define CCF_LOGGER_DEPRECATE(MACRO) #endif -#ifdef VERBOSE_LOGGING +#ifndef CCF_DISABLE_VERBOSE_LOGGING # define LOG_TRACE_FMT \ CCF_LOGGER_DEPRECATE(LOG_TRACE_FMT) CCF_LOG_FMT(TRACE, "") # define LOG_DEBUG_FMT \ @@ -391,8 +389,8 @@ namespace logger # define CCF_APP_TRACE CCF_LOG_FMT(TRACE, "app") # define CCF_APP_DEBUG CCF_LOG_FMT(DEBUG, "app") #else -// Without compile-time VERBOSE_LOGGING option, these logging macros are -// compile-time nops (and cannot be enabled by accident or malice) +// With verbose logging disabled by compile-time definition, these logging +// macros are compile-time nops (and cannot be enabled by accident or malice) # define LOG_TRACE_FMT(...) CCF_LOGGER_DEPRECATE(LOG_TRACE_FMT)((void)0) # define LOG_DEBUG_FMT(...) CCF_LOGGER_DEPRECATE(LOG_DEBUG_FMT)((void)0) diff --git a/include/ccf/ds/logger_level.h b/include/ccf/ds/logger_level.h new file mode 100644 index 000000000000..2b77d1a8395b --- /dev/null +++ b/include/ccf/ds/logger_level.h @@ -0,0 +1,13 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the Apache 2.0 License. +#pragma once + +enum LoggerLevel +{ + TRACE, + DEBUG, // events useful for debugging + INFO, // important events that should be logged even in release mode + FAIL, // survivable failures that should always be logged + FATAL, // fatal errors that may be non-recoverable + MAX_LOG_LEVEL +}; diff --git a/scripts/scan-build.sh b/scripts/scan-build.sh index b5f6488fa1b6..7444e64d177a 100755 --- a/scripts/scan-build.sh +++ b/scripts/scan-build.sh @@ -9,8 +9,5 @@ export CCC_CXX="clang++-$CLANG_VERSION" SCAN="scan-build-$CLANG_VERSION --exclude 3rdparty --exclude test" -# VERBOSE_LOGGING=ON is important, without it scan-build will report values as unused -# everywhere we compile out the logging statements that would otherwise read them -$SCAN cmake -GNinja -DCOMPILE_TARGET=virtual -DVERBOSE_LOGGING=ON -DCMAKE_BUILD_TYPE=Debug .. # Fails on the current build of clang, because of false positives in doctest, WIP $SCAN ninja || true \ No newline at end of file diff --git a/src/common/configuration.h b/src/common/configuration.h index a4140f699914..c53fd01bd29a 100644 --- a/src/common/configuration.h +++ b/src/common/configuration.h @@ -22,16 +22,13 @@ #include #include -namespace logger -{ - DECLARE_JSON_ENUM( - Level, - {{Level::TRACE, "Trace"}, - {Level::DEBUG, "Debug"}, - {Level::INFO, "Info"}, - {Level::FAIL, "Fail"}, - {Level::FATAL, "Fatal"}}); -} +DECLARE_JSON_ENUM( + LoggerLevel, + {{LoggerLevel::TRACE, "Trace"}, + {LoggerLevel::DEBUG, "Debug"}, + {LoggerLevel::INFO, "Info"}, + {LoggerLevel::FAIL, "Fail"}, + {LoggerLevel::FATAL, "Fatal"}}); DECLARE_JSON_ENUM( StartType, diff --git a/src/common/enclave_interface_types.h b/src/common/enclave_interface_types.h index 3d376f087f47..27cf3fc08bfb 100644 --- a/src/common/enclave_interface_types.h +++ b/src/common/enclave_interface_types.h @@ -2,6 +2,8 @@ // Licensed under the Apache 2.0 License. #pragma once +#include "ccf/ds/logger_level.h" + enum CreateNodeStatus { /** Call was successful and the node was successfully created */ diff --git a/src/consensus/aft/test/driver.cpp b/src/consensus/aft/test/driver.cpp index 2ee47f24a102..6a2542458e67 100644 --- a/src/consensus/aft/test/driver.cpp +++ b/src/consensus/aft/test/driver.cpp @@ -44,7 +44,7 @@ int main(int argc, char** argv) #else logger::config::add_text_console_logger(); #endif - logger::config::level() = logger::DEBUG; + logger::config::level() = LoggerLevel::DEBUG; threading::ThreadMessaging::init(1); diff --git a/src/consensus/aft/test/main.cpp b/src/consensus/aft/test/main.cpp index b55328cdfccc..48ab8335b989 100644 --- a/src/consensus/aft/test/main.cpp +++ b/src/consensus/aft/test/main.cpp @@ -769,7 +769,7 @@ DOCTEST_TEST_CASE("Recv append entries logic" * doctest::test_suite("multiple")) DOCTEST_TEST_CASE("Exceed append entries limit") { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; ccf::NodeId node_id0 = kv::test::PrimaryNodeId; ccf::NodeId node_id1 = kv::test::FirstBackupNodeId; diff --git a/src/ds/test/logger_bench.cpp b/src/ds/test/logger_bench.cpp index 183895ce3d92..6e54b15bdde5 100644 --- a/src/ds/test/logger_bench.cpp +++ b/src/ds/test/logger_bench.cpp @@ -51,7 +51,7 @@ static void log_accepted(picobench::state& s) { prepare_loggers(); - logger::config::level() = logger::DEBUG; + logger::config::level() = LoggerLevel::DEBUG; { picobench::scope scope(s); @@ -69,7 +69,7 @@ static void log_accepted_fmt(picobench::state& s) { prepare_loggers(); - logger::config::level() = logger::DEBUG; + logger::config::level() = LoggerLevel::DEBUG; { picobench::scope scope(s); @@ -87,7 +87,7 @@ static void log_rejected(picobench::state& s) { prepare_loggers(); - logger::config::level() = logger::FAIL; + logger::config::level() = LoggerLevel::FAIL; { picobench::scope scope(s); @@ -105,7 +105,7 @@ static void log_rejected_fmt(picobench::state& s) { prepare_loggers(); - logger::config::level() = logger::FAIL; + logger::config::level() = LoggerLevel::FAIL; { picobench::scope scope(s); diff --git a/src/ds/test/logger_json_test.cpp b/src/ds/test/logger_json_test.cpp index 40613e9a3d0c..7d77149b0767 100644 --- a/src/ds/test/logger_json_test.cpp +++ b/src/ds/test/logger_json_test.cpp @@ -12,7 +12,7 @@ TEST_CASE("Test custom log format") std::string test_log_file = "./test_json_logger.txt"; remove(test_log_file.c_str()); logger::config::add_json_console_logger(); - logger::config::level() = logger::DEBUG; + logger::config::level() = LoggerLevel::DEBUG; std::string log_msg_dbg = "log_msg_dbg"; std::string log_msg_fail = "log_msg_fail"; diff --git a/src/enclave/interface.h b/src/enclave/interface.h index cf6f3e815d0a..096385e96d57 100644 --- a/src/enclave/interface.h +++ b/src/enclave/interface.h @@ -38,7 +38,7 @@ DECLARE_RINGBUFFER_MESSAGE_PAYLOAD( std::chrono::microseconds::rep, std::string, size_t, - logger::Level, + LoggerLevel, std::string, uint16_t, std::string); diff --git a/src/enclave/main.cpp b/src/enclave/main.cpp index e1f9d5c66906..4987c801469b 100644 --- a/src/enclave/main.cpp +++ b/src/enclave/main.cpp @@ -72,6 +72,7 @@ extern "C" size_t enclave_version_size, size_t* enclave_version_len, StartType start_type, + LoggerLevel enclave_log_level, size_t num_worker_threads, void* time_location) { @@ -229,6 +230,25 @@ extern "C" return CreateNodeStatus::ReconfigurationMethodNotSupported; } + // Warn if run-time logging level is unsupported. SGX enclaves have their + // minimum logging level (maximum verbosity) restricted at compile-time, + // while other platforms can permit any level at compile-time and then bind + // the run-time choice in attestations. + const auto mv = logger::MOST_VERBOSE; + const auto requested = enclave_log_level; + const auto permitted = std::max(mv, requested); + if (requested != permitted) + { + LOG_FAIL_FMT( + "Unable to set requested enclave logging level '{}'. Most verbose " + "permitted level is '{}', so setting level to '{}'.", + logger::to_string(requested), + logger::to_string(mv), + logger::to_string(permitted)); + } + + logger::config::level() = permitted; + ccf::Enclave* enclave = nullptr; try diff --git a/src/enclave/virtual_enclave.h b/src/enclave/virtual_enclave.h index 22f72e106b6f..9bafc2b92d15 100644 --- a/src/enclave/virtual_enclave.h +++ b/src/enclave/virtual_enclave.h @@ -115,6 +115,7 @@ extern "C" size_t enclave_version_size, size_t* enclave_version_len, StartType start_type, + LoggerLevel enclave_log_level, size_t num_worker_thread, void* time_location) { @@ -134,6 +135,7 @@ extern "C" size_t, size_t*, StartType, + LoggerLevel, size_t, void*); @@ -157,6 +159,7 @@ extern "C" enclave_version_size, enclave_version_len, start_type, + enclave_log_level, num_worker_thread, time_location); diff --git a/src/host/configuration.h b/src/host/configuration.h index 99c09ed878ca..90d43e7481fb 100644 --- a/src/host/configuration.h +++ b/src/host/configuration.h @@ -111,7 +111,7 @@ namespace host struct Logging { - logger::Level host_level = logger::Level::INFO; + LoggerLevel host_level = LoggerLevel::INFO; LogFormat format = LogFormat::TEXT; bool operator==(const Logging&) const = default; diff --git a/src/host/enclave.h b/src/host/enclave.h index 48f51a55b5d5..6a243c1745af 100644 --- a/src/host/enclave.h +++ b/src/host/enclave.h @@ -128,7 +128,7 @@ namespace host expect_enclave_file_suffix(path, ".enclave.so.signed", type); } -# ifndef VERBOSE_LOGGING +# ifdef CCF_DISABLE_VERBOSE_LOGGING oe_log_set_callback(nullptr, nop_oe_logger); # endif @@ -220,6 +220,7 @@ namespace host std::vector& node_cert, std::vector& service_cert, StartType start_type, + LoggerLevel enclave_log_level, size_t num_worker_thread, void* time_location) { @@ -258,7 +259,8 @@ namespace host snapshot_aligned_size, node_cert.data(), node_cert.size(), &node_cert_len, \ service_cert.data(), service_cert.size(), &service_cert_len, \ enclave_version_buf.data(), enclave_version_buf.size(), \ - &enclave_version_len, start_type, num_worker_thread, time_location + &enclave_version_len, start_type, enclave_log_level, num_worker_thread, \ + time_location oe_result_t err = OE_FAILURE; diff --git a/src/host/main.cpp b/src/host/main.cpp index 2e4d0cb40ed5..04d7104b4f6d 100644 --- a/src/host/main.cpp +++ b/src/host/main.cpp @@ -97,6 +97,21 @@ int main(int argc, char** argv) app.add_flag( "-v, --version", print_version, "Display CCF host version and exit"); + LoggerLevel enclave_log_level = LoggerLevel::INFO; + std::map log_level_options; + for (size_t i = logger::MOST_VERBOSE; i < LoggerLevel::MAX_LOG_LEVEL; ++i) + { + const auto l = (LoggerLevel)i; + log_level_options[logger::to_string(l)] = l; + } + + app + .add_option( + "--enclave-log-level", + enclave_log_level, + "Logging level for the enclave code") + ->transform(CLI::CheckedTransformer(log_level_options, CLI::ignore_case)); + try { app.parse(argc, argv); @@ -634,6 +649,7 @@ int main(int argc, char** argv) node_cert, service_cert, config.command.type, + enclave_log_level, config.worker_threads, time_updater->behaviour.get_value()); ecall_completed.store(true); diff --git a/src/http/test/http_test.cpp b/src/http/test/http_test.cpp index 898567dec327..b3e93f355fb7 100644 --- a/src/http/test/http_test.cpp +++ b/src/http/test/http_test.cpp @@ -277,7 +277,7 @@ DOCTEST_TEST_CASE("URL parsing") DOCTEST_TEST_CASE("Pessimal transport") { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; const http::HeaderMap h1 = {{"foo", "bar"}, {"baz", "42"}}; const http::HeaderMap h2 = { diff --git a/src/kv/test/kv_bench.cpp b/src/kv/test/kv_bench.cpp index c4d1977912c4..992cb10e3aa2 100644 --- a/src/kv/test/kv_bench.cpp +++ b/src/kv/test/kv_bench.cpp @@ -52,7 +52,7 @@ std::string build_map_name(const std::string& core_name, kv::SecurityDomain sd) template static void serialise(picobench::state& s) { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; kv::Store kv_store; auto secrets = create_ledger_secrets(); @@ -84,7 +84,7 @@ static void serialise(picobench::state& s) template static void deserialise(picobench::state& s) { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; kv::Store kv_store; kv::Store kv_store2; @@ -125,7 +125,7 @@ static void deserialise(picobench::state& s) template static void commit_latency(picobench::state& s) { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; kv::Store kv_store; auto secrets = create_ledger_secrets(); @@ -163,7 +163,7 @@ static void commit_latency(picobench::state& s) template static void ser_snap(picobench::state& s) { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; kv::Store kv_store; auto secrets = create_ledger_secrets(); @@ -201,7 +201,7 @@ static void ser_snap(picobench::state& s) template static void des_snap(picobench::state& s) { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; kv::Store kv_store; kv::Store kv_store2; diff --git a/src/kv/test/kv_contention.cpp b/src/kv/test/kv_contention.cpp index 04ab90dd5cc3..167b8c4667ae 100644 --- a/src/kv/test/kv_contention.cpp +++ b/src/kv/test/kv_contention.cpp @@ -35,7 +35,7 @@ class SlowStubConsensus : public kv::test::StubConsensus DOCTEST_TEST_CASE("Concurrent kv access" * doctest::test_suite("concurrency")) { - logger::config::level() = logger::INFO; + logger::config::level() = LoggerLevel::INFO; // Multiple threads write random entries into random tables, and attempt to // commit them. A single thread continually compacts the kv to the latest diff --git a/src/node/rpc/gov_logging.h b/src/node/rpc/gov_logging.h index 3cd8fbe806ca..07448d220a12 100644 --- a/src/node/rpc/gov_logging.h +++ b/src/node/rpc/gov_logging.h @@ -4,7 +4,7 @@ #include "ccf/ds/logger.h" -#ifdef VERBOSE_LOGGING +#ifndef CCF_DISABLE_VERBOSE_LOGGING # define GOV_TRACE_FMT CCF_LOG_FMT(TRACE, "gov") # define GOV_DEBUG_FMT CCF_LOG_FMT(DEBUG, "gov") #else diff --git a/src/node/test/history_bench.cpp b/src/node/test/history_bench.cpp index f01e6e978408..69e4d2ff1736 100644 --- a/src/node/test/history_bench.cpp +++ b/src/node/test/history_bench.cpp @@ -160,7 +160,7 @@ PICOBENCH(append_compact<1000>).iterations(sizes).samples(10); int main(int argc, char* argv[]) { - logger::config::level() = logger::FATAL; + logger::config::level() = LoggerLevel::FATAL; threading::ThreadMessaging::init(1); picobench::runner runner; diff --git a/tests/infra/e2e_args.py b/tests/infra/e2e_args.py index eb004f92cc3e..2616e009ca19 100644 --- a/tests/infra/e2e_args.py +++ b/tests/infra/e2e_args.py @@ -107,11 +107,19 @@ def cli_args(add=lambda x: None, parser=None, accept_unknown=False): default=os.getenv("TEST_ENCLAVE", os.getenv("DEFAULT_ENCLAVE_PLATFORM", "sgx")), choices=("sgx", "snp", "virtual"), ) + log_level_choices = ("trace", "debug", "info", "fail", "fatal") + default_log_level = "info" parser.add_argument( "--host-log-level", help="Runtime host log level", - default="info", - choices=("trace", "debug", "info", "fail", "fatal"), + default=default_log_level, + choices=log_level_choices, + ) + parser.add_argument( + "--enclave-log-level", + help="Runtime enclave log level", + default=default_log_level, + choices=log_level_choices, ) parser.add_argument( "--log-format-json", diff --git a/tests/infra/network.py b/tests/infra/network.py index fc983d89d2e6..75ea88437895 100644 --- a/tests/infra/network.py +++ b/tests/infra/network.py @@ -165,6 +165,7 @@ class Network: "enclave_type", "enclave_platform", "host_log_level", + "enclave_log_level", "sig_tx_interval", "sig_ms_interval", "election_timeout_ms", diff --git a/tests/infra/remote.py b/tests/infra/remote.py index e0bc6772d42b..fa82bb416268 100644 --- a/tests/infra/remote.py +++ b/tests/infra/remote.py @@ -15,6 +15,10 @@ from jinja2 import Environment, FileSystemLoader, select_autoescape import json import infra.snp as snp +import ccf._versionifier +from setuptools.extern.packaging.version import ( # type: ignore + Version, +) from loguru import logger as LOG @@ -591,6 +595,7 @@ def __init__( curve_id=None, version=None, host_log_level="Info", + enclave_log_level="Info", major_version=None, node_address=None, config_file=None, @@ -814,7 +819,22 @@ def __init__( if major_version is None or major_version > 1: # use the relative path to the config file so that it works on remotes too - cmd = [bin_path, "--config", os.path.basename(config_file)] + cmd = [ + bin_path, + "--config", + os.path.basename(config_file), + ] + + v = ( + ccf._versionifier.to_python_version(version) + if version is not None + else None + ) + if v is None or v >= Version("4.0.5"): + cmd += [ + "--enclave-log-level", + enclave_log_level, + ] if start_type == StartType.start: members_info = kwargs.get("members_info")