From 6a1085ed4e7c80709d65217e20a7a7027953a6f5 Mon Sep 17 00:00:00 2001 From: Mikhail Filimonov Date: Sat, 17 Oct 2026 12:07:11 +0200 Subject: [PATCH] Log the first failed CAS blob publication attempt below Warning A lone failed attempt (for example a refused connection) is retried and usually succeeds, but the per-attempt warning reached clients with send_logs_level=warning and failed stateless tests on stderr. Attempt 1 now logs at Information; attempt 2 and later stay at Warning. CASBlobPublishAttemptFailed and CASBlobPublishGaveUp are unchanged. Related: https://github.com/Altinity/ClickHouse/pull/2555 Signed-off-by: Mikhail Filimonov Co-Authored-By: Claude Opus 5.5 --- .../ContentAddressed/Pool/CasPartWriteTxn.cpp | 9 ++++-- .../gtest_cas_blob_publish_transport.cpp | 31 +++++++++++++++++++ 2 files changed, 37 insertions(+), 3 deletions(-) diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPartWriteTxn.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPartWriteTxn.cpp index 4feb497cac86a..62337837debef 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPartWriteTxn.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPartWriteTxn.cpp @@ -78,14 +78,17 @@ uint64_t nowMs() } /// Rate-limited, because under an outage every blob of every write fails here; the counter has them all. +/// The first failure is routine and the next attempt usually succeeds, so only a repeat is a warning. void recordFailedPublicationAttempt( const String & key, BlobPublicationTransport transport, int attempt, int max_attempts, const String & error) { ProfileEvents::increment(ProfileEvents::CASBlobPublishAttemptFailed); LogSeriesLimiter log(getLogger("CasBlobPublishAttempt"), /*allowed_count=*/5, /*interval_s=*/30); - LOG_WARNING(log, "Publication of CAS blob {} ({}) failed, attempt {} of {}: {}", - key, transport == BlobPublicationTransport::Streaming ? "streaming" : "server-side copy", - attempt + 1, max_attempts, error); + const char * transport_name = transport == BlobPublicationTransport::Streaming ? "streaming" : "server-side copy"; + if (attempt == 0) + LOG_INFO(log, "Publication of CAS blob {} ({}) failed, attempt {} of {}: {}", key, transport_name, attempt + 1, max_attempts, error); + else + LOG_WARNING(log, "Publication of CAS blob {} ({}) failed, attempt {} of {}: {}", key, transport_name, attempt + 1, max_attempts, error); } bool isDeterministicBlobPublicationFailure(const std::exception & error) diff --git a/src/Disks/tests/gtest_cas_blob_publish_transport.cpp b/src/Disks/tests/gtest_cas_blob_publish_transport.cpp index b09661ce4d6dd..e769ef5d3036e 100644 --- a/src/Disks/tests/gtest_cas_blob_publish_transport.cpp +++ b/src/Disks/tests/gtest_cas_blob_publish_transport.cpp @@ -188,6 +188,16 @@ CountingS3::ObjectStore::FaultFn dropFirst(Verb verb) }; } +CountingS3::ObjectStore::FaultFn dropFirstTwo(Verb verb) +{ + return [verb](const CountingS3::Request & request, Poco::Net::HTTPServerResponse &) + { + if (request.verb == verb && request.nth <= 2) + throw CountingS3::DropResponse(); + return false; + }; +} + uint64_t failedPublicationAttempts() { return ProfileEvents::global_counters[ProfileEvents::CASBlobPublishAttemptFailed].load(); @@ -224,6 +234,27 @@ TEST(CASBlobPublishTransport, LostPutIsRepublishedWithAFreshEnvelope) EXPECT_EQ(failedPublicationAttempts() - failed_before, 1u); } +/// A single lost attempt is routine and the next one usually succeeds, so only a repeated failure is +/// worth a client-visible warning. +TEST(CASBlobPublishTransport, FirstFailedAttemptIsBelowWarning) +{ + (void)getContext(); + CountingS3::ObjectStore store(dropFirstTwo(Verb::PutObject)); + CountingS3Server server(store.responder()); + auto pool = openPool(server.getUrl()); + const std::string payload = "two-lost-puts-payload"; + auto build = startBuild(pool, payload); + DB::Cas::tests::ScopedLogCapture capture("CasBlobPublishAttempt", "warning"); + + DB::Cas::BlobSource source; + source.size = payload.size(); + source.open = [payload] { return std::make_unique(payload); }; + build->putBlob(DB::Cas::tests::idOf(payload), std::move(source)); + + EXPECT_EQ(capture.count("failed, attempt 1 of"), 0u) << capture.captured(); + EXPECT_EQ(capture.count("failed, attempt 2 of"), 1u) << capture.captured(); +} + /// A lost staged `CopyObject` is not resent: the staged copy is spent, so the retry streams. TEST(CASBlobPublishTransport, LostStagedCopyIsRepublishedByStreaming) {