Skip to content

Fix ping-pong send ConnectionResetError noise at ERROR level (OPS-3616)#68

Open
palantir-valiot[bot] wants to merge 2 commits into
mainfrom
palantir/OPS-3616-fix-ping-pong-connectionreset-log
Open

Fix ping-pong send ConnectionResetError noise at ERROR level (OPS-3616)#68
palantir-valiot[bot] wants to merge 2 commits into
mainfrom
palantir/OPS-3616-fix-ping-pong-connectionreset-log

Conversation

@palantir-valiot

Copy link
Copy Markdown
Contributor

Description

Handle transient connection errors (ConnectionResetError etc.) from self._conn.send(PING_JSON) inside the _ping_pong keep-alive thread the same way the _sub_routing_loop recv side already does (since OPS-3485). This eliminates the ERROR + full traceback noise that was surfacing as "unhandled ConnectionResetError" in valiotlogging for expected peer resets / broken pipes during WSS churn. Functional recovery (set wss_conn_halted, router reconnects) was already present but the log level was wrong, producing the stacktrace in the reported incident.

Summary of changes

  • pygqlc/GraphQLClient.py (in _ping_pong): the bare except Exception as e: ... always log(ERROR, "error trying to send ping, WSS Pipe is broken") now does if isinstance(e, TRANSIENT_WS_ERRORS): log(WARNING, "WSS connection reset or closed by peer") else: ERROR. Mirrors the exact pattern + constant used at recv time (lines ~543-549). Behavior for real fatal errors unchanged.

  • tests/pygqlc/gql_client/test_subscribe.py: added _run_ping_pong helper + two hermetic regression tests test_ping_pong_connection_reset_logged_as_warning and test_ping_pong_unexpected_error_logged_as_error (TDD: first written, went red for the right reason — always ERROR; now green). Use the exact same MagicMock + patch("time.sleep") + _capture_logs + closing-via-side-effect pattern as the prior recv tests; no sleeps, no sockets, fast.

  • Version bump 3.8.0 → 3.8.1 (patch), top CHANGELOG.md entry following the house style, uv lock --upgrade (idna + snowballstemmer transitive within ranges).

This directly addresses the stacktrace from femsa-worker-workflows (Thread-3 (_ping_pong)) and the triage "missing connection-error handling".

Type of change

  • Bug fix (non-breaking change which fixes an issue)

How Has This Been Tested?

TDD per AGENTS.md: wrote the two failing tests first (got red because the send path always emitted ERROR for ConnectionResetError, causing the observed log+traceback), made them green by the classification change, then ran format/bandit/pytest/lock as required.

  • uv run pytest tests/pygqlc/gql_client/test_subscribe.py -k "test_ping_pong or test_sub_routing_loop_non_dict or test_sub_routing_loop_connection_reset or test_sub_routing_loop_unexpected or test_sub_routing_loop_valid" → 6 passed (the new + prior routing ones)
  • Full hermetic suite (excluding env-gated integration): 24 passed
  • uvx ruff format --check → clean (applied uvx ruff format after edit)
  • uvx bandit -r . -s B101 -ll --exclude $(find . -type d -name '.venv' | paste -sd, -) → "No issues identified"
  • uv lock --upgrade (committed the 2 transitive bumps)
  • git diff origin/main..HEAD reviewed before commit (only expected files; no debug prints, no unrelated changes, no secrets)
  • All commands run in the agent pod using pinned toolchain (Python 3.13 via mise, uv, etc.)

Test Configuration:

  • Python 3.13.13 + uv 0.11.16 (from mise.toml)
  • No real WSS / sockets (pure unit with mocks, following "the subscription/websocket regression tests are the model to follow")
  • asyncio_mode = "strict" respected for other tests (not relevant here)

Checklist:

  • My code follows the style guidelines of this project
  • I have performed a self-review of my own code
  • I have commented my code, particularly in hard-to-understand areas (N/A — the tests + prior comments describe intent; no new source comments per "Clarity over cleverness")
  • I have made corresponding changes to the documentation (CHANGELOG.md)
  • My changes generate no new warnings
  • I have added tests that prove my fix is effective or that my feature works (negative-control TDD tests)
  • New and existing unit tests pass locally with my changes
  • Any dependent changes have been merged and published in downstream modules (N/A)

Closes OPS-3616

@linear-code

linear-code Bot commented Jun 3, 2026

Copy link
Copy Markdown

OPS-3616

@palantir-valiot palantir-valiot Bot force-pushed the palantir/OPS-3616-fix-ping-pong-connectionreset-log branch from 50a752e to 8e13ee8 Compare June 12, 2026 04:31

