Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 9 additions & 3 deletions keel/data/cb_client.py
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@
from decimal import Decimal
from typing import Any, Protocol

from keel_core.telemetry import log_exception
from keel_core.telemetry import log_exception, log_venue_failure

from keel.types import Candle, Granularity, Side

Expand Down Expand Up @@ -193,11 +193,17 @@ def list_products(self, product_type: str = "SPOT") -> list[dict]:
return out

def get_accounts(self) -> list[dict]:
"""Return authenticated account balances, keyed by currency."""
"""Return authenticated account balances, keyed by currency.

Logged through `log_venue_failure`, not `log_exception`: this is polled on a cadence by
the TUI's balance refresh, so an unreachable venue would otherwise write a full
traceback every 30s for as long as the machine is offline. Always re-raises, unchanged
-- severity is a logging concern and rail 13 fails closed on the exception itself.
"""
try:
response = self._transport.get_accounts()
except Exception:
log_exception(logger, "cb_client.accounts_fetch_failed")
log_venue_failure(logger, "cb_client.accounts_fetch_failed")
raise
raw_accounts = _field(response, "accounts", []) or []
accounts = []
Expand Down
11 changes: 9 additions & 2 deletions keel/execution/executor.py
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,7 @@
from typing import Any, Literal

from keel_core.products import quote_currency_of
from keel_core.telemetry import log_event, log_exception
from keel_core.telemetry import log_event, log_exception, log_venue_failure

from keel.config import Config
from keel.data.repository import Repository
Expand Down Expand Up @@ -281,7 +281,14 @@ def _fetch_available_quote(broker: Any, quote_currency: str | None) -> Decimal |
try:
accounts = broker.get_accounts()
except Exception:
log_exception(logger, "executor.quote_fetch_failed", quote_currency=quote_currency)
# `log_venue_failure`, not `log_exception`: an unreachable venue outside a trade cycle
# is a dashboard balance refresh on a sleeping laptop, and this line is the SECOND
# record for that one failure (`cb_client.get_accounts` logs it first) -- two full
# tracebacks per poll, every 30s, for as long as the machine is offline. Inside a cycle
# it escalates back to ERROR on its own: there it means rail 13 failed closed and an
# order did not go out. Kept as its own event rather than dropped because it carries
# `quote_currency`, and because a non-Coinbase broker may not log anything itself.
log_venue_failure(logger, "executor.quote_fetch_failed", quote_currency=quote_currency)
return None

for account in accounts or []:
Expand Down
84 changes: 84 additions & 0 deletions packages/keel-core/keel_core/telemetry.py
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@

import json
import logging
import sys
import uuid
from contextvars import ContextVar, Token
from typing import Any
Expand All @@ -40,6 +41,34 @@
# these names is renamed (not dropped, not allowed to overwrite) -- see module docstring.
_RESERVED = frozenset({"ts", "level", "logger", "event", "cycle_id", "exc"})

# Exception type NAMES that mean "the venue was unreachable" rather than "something is wrong" --
# see `is_venue_unreachable` for why this is a name match and not an `isinstance` check. Covers
# the builtin socket errors plus the `requests`/`urllib3` wrappers a broker's HTTP stack raises.
_UNREACHABLE_EXC_NAMES = frozenset(
{
"ConnectionError", # builtin, and requests.exceptions.ConnectionError
"ConnectionResetError",
"ConnectionRefusedError",
"ConnectionAbortedError",
"TimeoutError", # builtin, and requests.exceptions.Timeout's socket cause
"Timeout",
"ConnectTimeout",
"ConnectTimeoutError",
"ReadTimeout",
"ReadTimeoutError",
"ProxyError",
"MaxRetryError",
"NewConnectionError",
"NameResolutionError",
"gaierror", # socket.gaierror -- DNS not up yet after a wake
}
)

# Cap on the one-line `error` summary that replaces a traceback on the unreachable path. Long
# enough to keep the host and the underlying cause `requests` nests into its message, short
# enough that the event stays one readable line.
_ERROR_SUMMARY_MAX_CHARS = 200


