librarian: tolerate bad bytes in chunks; log what the result-send does
CI / compile (pull_request) Successful in 10s
CI / unit (pull_request) Successful in 20s
CI / integration (pull_request) Successful in 15s
CI / compile (push) Successful in 29s
CI / unit (push) Successful in 30s
CI / integration (push) Successful in 21s
build / build (push) Failing after 7s
CI / compile (pull_request) Successful in 10s
CI / unit (pull_request) Successful in 20s
CI / integration (pull_request) Successful in 15s
CI / compile (push) Successful in 29s
CI / unit (push) Successful in 30s
CI / integration (push) Successful in 21s
build / build (push) Failing after 7s
Two field-reported robustness gaps on top of the hang fix. 1) A stray non-UTF-8 byte in a chunk (0x96 in the report) raised UnicodeDecodeError from readline() - which is a ValueError, so the earlier `except OSError` did NOT catch it. The finally-sentinel meant no hang, but the producer died mid-file with a loud traceback and every DOI after the bad byte went unsearched. Now chunks are opened with errors="replace" (bad bytes become U+FFFD; DOIs are ASCII so a match is never affected) so the read runs to EOF, and the producer's except is broadened from OSError to Exception so no per-file error can ever crash the thread - it's logged and the sentinel still fires. 2) The result-send back to the bot (BackgroundTaskSearch._run) now logs exactly what goes out - target URL, uuid, DOI count and the DOI list - so the librarian log plainly shows a result was sent and what was in it. And a failed POST is no longer fatal: a RequestException used to propagate out of the worker loop and kill the thread, stalling every future query until restart; it's now caught and logged, and a non-200 from the bot is logged as a warning. Verified: tests/unit/test_search_bot.py gains a case writing a chunk with a 0x96 byte before a valid DOI and asserting that DOI is still found (file read to completion, not aborted). All 5 search_bot unit tests pass. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit was merged in pull request #4.
This commit is contained in:
@@ -451,18 +451,48 @@ class BackgroundTaskSearch(threading.Thread):
|
||||
json.dump(database, s_file)
|
||||
self.app.logger.info("FINISHED")
|
||||
|
||||
self.app.logger.info(result)
|
||||
coroutine = asyncio.to_thread(
|
||||
requests.post,
|
||||
f"{MAIN_BOT_ADDRESS}{SEND_RESULTS}",
|
||||
json=result,
|
||||
headers=_service_headers(),
|
||||
timeout=360,
|
||||
# Send the result back to the bot. Log EXACTLY what goes out (target,
|
||||
# uuid, how many DOIs and which) so the librarian log makes it plain a
|
||||
# result was sent and what was in it.
|
||||
payload = result # shape: {uuid: {DOI: {"Title": ..., "type": ...}}}
|
||||
hits = payload.get(librarian.uuid, {}) if isinstance(payload, dict) else {}
|
||||
target = f"{MAIN_BOT_ADDRESS}{SEND_RESULTS}"
|
||||
self.app.logger.info(
|
||||
"SENDING result for %s to %s: %d DOI(s): %s",
|
||||
librarian.uuid,
|
||||
target,
|
||||
len(hits),
|
||||
list(hits.keys()),
|
||||
)
|
||||
self.app.logger.info("SENT")
|
||||
result = await coroutine
|
||||
self.app.logger.info(result.status_code)
|
||||
self.app.logger.info("SEND CONFIRMED")
|
||||
# A failed send must NOT kill this worker - otherwise a bot that is
|
||||
# momentarily down stalls every future query until the librarian is
|
||||
# restarted. Log and carry on to the next queued search.
|
||||
try:
|
||||
response = await asyncio.to_thread(
|
||||
requests.post,
|
||||
target,
|
||||
json=payload,
|
||||
headers=_service_headers(),
|
||||
timeout=360,
|
||||
)
|
||||
if response.status_code == 200:
|
||||
self.app.logger.info(
|
||||
"SENT result for %s -> HTTP 200 (bot accepted)", librarian.uuid
|
||||
)
|
||||
else:
|
||||
self.app.logger.warning(
|
||||
"SENT result for %s but bot returned HTTP %s: %s",
|
||||
librarian.uuid,
|
||||
response.status_code,
|
||||
response.text[:500],
|
||||
)
|
||||
except requests.exceptions.RequestException as exc:
|
||||
self.app.logger.error(
|
||||
"FAILED to send result for %s to %s: %s",
|
||||
librarian.uuid,
|
||||
target,
|
||||
exc,
|
||||
)
|
||||
await asyncio.sleep(1)
|
||||
|
||||
|
||||
|
||||
@@ -90,7 +90,12 @@ def producer(out_q, control_q, filename, _logger):
|
||||
_logger: Logger object for logging.
|
||||
"""
|
||||
try:
|
||||
with open(DATABASE_PATH + filename, "r", encoding=ENCODING) as operated_file:
|
||||
# errors="replace" so a stray non-UTF-8 byte in a chunk (they happen in
|
||||
# scraped DOI dumps) becomes U+FFFD instead of raising UnicodeDecodeError
|
||||
# mid-file. Without it the readline() below would blow up, killing the
|
||||
# producer partway and leaving every DOI after the bad byte unsearched.
|
||||
# DOIs are ASCII, so a replaced byte can only affect junk, never a match.
|
||||
with open(DATABASE_PATH + filename, "r", encoding=ENCODING, errors="replace") as operated_file:
|
||||
print(f"Worker {filename} ")
|
||||
line_no = 0
|
||||
while True:
|
||||
@@ -113,11 +118,13 @@ def producer(out_q, control_q, filename, _logger):
|
||||
control_q.put(check)
|
||||
break
|
||||
print(f"Worker finished: {filename}")
|
||||
except OSError as exc:
|
||||
# A missing or unreadable chunk must not take the whole search down with
|
||||
# it - log and move on. The sentinel below still fires (finally), so the
|
||||
# consumers' count stays correct and nothing deadlocks.
|
||||
_logger.warning("Chunk %s unreadable, skipping: %s", filename, exc)
|
||||
except Exception as exc: # pylint: disable=broad-except
|
||||
# No per-file error (missing/unreadable chunk, a decode edge case that
|
||||
# slips past errors="replace", anything unforeseen) may take the whole
|
||||
# search down or crash the thread with a traceback. Log it and move on;
|
||||
# the sentinel below still fires (finally), so the consumers' count stays
|
||||
# correct and nothing deadlocks or silently loses a producer.
|
||||
_logger.warning("Chunk %s failed, skipping rest of it: %s", filename, exc)
|
||||
print(f"Worker {filename} failed: {exc}")
|
||||
finally:
|
||||
# ALWAYS emit exactly one sentinel per producer, on every exit path (EOF,
|
||||
|
||||
@@ -77,6 +77,23 @@ def test_no_chunks_returns_immediately(tmp_path, monkeypatch):
|
||||
assert result == [{"DOI": "10.0/x", "exists": False, "data": "DATA"}]
|
||||
|
||||
|
||||
def test_survives_invalid_utf8_byte_and_still_finds_later_doi(tmp_path, monkeypatch):
|
||||
# A chunk with a stray non-UTF-8 byte (0x96, the one from the field report)
|
||||
# must not crash the producer or abort the file mid-read: DOIs AFTER the bad
|
||||
# byte still have to be found.
|
||||
monkeypatch.setattr(search_bot, "DATABASE_PATH", str(tmp_path) + "/")
|
||||
target = "10.1234/after.the.bad.byte"
|
||||
(tmp_path / "0_chunk.txt").write_bytes(
|
||||
b"10.0000/before\n" + b"\x96 broken \x96 line \x96\n" + target.encode() + b"\n"
|
||||
)
|
||||
|
||||
finished, result = _run_bounded([(target, "DATA")])
|
||||
|
||||
assert finished, "an invalid UTF-8 byte hung or crashed the search"
|
||||
hit = [r for r in result if r["DOI"] == target and r["exists"]]
|
||||
assert hit, "DOI after the bad byte was not found - the file was aborted mid-read"
|
||||
|
||||
|
||||
def test_discover_chunk_files_sorted_numerically(tmp_path, monkeypatch):
|
||||
monkeypatch.setattr(search_bot, "DATABASE_PATH", str(tmp_path) + "/")
|
||||
for n in (0, 2, 10, 1):
|
||||
|
||||
Reference in New Issue
Block a user