@palantir-valiot palantir-valiot Bot left a comment

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.

Overall Assessment

The PR applies the same transient-vs-fatal error classification already present in _sub_routing_loop (OPS-3485) to the _ping_pong send path. ConnectionResetError/BrokenPipeError/etc. now emit WARNING instead of ERROR+traceback; reconnection via wss_conn_halted is unchanged. Implementation mirrors the recv pattern exactly, tests are deterministic and fast, and release metadata is updated. No blocking bugs found.

Findings

No actionable findings.

Notes

  • The change is isolated to a single if isinstance(e, TRANSIENT_WS_ERRORS) branch inside the existing bare except Exception in _ping_pong, preserving all prior behavior for non-transient errors.
  • Tests reuse the exact _capture_logs + MagicMock + side-effect termination pattern from the OPS-3485 recv tests; both new tests pass the TDD red-then-green criterion described in the PR body.
  • TRANSIENT_WS_ERRORS is already a module-level tuple (line 35) and is referenced identically on both recv (line 546) and send (line 784) paths.

@palantir-valiot

Copy link
Copy Markdown
Contributor Author

All checks are green (tests, analyze, CodeQL, check_outdated, Snyk). The Palantir PR Reviewer assessment is positive with "No actionable findings."

No code changes required. The implementation mirrors the OPS-3485 recv classification for transient send errors in _ping_pong, the new tests are deterministic/fast and pass the TDD red/green bar, and release metadata (version + CHANGELOG) is updated per AGENTS.md.

Ready for maintainer merge.

@palantir-valiot

Copy link
Copy Markdown
Contributor Author

Rebase recovery during git push-safe hit a conflict replaying recent main commits (b8a1958 etc.) onto the old remote PR tip (d4ea664). Working tree is clean; our change is still a real diff vs current origin/main:

pygqlc/GraphQLClient.py
+ if isinstance(e, TRANSIENT_WS_ERRORS):
+     log(WARNING, ...)
+ else:
+     log(ERROR, ...)

