fix(skills): TG routine read-timeouts silenced on OSError path + outage episode-start demoted ERROR→WARNING per Patrick ruling — ends medic wake-loop. 825 TG tests green
This commit is contained in:
@@ -11,6 +11,38 @@ PyPI version — not the changelog header.
|
||||
|
||||
## [2026-07-15]
|
||||
|
||||
### Fixed
|
||||
|
||||
- **Plan vectorization pipeline unwedged (DPLAN-0245): 57 closed plans were
|
||||
silently missing from semantic memory since mid-June.** Vector IDs were pure
|
||||
content hashes, so identical template boilerplate across different plans
|
||||
produced duplicate IDs within one ChromaDB upsert — the store rejected the
|
||||
entire batch, and the all-or-nothing intake retried the same failing batch
|
||||
forever. Fixed in @memory: IDs are now salted with the source filename when
|
||||
present (rollover hashes unchanged — no re-vectorization churn), in-batch
|
||||
dedup as a safety net, and `process_plans()` now runs per-file with the
|
||||
manifest saved after each success so a poison file can never wedge the queue
|
||||
again. Backlog drained and verified: 229/229 archived plans vectorized, 1112
|
||||
chunks, formerly-lost plans answering semantic queries at 85%+ similarity.
|
||||
990 memory tests green.
|
||||
|
||||
- **CLOSED_PLANS ledger append race (@flow): concurrent plan closes lost
|
||||
entries.** `append_to_closed_plans` was an unlocked read-modify-write; the
|
||||
S314 bulk sweep lost 18 of 21 entries to it (reconciled by hand). Now guarded
|
||||
by an `O_CREAT|O_EXCL` lockfile with retry/backoff, and the previously
|
||||
silent append failure is surfaced in close output and logs. 730 flow tests
|
||||
green.
|
||||
|
||||
- **Telegram routine read-timeouts no longer logged as errors (@skills,
|
||||
Patrick ruling): ends the medic wake-loop.** A routine long-poll read
|
||||
timeout (`socket.timeout` — an `OSError` subclass) slipped past the earlier
|
||||
`URLError`-only guard into the network-outage path, logging ERROR once per
|
||||
episode (~576 lines/30h) and waking @trigger's medic each time. The
|
||||
`_is_routine_read_timeout` guard now covers the `OSError` handler too, and
|
||||
the genuine-outage episode-start line is demoted ERROR→WARNING (backoff
|
||||
self-heals; recovery already logs INFO; medic only fires on ERROR/CRITICAL).
|
||||
Real failures still log ERROR. 825 telegram tests green.
|
||||
|
||||
### Security
|
||||
|
||||
- **Hook config trust model hardening (DPLAN-0244): closes a zero-interaction
|
||||
|
||||
@@ -380,7 +380,7 @@ class BaseBot:
|
||||
net_offline_since = now
|
||||
net_suppressed = 0
|
||||
net_last_summary = now
|
||||
logger.error("Telegram unreachable, backing off: %s", e)
|
||||
logger.warning("Telegram unreachable, backing off: %s", e)
|
||||
else:
|
||||
net_suppressed += 1
|
||||
if now - net_last_summary >= NETWORK_LOG_INTERVAL:
|
||||
@@ -471,6 +471,8 @@ class BaseBot:
|
||||
logger.error("Poll error: %s", e)
|
||||
return []
|
||||
except (ConnectionError, OSError) as e:
|
||||
if _is_routine_read_timeout(e):
|
||||
return []
|
||||
raise _NetworkPollError(str(e)) from e
|
||||
except Exception as e:
|
||||
logger.error("Unexpected poll error: %s", e)
|
||||
|
||||
@@ -164,6 +164,36 @@ class TestPollUpdatesErrorClassification:
|
||||
with pytest.raises(_NetworkPollError):
|
||||
bot.poll_updates(0)
|
||||
|
||||
def test_bare_socket_timeout_returns_empty(self, tmp_path, _patch_base_bot_deps):
|
||||
"""socket.timeout (subclass of OSError) with 'read operation' should be silenced, not raised."""
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
import socket
|
||||
|
||||
exc = socket.timeout("The read operation timed out")
|
||||
with patch("aipass.skills.lib.telegram.apps.handlers.base_bot.urlopen", side_effect=exc):
|
||||
result = bot.poll_updates(0)
|
||||
assert result == []
|
||||
|
||||
def test_bare_socket_timeout_no_error_log(self, tmp_path, _patch_base_bot_deps):
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
import socket
|
||||
|
||||
exc = socket.timeout("The read operation timed out")
|
||||
with (
|
||||
patch("aipass.skills.lib.telegram.apps.handlers.base_bot.urlopen", side_effect=exc),
|
||||
patch("aipass.skills.lib.telegram.apps.handlers.base_bot.logger") as mock_logger,
|
||||
):
|
||||
bot.poll_updates(0)
|
||||
mock_logger.error.assert_not_called()
|
||||
|
||||
def test_bare_connect_timeout_raises_network_error(self, tmp_path, _patch_base_bot_deps):
|
||||
"""A connect timeout (not read) IS a network error."""
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
exc = TimeoutError("Connection timed out")
|
||||
with patch("aipass.skills.lib.telegram.apps.handlers.base_bot.urlopen", side_effect=exc):
|
||||
with pytest.raises(_NetworkPollError):
|
||||
bot.poll_updates(0)
|
||||
|
||||
def test_non_network_urlerror_logs_error(self, tmp_path, _patch_base_bot_deps):
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
exc = URLError("HTTP Error 502")
|
||||
@@ -247,7 +277,7 @@ class TestRunLoopNetworkBackoff:
|
||||
|
||||
|
||||
class TestLogOnceSemantics:
|
||||
def test_first_failure_logs_error(self, tmp_path, _patch_base_bot_deps):
|
||||
def test_first_failure_logs_warning(self, tmp_path, _patch_base_bot_deps):
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
call_count = 0
|
||||
|
||||
@@ -266,8 +296,10 @@ class TestLogOnceSemantics:
|
||||
):
|
||||
bot.run()
|
||||
|
||||
warn_calls = [c for c in mock_logger.warning.call_args_list if "unreachable" in str(c)]
|
||||
assert len(warn_calls) == 1
|
||||
error_calls = [c for c in mock_logger.error.call_args_list if "unreachable" in str(c)]
|
||||
assert len(error_calls) == 1
|
||||
assert len(error_calls) == 0
|
||||
|
||||
def test_subsequent_failures_suppressed(self, tmp_path, _patch_base_bot_deps):
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
@@ -288,9 +320,9 @@ class TestLogOnceSemantics:
|
||||
):
|
||||
bot.run()
|
||||
|
||||
error_calls = [c for c in mock_logger.error.call_args_list if "unreachable" in str(c)]
|
||||
# Only one "unreachable" error, not 10
|
||||
assert len(error_calls) == 1
|
||||
warn_calls = [c for c in mock_logger.warning.call_args_list if "unreachable" in str(c)]
|
||||
# Only one "unreachable" warning, not 10
|
||||
assert len(warn_calls) == 1
|
||||
|
||||
def test_recovery_logs_info(self, tmp_path, _patch_base_bot_deps):
|
||||
bot = _make_bot(tmp_path, _patch_base_bot_deps)
|
||||
|
||||
Reference in New Issue
Block a user