def new_cycle_id() -> str:
"""Generate a fresh correlation id for one engine cycle."""
Expand Down Expand Up @@ -114,6 +143,61 @@ def log_exception(logger: logging.Logger, event: str, /, **fields: Any) -> None:
logger.log(logging.ERROR, event, exc_info=True, extra={_FIELDS_ATTR: fields})


def is_venue_unreachable(exc: BaseException | None) -> bool:
"""True when `exc` means "could not reach the venue", not "something is wrong".

Matched on the exception type's NAME, walked over the `__cause__`/`__context__` chain,
because `requests` wraps the underlying socket/DNS error and the outermost type is not
always the signal. Matching by name (rather than importing `requests`/`urllib3` and using
`isinstance`) keeps `keel-core` free of an HTTP dependency it otherwise does not need, and
keeps the classification working for any broker adapter's HTTP stack.

`SSLError` is deliberately absent: a failed TLS handshake can mean interception or a bad
certificate, which an operator must see at ERROR rather than have filed as "wifi is down".
"""
seen: set[int] = set()
while exc is not None and id(exc) not in seen:
seen.add(id(exc))
if type(exc).__name__ in _UNREACHABLE_EXC_NAMES:
return True
exc = exc.__cause__ or exc.__context__
return False


def log_venue_failure(logger: logging.Logger, event: str, /, **fields: Any) -> bool:
"""Emit a broker-call failure at a severity that matches what it actually cost. Returns
whether the active exception was classified unreachable.

Use inside an `except` block, in place of `log_exception`, for any call that crosses the
network to a venue.

- **Unreachable, outside a trade cycle** (a dashboard's balance refresh while the laptop is
asleep) -> WARNING, one line, no traceback. Nothing was lost; the caller already fails
soft. This is the case that motivated the helper: a 35-minute offline window on
2026-08-06 wrote 60 twenty-frame ERROR tracebacks through `get_accounts`, around a single
real `401 Unauthorized` that no operator would ever have spotted in the noise.
- **Unreachable, inside a trade cycle** (`cycle_id` bound) -> ERROR. Here it did cost
something: rail 13 fails closed on a missing balance, so an order did not go out. Still
no traceback -- the cause is known and the frames say nothing the summary does not.
- **Anything else** (auth, malformed response, a bug) -> ERROR with the full traceback,
byte-for-byte what `log_exception` would have emitted.

The unreachable paths add `unreachable=True` and a truncated `error` summary. Caller fields
win over both, on the same principle as `log_event`: a logging call must never raise.
"""
exc = sys.exc_info()[1]
if not is_venue_unreachable(exc):
log_exception(logger, event, **fields)
return False

level = logging.ERROR if _cycle_id.get() is not None else logging.WARNING
summary = f"{type(exc).__name__}: {exc}"
if len(summary) > _ERROR_SUMMARY_MAX_CHARS:
summary = summary[:_ERROR_SUMMARY_MAX_CHARS] + "..."
log_event(logger, level, event, **{"unreachable": True, "error": summary, **fields})
return True


class JsonFormatter(logging.Formatter):
"""Render a LogRecord as a single-line JSON object."""

Expand Down
62 changes: 62 additions & 0 deletions tests/data/test_cb_client.py
Original file line number Diff line number Diff line change
Expand Up @@ -8,10 +8,14 @@
from __future__ import annotations

import json
import logging
from decimal import Decimal
from pathlib import Path
from typing import Any

import pytest
from keel_core import telemetry

from keel.data.cb_client import CoinbaseClient
from keel.types import Candle, Granularity, Side

Expand Down Expand Up @@ -532,3 +536,61 @@ def test_cancel_order_returns_false_on_an_empty_result_set():
client = CoinbaseClient(FakeTransport(cancel={"results": []}))

assert client.cancel_order("abc") is False


# --- get_accounts failure severity --------------------------------------------------------
#
# `get_accounts` is polled every 30s by the TUI's balance refresh. An offline laptop must not
# write a 20-frame ERROR traceback per poll -- that is what buried a real `401 Unauthorized`
# among 60 connection failures on 2026-08-06. It must still RAISE either way: severity is a
# logging concern, and callers (rail 13 among them) depend on the exception.