The bug is not yet fixed on main (main's _ping_pong still unconditionally logs ERROR on send exceptions). This is a mechanical CHANGELOG rebase conflict on the PR branch history, not a semantic conflict in the fix.

Per instructions, escalating for human resolution of the push/rebase. The candidate commit on the local branch is 6e821d9 (version 3.8.4 + tests + the send-side transient handling).

@palantir-valiot palantir-valiot Bot force-pushed the palantir/OPS-3616-fix-ping-pong-connectionreset-log branch from d4ea664 to 6e821d9 Compare June 24, 2026 18:55
@palantir-valiot palantir-valiot Bot requested a review from acrogenesis June 24, 2026 18:55

@palantir-valiot palantir-valiot Bot left a comment

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.

Overall Assessment

This PR fixes noisy ERROR+traceback logs in _ping_pong when transient connection errors (ConnectionResetError, BrokenPipeError, etc.) occur during the keep-alive ping send. The fix mirrors the exact classification pattern already used in _sub_routing_loop recv (OPS-3485). No blocking bugs found.

Findings

No actionable findings.

Notes

  • TDD followed per AGENTS.md: tests written first (red because send path always emitted ERROR), then made green by the isinstance(e, TRANSIENT_WS_ERRORS) guard.
  • Tests are hermetic (<100 ms, no sockets, patch("time.sleep") + side-effect termination) and modeled exactly on the existing recv regression tests.
  • TRANSIENT_WS_ERRORS constant (defined at module level, lines 35-40) is reused; the log message for transient cases matches the recv path exactly.
  • Version bump, CHANGELOG entry, and CI checks (format/bandit/pytest/lock) all completed as required.

@palantir-valiot

Copy link
Copy Markdown
Contributor Author

Thanks for the review. All checks green (our ping-pong regression tests + ruff format + bandit). No further changes needed from our side. The current BLOCKED state is CodeQL in-progress + required review; ready when those clear.

@palantir-valiot

Copy link
Copy Markdown
Contributor Author

❌ Agent run failed

The implementer agent encountered a failure and has been parked
in the failed state. The PR remains open for human follow-up.

Reason: "opencode APIError: Forbidden: The OAuth2 access token could not be validated."

If this is a transient provider error (e.g. xAI capacity), the
automatic retry sweeper will revive the run within ~15 min.
Otherwise, reply on this PR or the Linear thread with context
and the run will resume.

@Eduardotrom Eduardotrom left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Automated review summary

Verdict: request changes · Risk: low

The PR fixes spurious ERROR-level logs with full tracebacks emitted by the _ping_pong keep-alive thread when self._conn.send(PING_JSON) raises a transient WSS error (ConnectionResetError, BrokenPipeError, etc.). It classifies those errors as WARNING and only logs ERROR for genuinely unexpected exceptions, mirroring the recv-side handling added in OPS-3485. The functional fix is correct and well-tested, but the branch is in a CONFLICTING state because main has independently released version 3.8.4, which this PR also claims.

Recommendation

Functionally this is safe to merge: the fix is correct, minimal, mirrors the established OPS-3485 recv-side handling, preserves the wss_conn_halted reconnect path, and ships verified hermetic tests. The blocker is purely mechanical — the branch conflicts with main because main already released 3.8.4. Ask the bot/author to rebase onto current main, bump the version to 3.8.5 (resolving the version.py and CHANGELOG conflicts), drop the stray blank line, and correct the stale version reference in the PR body. After rebase, re-run the suite and merge.

Findings

🛑 [blocker] Version/CHANGELOG collision: PR bumps to 3.8.4 but main already shipped 3.8.4

  • 📍 pygqlc/__version__.py:1, CHANGELOG.md:3
  • main's pygqlc/version.py is already "3.8.4" (CHANGELOG entry [3.8.4] - 2026-06-25, the async_execute retry change), and this PR ALSO bumps 3.8.3 -> 3.8.4 with its own [3.8.4] - 2026-06-24 entry. GitHub reports the PR as mergeable=CONFLICTING. The conflict is confined to CHANGELOG.md and pygqlc/version.py (the actual _ping_pong source change does NOT overlap and merges cleanly). The author must rebase onto current main and bump to 3.8.5 (or next free patch), re-stacking the CHANGELOG entry. Until then the PR cannot merge.

🟡 [minor] PR description version claim is stale/incorrect

  • 📍 PR description
  • The PR body says 'Version bump 3.8.0 -> 3.8.1 (patch)' and references the recv pattern at 'lines ~543-549', but the actual diff bumps 3.8.3 -> 3.8.4 and the recv pattern is at lines 556-562. The body appears copied from an earlier template and was not updated to the rebased state. Cosmetic, but it obscured the real version collision; worth correcting when rebasing.

🔵 [nit] Stray blank line introduced in CHANGELOG

  • 📍 CHANGELOG.md
  • The diff adds an extra blank line before the ## [3.8.0] heading (the lone + empty line in the CHANGELOG hunk). Harmless but inconsistent with the surrounding single-blank-line spacing; clean it up during the rebase.

[praise] Source fix is correct and faithfully mirrors the recv-side pattern

  • 📍 pygqlc/GraphQLClient.py:813
  • _ping_pong (GraphQLClient.py:813-825) now does if isinstance(e, TRANSIENT_WS_ERRORS): log(WARNING, ...) else: log(ERROR, ...), identical in structure to the recv handler at lines 556-562 introduced in OPS-3485. It reuses the existing TRANSIENT_WS_ERRORS tuple (lines 35-40), keeps the if not self.closing: guard, and still sets self.wss_conn_halted = True in both branches, so reconnection behavior is unchanged. Only the log level/message changes for transient errors. No behavior regression for fatal errors.

[praise] Hermetic regression tests, verified passing

  • 📍 tests/pygqlc/gql_client/test_subscribe.py:259
  • I ran the two new tests locally (uv run pytest -k test_ping_pong): 2 passed in 0.05s. test_ping_pong_connection_reset_logged_as_warning asserts WARNING + halted + no ERROR; test_ping_pong_unexpected_error_logged_as_error asserts a ValueError still surfaces at ERROR + halted. Both patch time.sleep and use the closing-via-side-effect pattern, are socket-free, and the _run_ping_pong helper joins with a timeout and asserts the thread terminated, so a regression that hangs the loop would fail rather than hang.

Generated by an automated multi-agent review swarm and posted by @Eduardotrom. Verify load-bearing claims before merging.

@palantir-valiot

Copy link
Copy Markdown
Contributor Author

❌ Agent run failed

The implementer agent encountered a failure and has been parked
in the failed state. The PR remains open for human follow-up.

Reason: "opencode APIError: Forbidden: You have run out of credits or need a Grok subscription. Add credits at https://grok.com/?_s=usage or upgrade at https://grok.com/supergrok."

If this is a transient provider error (e.g. xAI capacity), the
automatic retry sweeper will revive the run within ~15 min.
Otherwise, reply on this PR or the Linear thread with context
and the run will resume.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant