From d297aeca2c375d202102b2d812e9f85de0eccb99 Mon Sep 17 00:00:00 2001 From: Bernardo Meurer Costa Date: Thu, 22 Jan 2026 21:01:24 +0000 Subject: [PATCH] feat(libstore/aws-creds): route AWS CRT logs through Nix logger Previously AWS CRT logs went directly to stderr via ApiHandle::InitializeLogging, causing log spam that didn't respect Nix's verbosity settings. This implements a custom aws_logger using the aws-c-common C API that: - Routes all AWS logs through nix::logger - Maps AWS log levels conservatively (ERROR/WARN -> lvlInfo) since the SDK treats expected conditions like missing IMDS as errors - Prefixes messages with (aws) for clarity - Respects Nix's verbosity flags (-v, -vv, etc.) (cherry picked from commit 3b8b764e29475d9677471fcf52c1eb2e09eaf723) --- src/libstore/aws-creds.cc | 115 +++++++++++++++++++++++--- tests/nixos/s3-binary-cache-store.nix | 42 ++++++++++ 2 files changed, 145 insertions(+), 12 deletions(-) diff --git a/src/libstore/aws-creds.cc b/src/libstore/aws-creds.cc index 1ea37b129..9b0ddefdc 100644 --- a/src/libstore/aws-creds.cc +++ b/src/libstore/aws-creds.cc @@ -13,6 +13,11 @@ // C library headers for SSO provider support # include +// C library headers for custom logging +# include + +# include + # include # include @@ -30,6 +35,101 @@ AwsAuthError::AwsAuthError(int errorCode) namespace { +/** + * Map AWS log level to Nix verbosity. + * AWS levels: AWS_LL_NONE=0, AWS_LL_FATAL=1, AWS_LL_ERROR=2, AWS_LL_WARN=3, + * AWS_LL_INFO=4, AWS_LL_DEBUG=5, AWS_LL_TRACE=6 + * + * We map very conservatively because the AWS SDK is extremely noisy. What AWS + * considers "info" includes low-level details like "Initializing epoll" and + * "Starting event-loop thread". What it considers "errors" includes expected + * conditions like missing ~/.aws/config or IMDS being unavailable on non-EC2. + * + * To avoid spamming users, we only show FATAL at default verbosity. Everything + * else requires -vvvvv (lvlDebug) or higher to see. + */ +static Verbosity awsLogLevelToVerbosity(enum aws_log_level level) +{ + switch (level) { + case AWS_LL_FATAL: + return lvlError; + case AWS_LL_ERROR: + case AWS_LL_WARN: + case AWS_LL_INFO: + return lvlDebug; + case AWS_LL_DEBUG: + case AWS_LL_TRACE: + return lvlVomit; + // AWS_LL_NONE and AWS_LL_COUNT are enum sentinels, not real log levels + case AWS_LL_NONE: + case AWS_LL_COUNT: + return lvlDebug; + } + unreachable(); +} + +/** + * Custom AWS logger that routes logs through Nix's logging infrastructure. + * + * The AWS CRT C++ wrapper (ApiHandle::InitializeLogging) only supports FILE* + * or filename-based logging. The underlying C library supports custom loggers + * via aws_logger struct with a vtable containing callback functions. + */ +static int nixAwsLoggerLog( + struct aws_logger * logger, enum aws_log_level logLevel, aws_log_subject_t subject, const char * format, ...) +{ + Verbosity nixLevel = awsLogLevelToVerbosity(logLevel); + if (nixLevel > verbosity) + return AWS_OP_SUCCESS; /* Bail out early to avoid formatting the message unnecessarily. */ + + va_list args; + va_start(args, format); + std::array buffer{}; + auto res = vsnprintf(buffer.data(), buffer.size(), format, args); + va_end(args); + if (res < 0) /* Skip garbage debug messages in case the SDK is busted. */ + return AWS_OP_SUCCESS; + + const char * subjectName = aws_log_subject_name(subject); + printMsgUsing(nix::logger, nixLevel, "(aws:%s) %s", subjectName ? subjectName : "unknown", chomp(buffer.data())); + return AWS_OP_SUCCESS; +} + +/** + * Get current log level for a subject - determines which messages will be logged. + * Must be consistent with awsLogLevelToVerbosity mapping. + */ +static aws_log_level nixAwsLoggerGetLevel(struct aws_logger * logger, aws_log_subject_t subject) +{ + // Map Nix verbosity back to AWS log level (inverse of awsLogLevelToVerbosity) + if (verbosity >= lvlVomit) + return AWS_LL_TRACE; + if (verbosity >= lvlDebug) + return AWS_LL_INFO; // error/warn/info are all mapped to lvlDebug + return AWS_LL_FATAL; +} + +static void initialiseAwsLogger() +{ + static std::once_flag initialised; /* aws_logger_set must only be called once */ + std::call_once(initialised, []() { + static aws_logger_vtable nixAwsLoggerVtable = { + .log = nixAwsLoggerLog, + .get_log_level = nixAwsLoggerGetLevel, + .clean_up = [](struct aws_logger *) {}, // No resources to clean up + .set_log_level = nullptr, + }; + + static aws_logger nixAwsLogger = { + .vtable = &nixAwsLoggerVtable, + .allocator = nullptr, + .p_impl = nullptr, + }; + + aws_logger_set(&nixAwsLogger); + }); +} + /** * Helper function to wrap a C credentials provider in the C++ interface. * This replicates the static s_CreateWrappedProvider from aws-crt-cpp. @@ -119,18 +219,9 @@ class AwsCredentialProviderImpl : public AwsCredentialProvider public: AwsCredentialProviderImpl() { - // Map Nix's verbosity to AWS CRT log level - Aws::Crt::LogLevel logLevel; - if (verbosity >= lvlVomit) { - logLevel = Aws::Crt::LogLevel::Trace; - } else if (verbosity >= lvlDebug) { - logLevel = Aws::Crt::LogLevel::Debug; - } else if (verbosity >= lvlChatty) { - logLevel = Aws::Crt::LogLevel::Info; - } else { - logLevel = Aws::Crt::LogLevel::Warn; - } - apiHandle.InitializeLogging(logLevel, stderr); + // Install custom logger that routes AWS CRT logs through Nix's logging infrastructure. + // This ensures AWS logs respect Nix's verbosity settings and are formatted consistently. + initialiseAwsLogger(); // Create a shared TLS context for SSO (required for HTTPS connections) auto allocator = Aws::Crt::ApiAllocator(); diff --git a/tests/nixos/s3-binary-cache-store.nix b/tests/nixos/s3-binary-cache-store.nix index 154c1fb1b..65a41fc82 100644 --- a/tests/nixos/s3-binary-cache-store.nix +++ b/tests/nixos/s3-binary-cache-store.nix @@ -229,6 +229,47 @@ in print("✓ Credential provider created once and cached") + @setup_s3() + def test_aws_log_integration(bucket): + """Test that AWS SDK logs are properly routed through Nix logger""" + print("\n=== Testing AWS Log Integration ===") + + store_url = make_s3_url(bucket) + + # With default verbosity, AWS noise should NOT appear + # All AWS messages are demoted to lvlDebug or lvlVomit + output_default = server.succeed( + f"{ENV_WITH_CREDS} nix copy --to '{store_url}' {PKGS['A']} 2>&1" + ) + + if "(aws:" in output_default: + print("Output at default verbosity:") + print(output_default) + raise Exception("Found AWS noise at default verbosity") + + print(" ✓ Default verbosity filters AWS noise") + + # With --debug (lvlDebug), we should see AWS messages with (aws:subject) prefix + output_debug = server.succeed( + f"{ENV_WITH_CREDS} nix copy --debug --to '{store_url}' {PKGS['B']} 2>&1" + ) + + # Check for the (aws:subject) prefix format + if "(aws:" not in output_debug: + print("Output at --debug verbosity:") + print(output_debug) + raise Exception("Expected to see (aws:subject) prefix in debug output") + + print(" ✓ Debug output shows AWS messages with (aws:subject) prefix") + + # Should also see Nix's own credential provider creation message + if "creating new AWS credential provider" not in output_debug: + print("Debug output:") + print(output_debug) + raise Exception("Expected to see credential provider creation at debug level") + + print(" ✓ Debug verbosity shows credential provider messages") + @setup_s3(populate_bucket=[PKGS['A']]) def test_fetchurl_basic(bucket): """Test builtins.fetchurl works with s3:// URLs""" @@ -909,6 +950,7 @@ in # Run tests (each gets isolated bucket via decorator) test_credential_caching() + test_aws_log_integration() test_fetchurl_basic() test_error_message_formatting() test_fork_credential_preresolution()