Skip to content

Do not warn on benign double completion of backup-aware invocations [HZ-5459]#1475

Merged
ihsandemir merged 3 commits into
hazelcast:masterfrom
ihsandemir:fix/spurious-failed-to-set-response-warning
Jun 4, 2026
Merged

Do not warn on benign double completion of backup-aware invocations [HZ-5459]#1475
ihsandemir merged 3 commits into
hazelcast:masterfrom
ihsandemir:fix/spurious-failed-to-set-response-warning

Conversation

@ihsandemir

Copy link
Copy Markdown
Contributor

Fixes #1474

Problem

Since 5.7.0 a healthy C++ client connected to a multi-member cluster continuously emits WARNING lines like:

Failed to set the response for invocation. Dropping the response. The state of the promise has already been set., ClientInvocation{ ... operation=map.put ... backup_acks_expected_ = 1, backup_acks_received = 1, ... }

A 10-client soak run produced 47,664 of these, all for backup-aware operations with backup_acks_expected == backup_acks_received, with no actual failures.

Root cause

For a backup-aware operation the invocation completes once the primary response and the backup ack(s) have arrived. Both notify_response() and notify_backup() can win the final completion, and there is an inherent race in which both reach complete() with the same pending response:

  1. notify_response stages pending_response_
  2. notify_backup (other thread) increments the ack count and completes the promise
  3. notify_response's recheck now sees received == expected, falls through and calls complete() again → boost::promise_already_satisfied

The future is completed exactly once with the correct value; the duplicate is harmlessly dropped. Only the log line is wrong. The race became routine after the multi-threaded pipeline work (#1412), which made the response and the backup ack run on different threads.

This mirrors the Java client (BaseInvocation.notifyResponse has the same double-check). The difference is reporting: Java's AbstractInvocationFuture.warnIfSuspiciousDoubleCompletion only warns when the already-set value differs from the offered one, so the same-value backup-ack race is silent. The C++ complete() warned on every promise_already_satisfied.

Fix

complete() now mirrors Java: a duplicate completion with the same response (the benign backup-ack race) is logged at finest, while a genuinely conflicting value still warns. This also aligns the value path with how set_exception() already handles the same condition.

Tests

Added client_invocation_test with two cases driving the private completion path via friend access:

  • benign double completion with the same response → no WARNING, one finest
  • conflicting double completion with a different response → one WARNING

Verified red/green: the benign test fails before the fix (logs at WARNING) and passes after. Both tests pass against a running cluster.

@ihsandemir ihsandemir changed the title Do not warn on benign double completion of backup-aware invocations Do not warn on benign double completion of backup-aware invocations [HZ-5459] Jun 4, 2026
@ihsandemir ihsandemir self-assigned this Jun 4, 2026
@ihsandemir ihsandemir added this to the 5.7.0 milestone Jun 4, 2026
dmitriyrazboev
dmitriyrazboev previously approved these changes Jun 4, 2026
class address;

namespace test {
// White-box test fixture; granted access to private completion internals to

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use "exposed for testing" or some other terminology in use elsewhere in the codebase?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

fixed at 88e26cb

@@ -0,0 +1,185 @@
/*
* Copyright (c) 2008-2025, Hazelcast, Inc. All Rights Reserved.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
* Copyright (c) 2008-2025, Hazelcast, Inc. All Rights Reserved.
* Copyright (c) 2008-2026, Hazelcast, Inc. All Rights Reserved.

Not sure how were managing this.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

moved this file content into existing HazelcastTests5.cpp file.

@ihsandemir
ihsandemir force-pushed the fix/spurious-failed-to-set-response-warning branch 2 times, most recently from 7bf3fe5 to 71c9163 Compare June 4, 2026 08:34
For a backup-aware operation the primary response (notify_response) and the
last backup ack (notify_backup) can race to complete the invocation. Both
paths complete with the same pending response, so the loser of the race hits
boost::promise_already_satisfied. The future is still completed exactly once
with the correct value and the duplicate is harmlessly dropped, but complete()
logged every occurrence at WARNING, flooding the logs of healthy clients under
load. The race became routinely observable after the multi-threaded pipeline
work, which made the response and the backup ack run on different threads.

Mirror the Java client's AbstractInvocationFuture.warnIfSuspiciousDouble-
Completion: only warn when the offered response differs from the canonical
pending_response_. A duplicate completion with the same response is logged at
finest, while a genuinely conflicting value still warns. This also matches how
set_exception() already treats promise_already_satisfied.

Add regression tests that drive the private completion path via friend access
to assert the benign duplicate is not a warning and a conflicting one still is.

Fixes hazelcast#1474
@ihsandemir
ihsandemir force-pushed the fix/spurious-failed-to-set-response-warning branch from 71c9163 to 56204de Compare June 4, 2026 08:34
@ihsandemir
ihsandemir merged commit 551dd2c into hazelcast:master Jun 4, 2026
31 checks passed
@ihsandemir
ihsandemir deleted the fix/spurious-failed-to-set-response-warning branch June 4, 2026 13:03
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Spurious "Failed to set the response for invocation" WARNING logs for backup-aware operations (5.7.0) [HZ-5459]

3 participants