Skip to content

[fix] Fix to avoid request dropping in the accept queue - #172

Merged
0oshowero0 merged 8 commits into
Ascend:mainfrom
OutstanderWang:fix_no_dropping_in_accept_queue
Sep 11, 2026
Merged

[fix] Fix to avoid request dropping in the accept queue #172
0oshowero0 merged 8 commits into
Ascend:mainfrom
OutstanderWang:fix_no_dropping_in_accept_queue

Conversation

@OutstanderWang

@OutstanderWang OutstanderWang commented Sep 10, 2026

Copy link
Copy Markdown
Contributor

Summary

A storage-unit request can be lost between the manager and the unit without either end raising an error. #171 recovers such a request by retrying it; this PR closes one of the paths it can be lost on, and adds the instrumentation needed to tell the loss apart from a slow unit.

It also corrects two defects in the diagnosis that #171 introduced — both are on main today.

What's here

1. Raise the client-facing ROUTER's accept queue

ZMQ defaults BACKLOG to 100. That was simply the unset default: a full accept queue is drained without an RST (tcp_abort_on_overflow=0), so the client stays in ESTABLISHED waiting for a reply nobody will ever send, and the server never learns the request existed. Neither end raises.

Default is now 4096, tunable via TQ_STORAGE_ZMQ_BACKLOG (set it to 100 to restore ZMQ's default for an A/B run). This only raises a queue ceiling — it cannot reject a connection that previously succeeded.

2. Make the loss measurable rather than inferred

  • Arrival counters (requests_arrived, arrivals_by_op in get_metrics). The per-op counters advance inside monitor.measure(), so they only move once a request completes — a request that arrived and then stalled is indistinguishable from one that never arrived. Counting at decode time separates the two, and a shortfall against the caller's send count localizes the loss to one side of the connection.
  • Accept-queue probe (transfer_queue/utils/accept_probe.py). Samples Recv-Q / sk_drops / ListenOverflows from the kernel's own view. Opt-in and off by default (TQ_ACCEPT_PROBE_INTERVAL=0): it shells out to ss on a timer, and depth must be sampled sub-second because the queue drains in milliseconds — which is why inspecting a unit after it hung always read zero.

3. Report an accept-queue drop once per drop

sk_drops is a cumulative kernel counter, but the initial check compared it against the probe's first sample. Once a socket had ever dropped a connection the condition stayed true for the life of the process — at a 0.1 s interval that is ten errors per second per storage unit. The flood also destroyed the signal: repeating the same cumulative total says nothing about when drops happened. Now compares against the previous sample and reports both deltas.

4. Base the timeout diagnosis on evidence (fixes two defects on main)

_diagnose_storage_unit reported verdict=request_lost_in_flight unconditionally whenever the post-failure probe answered. But a unit that resumed inside the 10 s diagnostic window answers that probe too, having merely finished the original request late — so the verdict asserted where the request was lost on evidence that only shows the unit is serving now. It also printed ops= from op_stats, which _handle_get_metrics populates only when Prometheus is enabled, so the line read ops={} as if the unit had served nothing.

The verdict now follows the unit's own arrival counter for the failed operation:

Probe answered, and… Verdict
no arrival recorded for that op request_lost_in_flight
an arrival recorded for that op arrived_but_unfinished
counters unavailable (e.g. older unit) unit_serving_again

op_stats is now reported as unavailable(prometheus_disabled) rather than as an empty dict.

The counters could not actually be correlated as intended. The worker keyed arrivals_by_op by str(operation), which for a (str, Enum) member renders as "ZMQRequestType.GET_DATA", while op_stats is keyed "GET_DATA" — the two dicts shared no keys at all. Fixed by keying on operation.name. Note .value would also miss: the enum values are short wire tokens (GET_DATA = "GET").

5. Stop the accept probe on shutdown

AcceptQueueProbe.start() was called but stop() had no caller. The finalizer tore down only the ZMQ resources, so a unit finalized without its process exiting left the daemon thread spawning ss on a timer indefinitely, and the window summary was never logged. Now stopped in _shutdown_resources, before the ZMQ teardown.

Behavior and compatibility

  • No public API change. transfer_queue/utils/zmq_utils.py is untouched.
  • One default changes: ROUTER BACKLOG 100 → 4096.
  • The probe is off by default and imported lazily, so a run that does not enable it never loads the module or spawns the thread.
  • Steady-state log volume is unchanged; the near-full-queue warning fires once per probe, not per sample.

New configuration

Variable Default Purpose
TQ_STORAGE_ZMQ_BACKLOG 4096 Accept-queue depth for the client-facing ROUTER
TQ_ACCEPT_PROBE_INTERVAL 0 (off) Accept-queue sampling period, seconds; sub-second when enabled

Note on the rebase

This branch previously carried #171's commits as its base and included a per-call socket-timeout change. Since then #171 merged and #167 replaced per-call sockets with ZMQSocketPool, which resolves timeouts from the pool instead of the decorator. That change therefore had nowhere left to live and has been dropped — main already routes the two timeouts through separate storage_rpc_pool / storage_probe_pool instances, which satisfies the same intent. Its test file went with it; pool timeout behaviour is covered by tests/test_zmq_socket_pool.py::test_timed_out_socket_is_not_reused.

The branch is now four commits on top of ba8880c, all mine.

Testing

  • tests/test_accept_probe.py — utilization and delta arithmetic, peak tracking across a drained burst, drop reported once per drop, each new drop still reported, warn-once behaviour, zero-backlog not dividing by zero, and the probe being stopped on shutdown.
  • tests/test_storage_request_retry.py — the diagnosis table above, plus the empty-op_stats case and the arrival-key spelling.
  • Full suite: 644 passed, 10 skipped, against a 623-passing baseline measured on ba8880c itself — the +21 are the new tests, no regressions.
  • check_license.py, check_docstrings.py, ruff check and ruff format --check all clean.

tests/test_yuanrong_storage_client_e2e.py is excluded from those runs: it errors identically on the unmodified base (optional Yuanrong backend not installed locally).

@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

@chatgpt-codex-connector chatgpt-codex-connector Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 8b15ed12fe

ℹ️ About Codex in GitHub

Codex has been enabled to automatically review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

When you sign up for Codex through ChatGPT, Codex can also answer questions or update the PR, like "@codex address that feedback".

Comment on lines +229 to +231
f"{tcp} verdict=request_lost_in_flight (unit answered a fresh probe: "
f"ops={op_counts} active_keys={body.get('active_keys')} "
f"rss_gb={body.get('process_rss_bytes', 0) / 2**30:.2f})"

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

P1 Badge Do not classify every recovered unit as an in-flight loss

When a unit resumes within the 10-second diagnostic window after several slow requests timed out, a fresh metrics probe can succeed even though the original requests reached the worker and merely completed late. This branch nevertheless unconditionally reports verdict=request_lost_in_flight; moreover, it ignores the newly added requests_arrived and arrivals_by_op fields, and op_stats is empty unless Prometheus was enabled. Correlate arrival/completion state with the failed operation or report only that the unit is serving again rather than asserting where the request was lost.

AGENTS.md reference: AGENTS.md:L5-L9

Useful? React with 👍 / 👎.

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 in 86ed611 — thank you, this was right on both counts.

The probe answering only shows the unit is serving now, so the verdict no longer asserts where the request went unless the unit's own counters support it. _diagnose_storage_unit now takes the failed operation and reads arrivals_by_op:

Probe answered, and… Verdict
no arrival recorded for that op request_lost_in_flight
an arrival recorded for that op arrived_but_unfinished
counters unavailable (e.g. an older unit) unit_serving_again

A unit that resumed inside the diagnostic window therefore reports arrived_but_unfinished rather than blaming the link.

On the op_stats point: it is now reported as completed=unavailable(prometheus_disabled) when empty, instead of printing ops={} as though the unit had served nothing.

One thing your comment led me to that I would not have found otherwise: the two dicts could not actually be correlated at all. The worker keyed arrivals_by_op by str(operation), which for a (str, Enum) member renders as "ZMQRequestType.GET_DATA", while op_stats is keyed "GET_DATA" — they shared no keys. Fixed by keying on operation.name. Worth noting .value would also have missed, since the enum values are short wire tokens (GET_DATA = "GET").

Covered by the parametrised cases in tests/test_storage_request_retry.py::test_diagnosis_classifies_the_failure, plus tests pinning the empty-op_stats wording and the arrival-key spelling.

Comment on lines +265 to +270
self._accept_probe = AcceptQueueProbe(
port=self._put_get_socket_port,
owner_id=str(self.storage_unit_id),
interval_s=TQ_ACCEPT_PROBE_INTERVAL,
)
self._accept_probe.start()

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

P1 Badge Stop the accept probe during unit shutdown

When TQ_ACCEPT_PROBE_INTERVAL enables this path and a storage unit is finalized without terminating its process, nothing calls AcceptQueueProbe.stop()—the finalizer only shuts down the ZMQ resources. The daemon thread retains the probe and continues spawning ss subprocesses indefinitely after the unit is gone, leaking work and also preventing the final statistics from being logged; pass the probe to _shutdown_resources and stop it there.

AGENTS.md reference: AGENTS.md:L17-L18

Useful? React with 👍 / 👎.

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 in 86ed611 — correct, stop() had no caller anywhere in the tree.

_shutdown_resources now takes the probe and stops it before the ZMQ teardown, and self._accept_probe is passed through the weakref.finalize registration alongside the existing thread/context arguments. The probe holds no back-reference to the unit, so this does not keep it alive.

Stopping it there also recovers the window summary: AcceptQueueProbe.stop() logs stats.describe(), which was previously unreachable — describe() had no other caller, so the peak depth and drop deltas a run had accumulated were simply discarded.

tests/test_accept_probe.py covers both that stop() is invoked when _shutdown_resources runs with a probe present, and that the default path (no probe, since TQ_ACCEPT_PROBE_INTERVAL=0) is unaffected.

@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

OutstanderWang added a commit to OutstanderWang/TransferQueue that referenced this pull request Sep 10, 2026
…be on shutdown

Addresses the two P1 comments from the Codex review on Ascend#172.

A successful post-failure probe only shows the unit is serving now, but the
diagnosis reported verdict=request_lost_in_flight unconditionally. A unit that
resumes inside the 10s diagnostic window answers that probe too, having merely
finished the original request late, so the verdict asserted where the request was
lost on evidence that could not support it. It also printed ops= from op_stats,
which _handle_get_metrics only populates when Prometheus is enabled, so the line
read ops={} as if the unit had served nothing.

Decide from the unit's own arrival counter for the failed operation instead: no
arrival means the request never reached the worker, an arrival means it did and
did not finish, and no counter at all now reports only that the unit recovered.
op_stats is reported as unavailable rather than empty when Prometheus is off.

The arrival counters could not actually be correlated as intended. The worker
keyed them by str(operation), which for a (str, Enum) member renders as
"ZMQRequestType.GET_DATA", while op_stats is keyed "GET_DATA", so the two dicts
shared no keys. Key by operation.name: the enum's value is the short wire token
"GET", so .value would not match either.

Separately, nothing ever called AcceptQueueProbe.stop(). The finalizer tore down
only the ZMQ resources, so when a unit was finalized without its process exiting
the daemon thread kept spawning ss on a timer and the window summary was never
logged. Stop it in _shutdown_resources, before the ZMQ teardown.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

OutstanderWang added a commit to OutstanderWang/TransferQueue that referenced this pull request Sep 11, 2026
…be on shutdown

Addresses the two P1 comments from the Codex review on Ascend#172.

A successful post-failure probe only shows the unit is serving now, but the
diagnosis reported verdict=request_lost_in_flight unconditionally. A unit that
resumes inside the 10s diagnostic window answers that probe too, having merely
finished the original request late, so the verdict asserted where the request was
lost on evidence that could not support it. It also printed ops= from op_stats,
which _handle_get_metrics only populates when Prometheus is enabled, so the line
read ops={} as if the unit had served nothing.

Decide from the unit's own arrival counter for the failed operation instead: no
arrival means the request never reached the worker, an arrival means it did and
did not finish, and no counter at all now reports only that the unit recovered.
op_stats is reported as unavailable rather than empty when Prometheus is off.

The arrival counters could not actually be correlated as intended. The worker
keyed them by str(operation), which for a (str, Enum) member renders as
"ZMQRequestType.GET_DATA", while op_stats is keyed "GET_DATA", so the two dicts
shared no keys. Key by operation.name: the enum's value is the short wire token
"GET", so .value would not match either.

Separately, nothing ever called AcceptQueueProbe.stop(). The finalizer tore down
only the ZMQ resources, so when a unit was finalized without its process exiting
the daemon thread kept spawning ss on a timer and the window summary was never
logged. Stop it in _shutdown_resources, before the ZMQ teardown.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@OutstanderWang
OutstanderWang force-pushed the fix_no_dropping_in_accept_queue branch from 6e76543 to ccf8459 Compare September 11, 2026 06:50
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

Builds on the retry in Ascend#171, which established that a request is lost between the
two ends rather than queued behind slow work. Two things that retry does not cover.

Raise the client-facing ROUTER's accept queue from ZMQ's default of 100, which was
just the unset default. A full accept queue is emptied without sending an RST
(tcp_abort_on_overflow=0), leaving the client established and waiting for a reply
nobody will send, while the server never learns the request existed. The observed
hung unit's listen socket had already charged 23 drops, and machine-wide
ListenOverflows equalled ListenDrops, which is the signature of exactly that. It is
a second silent-loss path alongside the unbounded DEALER queue. Tunable via
TQ_STORAGE_ZMQ_BACKLOG; set it to 100 to restore the old value for an A/B run.

Count requests as the worker decodes them, and sample the accept queue when asked.
The per-op counters advance inside monitor.measure(), so they only move once a
request completes and a request that arrived but never finished reads exactly like
one that never arrived; the diagnostic probe cannot tell those apart either. An
arrival count next to the completion histograms does, and a shortfall against the
caller's send count localizes the loss to one side. The queue-depth probe is opt-in
via TQ_ACCEPT_PROBE_INTERVAL and off by default: it shells out to ss on a timer, and
depth has to be sampled sub-second because the queue drains in milliseconds, which
is why inspecting a unit after it hung always read zero.

Tests cover the probe's peak and delta arithmetic and the levels it logs at.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
sk_drops is a cumulative kernel counter, but the check compared it against the
probe's first sample. Once the socket had ever dropped a connection the
condition stayed true for the life of the process: at the 0.1s sampling
interval that is ten errors a second per storage unit, and one long-running
instance had logged over a hundred thousand of them.

The flood also destroyed the signal the probe exists to provide. Repeating the
same cumulative total on every sample says nothing about when the drops
happened, so a handful charged during one resume window is indistinguishable
from an ongoing overflow -- exactly the question the probe was added to answer.

Compare against the previous sample instead, captured before last_sample is
overwritten, and report both deltas so a single line still shows the run total.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
The sanity job runs check_license.py and check_docstrings.py over every source
file. accept_probe.py was added without the Apache header, so the license step
failed and the job stopped before reaching the docstring step, which was hiding
five undocumented public members behind the first error.

Comments and docstrings only; no behavior change.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
…be on shutdown

Addresses the two P1 comments from the Codex review on Ascend#172.

A successful post-failure probe only shows the unit is serving now, but the
diagnosis reported verdict=request_lost_in_flight unconditionally. A unit that
resumes inside the 10s diagnostic window answers that probe too, having merely
finished the original request late, so the verdict asserted where the request was
lost on evidence that could not support it. It also printed ops= from op_stats,
which _handle_get_metrics only populates when Prometheus is enabled, so the line
read ops={} as if the unit had served nothing.

Decide from the unit's own arrival counter for the failed operation instead: no
arrival means the request never reached the worker, an arrival means it did and
did not finish, and no counter at all now reports only that the unit recovered.
op_stats is reported as unavailable rather than empty when Prometheus is off.

The arrival counters could not actually be correlated as intended. The worker
keyed them by str(operation), which for a (str, Enum) member renders as
"ZMQRequestType.GET_DATA", while op_stats is keyed "GET_DATA", so the two dicts
shared no keys. Key by operation.name: the enum's value is the short wire token
"GET", so .value would not match either.

Separately, nothing ever called AcceptQueueProbe.stop(). The finalizer tore down
only the ZMQ resources, so when a unit was finalized without its process exiting
the daemon thread kept spawning ss on a timer and the window summary was never
logged. Stop it in _shutdown_resources, before the ZMQ teardown.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

Comment on lines +294 to +297
return f"{tcp} {self._verdict_from_counters(body, operation)} {_describe_unit_state(body)}"

@staticmethod
def _verdict_from_counters(body: dict[str, Any], operation: str) -> str:

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

We better merge these two functions, merge the core logic of _verdict_from_counters into _describe_unit_state

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.

Done in 9d1ef6a_verdict_from_counters is folded into _describe_unit_state, which now builds the verdict and the state it was drawn from in one pass and returns the whole line. _diagnose_storage_unit just calls it.

Comment on lines +180 to +182
# Requests counted the moment the worker decodes one, independent of whether it completes.
# Class-level defaults so a unit built without __init__ (tests drive the worker loop
# directly) still counts instead of raising. See the increment site for why they exist.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

We can remove these comments

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.

Removed in 9d1ef6a.

Comment on lines +244 to +246
# An overflowing accept queue is drained silently (tcp_abort_on_overflow=0), so it
# surfaces only as a client stuck in ESTABLISHED waiting for a reply that never
# comes. Env-tunable so an A/B run can restore ZMQ's default of 100.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

We can remove these comments

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.

Removed in 9d1ef6a.

Comment on lines +389 to +394
# Counted on arrival, unlike op_stats which only advances on completion, so a
# gap between the two isolates requests that arrived and never finished.
self._requests_arrived += 1
# Keyed by name, not str() or value: str() renders as
# "ZMQRequestType.GET_DATA" and the value is the short wire token "GET",
# while op_stats below is keyed "GET_DATA". Only name lets the two join.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

We can remove these comments

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.

Removed in 9d1ef6a. The name-vs-value subtlety it described is kept as an executable check: test_arrival_key_for_get_is_the_enum_name_not_its_wire_value.

_ARRIVAL_KEY_BY_OPERATION = {"get": "GET_DATA", "put": "PUT_DATA", "clear": "CLEAR_DATA"}


def _describe_unit_state(body: dict[str, Any]) -> str:

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

The returned network probs are not formatted by the function so Prometheus & Grafana might not see the results.

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.

Good catch — the probe data only ever reached log strings, so nothing could chart or alert on it. Wired through the controller's exporter in da8acd0:

Metric Labels
tq_storage_requests_arrived storage_unit_id
tq_storage_arrivals_by_op storage_unit_id, op_type
tq_storage_accept_queue_backlog / _peak / _peak_utilization_ratio storage_unit_id
tq_storage_socket_drops storage_unit_id
tq_storage_listen_overflows / tq_storage_listen_other_drops storage_unit_id

arrivals_by_op is labelled by op_type deliberately, so it can be read directly against the existing tq_storage_request_ops: arrivals count decode, request_ops counts completion, so a gap between the two rates is requests arriving and not finishing.

Three details worth flagging:

  • Names omit _total. docs/metrics.md records that ZMQ-collected gauges avoid Prometheus reserved suffixes because they break label_values(). I had used _total at first and corrected it.
  • Accept-queue series are removed, not zeroed, when the probe is off (TQ_ACCEPT_PROBE_INTERVAL=0, the default), following the existing capacity is None pruning. Reporting 0 drops would be indistinguishable from a measured absence of drops.
  • Overflow and non-overflow drops are separate series. That split is the actionable part: a non-zero tq_storage_listen_other_drops means raising the backlog would not have prevented every drop.

Also added a Grafana row with four panels (arrived vs completed, peak vs backlog, socket drops, overflow vs other) and documented the metrics, the two env vars, and the cumulative-since-probe-start semantics that make rate() the right operator. 652 passed / 10 skipped, up from 649.

Review feedback: fold _verdict_from_counters into _describe_unit_state so the
verdict and the state it was drawn from are built in one pass, and drop comments
that restated what the code already says. The arrival-key spelling that a comment
explained is pinned by test_arrival_key_for_get_is_the_enum_name_not_its_wire_value.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

"""


# Maps the operation name used by the retry path to the storage unit's arrival counter key.

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

remove these comments

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.

Removed in da8acd0. Also trimmed the stale comment in _handle_get_metrics that still described the arrival/completion inference deleted in 993d6f9.

…ablish

Two review findings, both about inference rather than measurement.

The timeout diagnosis read the unit's arrival counter for the failed operation and
reported arrived_but_unfinished when it was nonzero, request_lost_in_flight when it
was zero. Neither follows. The counters are per operation and cumulative, carry no
request id and never decrease, so a nonzero count may be entirely historical: a unit
that had served nine GETs and never saw the tenth still reports nine. The zero case
is no better, because the counters restart with the process, so a unit that restarted
inside the timeout window reports zero for a request that did reach its predecessor.
A probe answering proves only that the unit is serving again, so that is all the
verdict now says; the counters stay in the line as triage input. This also removes
the operation argument and the key map that existed only to support the inference.

The accept-queue probe alerted "accept queue dropped a connection" and advised raising
ZMQ_BACKLOG whenever a listening socket's sk_drops rose. The kernel charges sk_drops
on many establishment failures that are not overflow -- failing to allocate the child
socket under memory pressure, failing to route it, failing to inherit the port -- all
of which reach tcp_listendrop() without touching ListenOverflows (Linux v6.6,
net/ipv4/tcp_ipv4.c exit_overflow/exit_nonewsk/exit). So sk_drops locates the socket,
not the cause. The alert now reports the drop, prints the overflow and non-overflow
deltas beside it, and offers the backlog only as the fix for one candidate.

ListenDrops minus ListenOverflows is the discriminator that was missing, so it is now
computed and exposed in get_metrics: positive means a bigger backlog could not have
prevented every drop in the window.

Also corrects the docstrings. ListenOverflows and ListenDrops are per network
namespace rather than machine-wide, ListenDrops is not a queue-full counter, and
tcp_abort_on_overflow=0 does not strand the connection: it withholds the RST, and the
server's SYN-ACK retransmits let the connection complete if the queue drains within
tcp_synack_retries.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

@OutstanderWang

Copy link
Copy Markdown
Contributor Author

Both points were right, and I have narrowed the diagnostics accordingly in 993d6f9.

1. Cumulative counters cannot locate one request. They are per-operation, carry no request id, never decrease, and reset with the process — so neither direction of inference holds. A nonzero count may be entirely historical (nine completed GETs say nothing about the tenth), and the zero case is no better than I claimed either: a unit that restarted inside the timeout window reports zero for a request that did reach its predecessor, so request_lost_in_flight was unsound too. A successful probe now reports only verdict=unit_serving_again, with the counters retained in the line as triage input. _ARRIVAL_KEY_BY_OPERATION and the operation parameter are gone.

The old test did exactly what you said — asserted the branch, not the semantics. It is replaced by a parametrised regression test over your two timings plus the restart case, asserting the log never claims arrival or non-arrival.

2. sk_drops does not imply overflow. Confirmed against Linux v6.6: tcp_listendrop() (include/net/tcp.h) increments sk_drops and LINUX_MIB_LISTENDROPS only, and in tcp_v4_syn_recv_sock() the exit_overflowexit_nonewskexit fall-through means every failure reaches it while only exit_overflow bumps LISTENOVERFLOWS. Your example understates it slightly — besides the tcp_create_openreq_child() NULL path there are also inet_csk_route_child_sock(), tcp_md5_key_copy() and __inet_inherit_port() failures, plus several in tcp_conn_request().

The alert now reports that the listening socket dropped an incoming connection, prints the overflow and non-overflow deltas beside it, and offers the backlog as the fix for one candidate rather than the diagnosis.

That also gave a discriminator worth keeping: ListenDrops - ListenOverflows > 0 proves at least one drop in the window was not an overflow. It is now computed as non_overflow_drop_delta and exposed in get_metrics.

3. Docstring corrections. ListenOverflows / ListenDrops are per network namespace, not machine-wide; ListenDrops is not a queue-full counter; and tcp_abort_on_overflow=0 does not strand the connection. One refinement on the last point: recovery is driven by the server's SYN-ACK retransmit timer rather than the client, bounded by tcp_synack_retries (default 5, ~63 s), so the docstring says that rather than "the client retransmits".

Retry policy, timeout propagation and the data path are unchanged. 649 passed / 10 skipped, up from 644 — the five new tests are the two counter-example timings, the restart case, and the overflow/non-overflow split.

The arrival counters and accept-queue probe only reached log strings, so nothing
could chart them or alert on them. Export both through the controller's exporter,
which already collects storage-unit metrics over ZMQ.

Arrivals become tq_storage_requests_arrived and tq_storage_arrivals_by_op, the
latter labelled by op_type like the existing tq_storage_request_ops it is meant to
be read against: arrivals count decode, request_ops counts completion, so a gap
between the two rates is requests arriving and not finishing.

The accept-queue series carry the probe's backlog, peak depth, peak utilization and
drop deltas. They are removed rather than set to zero when the probe is disabled,
following the capacity-is-None precedent, because a zero drop count would otherwise
be indistinguishable from a measured absence of drops.

Overflow and non-overflow drops are exported separately. The kernel charges a
listening socket's sk_drops on several establishment failures, so the split is what
tells a dashboard whether raising the backlog would have helped.

Names omit the _total suffix per the rule in docs/metrics.md: these are Gauges fed
from a remote body, and the reserved suffix breaks label_values() queries.

Adds a Grafana row with those four views, and documents the metrics, the two
environment variables that drive them, and the cumulative-since-probe-start
semantics that make rate() the right operator.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

Compress the prose the diagnostics accumulated across review rounds. The
accept_probe module docstring had grown to 28 lines recounting one incident and
restating each kernel counter; it keeps only the two caveats a caller needs to read
the numbers correctly and points at docs/metrics.md for the rest. Several comments
that restated their code are gone, and the invariant docstrings on the diagnosis
path are shortened rather than dropped, since they are what stops the overclaiming
verdict coming back.

Also drops AcceptQueueStats.peak_history, which was appended to on every new peak
and never read.

No behavior change.

Signed-off-by: OutstanderWang <wangweiyanster@gmail.com>
@ascend-robot

Copy link
Copy Markdown

CLA Signature Pass

OutstanderWang, thanks for your pull request. All authors of the commits have signed the CLA. 👍

@0oshowero0
0oshowero0 merged commit fc33c97 into Ascend:main Sep 11, 2026
8 checks passed
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.

3 participants