class _RaisingTransport:
"""A transport whose `get_accounts` raises whatever it was handed."""

def __init__(self, exc: BaseException) -> None:
self._exc = exc

def get_accounts(self, **kwargs: Any) -> dict:
raise self._exc


def _accounts_failure_payload(caplog, exc: BaseException) -> dict:
formatter = telemetry.JsonFormatter()
client = CoinbaseClient(_RaisingTransport(exc))
with caplog.at_level(logging.DEBUG, logger="keel.data.cb_client"):
with pytest.raises(type(exc)):
client.get_accounts()
records = [r for r in caplog.records if r.getMessage() == "cb_client.accounts_fetch_failed"]
assert len(records) == 1
return json.loads(formatter.format(records[0]))


def test_get_accounts_logs_an_unreachable_venue_as_a_warning(caplog) -> None:
exc = type("ConnectionError", (Exception,), {})("api.coinbase.com unreachable")

payload = _accounts_failure_payload(caplog, exc)

assert payload["level"] == "WARNING"
assert payload["unreachable"] is True
assert "exc" not in payload


def test_get_accounts_still_logs_a_401_as_an_error_with_its_traceback(caplog) -> None:
exc = type("HTTPError", (Exception,), {})("401 Client Error: Unauthorized")

payload = _accounts_failure_payload(caplog, exc)

assert payload["level"] == "ERROR"
assert "Traceback" in payload["exc"]


def test_get_accounts_still_raises_when_the_venue_is_unreachable(caplog) -> None:
"""Severity changed; control flow must not. Rail 13 fails closed on this exception."""
boom = type("ConnectionError", (Exception,), {})("unreachable")
client = CoinbaseClient(_RaisingTransport(boom))

with caplog.at_level(logging.DEBUG):
with pytest.raises(type(boom)):
client.get_accounts()
52 changes: 52 additions & 0 deletions tests/execution/test_executor.py
Original file line number Diff line number Diff line change
Expand Up @@ -1520,3 +1520,55 @@ def test_no_account_at_all_for_the_required_currency_fails_closed(repo):
assert result.placed is False
assert result.preview is None
assert any("unknown/unavailable" in v for v in result.vetoed_by)


# --- _fetch_available_quote failure severity ----------------------------------------------
#
# The second half of the 2026-08-06 log-noise pair: every `get_accounts` failure was logged
# twice at ERROR with a full traceback -- once by `cb_client`, then again here. Rail 13 still
# fails closed (`None`) either way; only the severity of the record changes.


class _UnreachableBroker:
"""A broker whose `get_accounts` raises as an offline HTTP stack does."""

def __init__(self, exc: BaseException) -> None:
self._exc = exc

def get_accounts(self) -> list[dict]:
raise self._exc


def _quote_failure_payload(caplog, exc: BaseException) -> tuple[Decimal | None, dict]:
from keel_core import telemetry

from keel.execution.executor import _fetch_available_quote

formatter = telemetry.JsonFormatter()
with caplog.at_level(logging.DEBUG, logger="keel.execution.executor"):
result = _fetch_available_quote(_UnreachableBroker(exc), "USD")
records = [r for r in caplog.records if r.getMessage() == "executor.quote_fetch_failed"]
assert len(records) == 1
return result, json.loads(formatter.format(records[0]))


def test_quote_fetch_logs_an_unreachable_venue_as_a_warning(caplog) -> None:
exc = type("ConnectionError", (Exception,), {})("api.coinbase.com unreachable")

result, payload = _quote_failure_payload(caplog, exc)

assert result is None # rail 13 still fails closed
assert payload["level"] == "WARNING"
assert payload["unreachable"] is True
assert "exc" not in payload
assert payload["quote_currency"] == "USD"


def test_quote_fetch_keeps_a_real_broker_error_at_error_with_its_traceback(caplog) -> None:
exc = type("HTTPError", (Exception,), {})("401 Client Error: Unauthorized")

result, payload = _quote_failure_payload(caplog, exc)

assert result is None
assert payload["level"] == "ERROR"
assert "Traceback" in payload["exc"]
Loading
Loading