Richie/dotfiles
1
0
Fork 0
Code Issues 1 Pull Requests 3 Actions Packages Projects Releases Wiki Activity

Refactor logging statements to use f-strings for improved readability and consistency across the codebase. This change enhances the clarity of log messages by directly embedding variable values, making it easier to trace and debug application behavior.

Browse Source
This commit is contained in:
Richie
2026-07-16 13:09:34 -04:00
parent 4a97f5a2d0
commit 49b93c79f6
23 changed files with 142 additions and 368 deletions
Download Patch File Download Diff File Expand all files Collapse all files
python/ebook_search/protected_phrases/__init__.py
+1
View File
@@ -0,0 +1 @@
"""Protected phrase extraction and matching for ebook search."""
python/ebook_search/protected_phrases/extraction.py
+13 -32
View File
@@ -682,33 +682,26 @@ def extract_phrase_candidates_for_book(
"""
started_at = perf_counter()
logger.info(
"ebook_phrase_candidate_extract_start chapters=%s chars=%s min_tokens=%s max_tokens=%s max_candidates=%s",
len(chapters),
len(book_text),
config.phrase_min_tokens,
config.phrase_max_tokens,
config.protected_phrase_max_candidates_per_book,
f"ebook_phrase_candidate_extract_start chapters={len(chapters)} chars={len(book_text)} "
f"{config.phrase_min_tokens=} {config.phrase_max_tokens=} {config.protected_phrase_max_candidates_per_book=}"
)
raw_started_at = perf_counter()
raw = extract_raw_ngrams_by_chapter(chapters, config)
logger.info(
"ebook_phrase_candidate_extract_raw_complete candidates=%s duration_ms=%.1f",
len(raw),
(perf_counter() - raw_started_at) * 1000,
f"ebook_phrase_candidate_extract_raw_complete candidates={len(raw)} duration_ms={(perf_counter() - "
f"raw_started_at) * 1000:.1f}"
)
yake_started_at = perf_counter()
yake_candidates = extract_yake_candidates(book_text, config)
logger.info(
"ebook_phrase_candidate_extract_yake_complete candidates=%s duration_ms=%.1f",
len(yake_candidates),
(perf_counter() - yake_started_at) * 1000,
f"ebook_phrase_candidate_extract_yake_complete candidates={len(yake_candidates)} duration_ms={(perf_counter() - "
f"yake_started_at) * 1000:.1f}"
)
capitalized_started_at = perf_counter()
capitalized = extract_capitalized_phrases(book_text, config)
logger.info(
"ebook_phrase_candidate_extract_capitalized_complete candidates=%s duration_ms=%.1f",
len(capitalized),
(perf_counter() - capitalized_started_at) * 1000,
f"ebook_phrase_candidate_extract_capitalized_complete candidates={len(capitalized)} "
f"duration_ms={(perf_counter() - capitalized_started_at) * 1000:.1f}"
)
metadata_candidates = extract_metadata_candidates(metadata, config)
@@ -732,22 +725,10 @@ def extract_phrase_candidates_for_book(
: config.protected_phrase_max_candidates_per_book
]
logger.info(
"ebook_phrase_candidate_extract_complete raw=%s yake=%s capitalized=%s metadata=%s "
"merged=%s filtered_too_short=%s filtered_too_rare=%s filtered_too_common=%s filtered_junk=%s "
"min_uses=%s storable=%s limited=%s enrich_score_ms=%.1f duration_ms=%.1f",
len(raw),
len(yake_candidates),
len(capitalized),
len(metadata_candidates),
pre_filter_count,
filtered_too_short,
filtered_too_rare,
filtered_too_common,
filtered_junk,
minimum_candidate_raw_count(config),
len(candidates),
len(limited),
(perf_counter() - enriched_started_at) * 1000,
(perf_counter() - started_at) * 1000,
f"ebook_phrase_candidate_extract_complete raw={len(raw)} yake={len(yake_candidates)} "
f"capitalized={len(capitalized)} metadata={len(metadata_candidates)} {pre_filter_count=} {filtered_too_short=} "
f"{filtered_too_rare=} {filtered_too_common=} {filtered_junk=} min_uses={minimum_candidate_raw_count(config)} "
f"storable={len(candidates)} limited={len(limited)} enrich_score_ms={(perf_counter() - enriched_started_at) * "
f"1000:.1f} duration_ms={(perf_counter() - started_at) * 1000:.1f}"
)
return limited
python/ebook_search/protected_phrases/generate_ngrams.py
+16 -49
View File
@@ -68,12 +68,8 @@ async def generate_candidate_phrases_for_books(
source_ids = (await session.scalars(source_query)).all()
books_seen = len(source_ids)
logger.info(
"ebook_candidate_phrase_generation_start books_seen=%s min_tokens=%s max_tokens=%s "
"max_candidates_per_book=%s",
books_seen,
config.phrase_min_tokens,
config.phrase_max_tokens,
config.protected_phrase_max_candidates_per_book,
f"ebook_candidate_phrase_generation_start {books_seen=} {config.phrase_min_tokens=} {config.phrase_max_tokens=} "
f"{config.protected_phrase_max_candidates_per_book=}"
)
pool = get_extraction_pool(config.protected_phrase_extraction_workers)
@@ -89,19 +85,11 @@ async def generate_candidate_phrases_for_books(
await asyncio.wait([wrapped_future])
exception = wrapped_future.exception()
if exception is not None:
logger.error(
"ebook_candidate_phrase_generation_book_failed source_id=%s",
source_id,
exc_info=exception,
)
logger.error(f"ebook_candidate_phrase_generation_book_failed {source_id=}")
outcomes.append(BookCandidateResult())
continue
saved_count = wrapped_future.result()
logger.info(
"ebook_candidate_phrase_generation_book_committed source_id=%s candidates=%s",
source_id,
saved_count,
)
logger.info(f"ebook_candidate_phrase_generation_book_committed {source_id=} {saved_count=}")
outcomes.append(BookCandidateResult(candidates=saved_count, built=True))
result = PhraseCandidateGenerationResult(
@@ -110,10 +98,8 @@ async def generate_candidate_phrases_for_books(
candidate_phrases=sum(outcome.candidates for outcome in outcomes),
)
logger.info(
"ebook_candidate_phrase_generation_complete books_seen=%s books_built=%s candidate_total=%s",
result.books_seen,
result.books_built,
result.candidate_phrases,
f"ebook_candidate_phrase_generation_complete {result.books_seen=} {result.books_built=} "
f"{result.candidate_phrases=}"
)
return result
@@ -141,11 +127,7 @@ async def recalculate_candidate_phrases_for_book(
regeneration failure rolls the deletion back.
"""
started_at = perf_counter()
logger.info(
"ebook_candidate_phrase_recalculation_start source_id=%s title=%r",
source.id,
source.title,
)
logger.info(f"ebook_candidate_phrase_recalculation_start {source.id=} {source.title=}")
deleted = await delete_phrase_data_for_book(session, source.id)
candidate_count = await generate_candidate_phrases_for_book(
session,
@@ -164,15 +146,9 @@ async def recalculate_candidate_phrases_for_book(
candidate_phrases=candidate_count,
)
logger.info(
"ebook_candidate_phrase_recalculation_complete source_id=%s deleted_candidates=%s "
"deleted_protected=%s deleted_aliases=%s deleted_mentions=%s candidates=%s duration_ms=%.1f",
source.id,
result.deleted_candidates,
result.deleted_protected_phrases,
result.deleted_aliases,
result.deleted_mentions,
result.candidate_phrases,
(perf_counter() - started_at) * 1000,
f"ebook_candidate_phrase_recalculation_complete {source.id=} {result.deleted_candidates=} "
f"{result.deleted_protected_phrases=} {result.deleted_aliases=} {result.deleted_mentions=} "
f"{result.candidate_phrases=} duration_ms={(perf_counter() - started_at) * 1000:.1f}"
)
return result
@@ -268,10 +244,8 @@ async def generate_candidate_phrases_for_book(
await session.rollback()
raise
logger.info(
"ebook_candidate_phrase_generation_book_duration book_id=%s candidates=%s duration_ms=%.1f",
book_id,
saved_count,
(perf_counter() - started_at) * 1000,
f"ebook_candidate_phrase_generation_book_duration {book_id=} {saved_count=} duration_ms={(perf_counter() - "
f"started_at) * 1000:.1f}"
)
return saved_count
@@ -306,23 +280,16 @@ async def store_candidate_phrases_for_book(
await session.flush()
saved_count = len(rows)
logger.info(
"ebook_candidate_phrase_save_start book_id=%s candidates=%s mode=bulk_insert",
book_id,
len(limited_candidates),
f"ebook_candidate_phrase_save_start {book_id=} candidates={len(limited_candidates)} mode=bulk_insert"
)
else:
pruned_count = await prune_unstorable_unjudged_candidate_phrases(session, book_id, config)
logger.info(
"ebook_candidate_phrase_save_start book_id=%s candidates=%s pruned_unstorable=%s",
book_id,
len(limited_candidates),
pruned_count,
f"ebook_candidate_phrase_save_start {book_id=} candidates={len(limited_candidates)} {pruned_count=}"
)
saved_count = await bulk_upsert_unjudged_candidates(session, book_id, series_id, limited_candidates)
logger.info(
"ebook_candidate_phrase_save_complete book_id=%s candidates=%s save_ms=%.1f",
book_id,
saved_count,
(perf_counter() - save_started_at) * 1000,
f"ebook_candidate_phrase_save_complete {book_id=} {saved_count=} save_ms={(perf_counter() - save_started_at) * "
f"1000:.1f}"
)
return saved_count
python/ebook_search/protected_phrases/judge_ngrams.py
+21 -61
View File
@@ -80,12 +80,8 @@ async def judge_candidate_phrases_for_books(
book_workers = max(1, config.phrase_judge_book_workers)
phrase_workers = max(1, config.phrase_judge_phrase_workers)
logger.info(
"ebook_candidate_phrase_judgment_start books_seen=%s book_workers=%s phrase_workers=%s "
"confidence_threshold=%.2f",
books_seen,
book_workers,
phrase_workers,
config.protected_phrase_confidence_threshold,
f"ebook_candidate_phrase_judgment_start {books_seen=} {book_workers=} {phrase_workers=} "
f"{config.protected_phrase_confidence_threshold=:.2f}"
)
book_semaphore = asyncio.Semaphore(book_workers)
@@ -105,14 +101,8 @@ async def judge_candidate_phrases_for_books(
phrase_mentions=sum(outcome.mentions for outcome in outcomes),
)
logger.info(
"ebook_candidate_phrase_judgment_complete books_seen=%s books_judged=%s books_failed=%s "
"candidates_judged=%s protected=%s mentions=%s",
result.books_seen,
result.books_judged,
result.books_failed,
result.candidates_judged,
result.protected_phrases,
result.phrase_mentions,
f"ebook_candidate_phrase_judgment_complete {result.books_seen=} {result.books_judged=} {result.books_failed=} "
f"{result.candidates_judged=} {result.protected_phrases=} {result.phrase_mentions=}"
)
return result
@@ -147,7 +137,7 @@ async def judge_one_book_async(
return BookJudgmentResult()
return await persist_book_judgments(engine, source_id, config, judged)
except Exception:
logger.exception("ebook_candidate_phrase_judgment_book_failed source_id=%s", source_id)
logger.exception(f"ebook_candidate_phrase_judgment_book_failed {source_id=}")
return BookJudgmentResult(failed=True)
@@ -173,7 +163,7 @@ async def prepare_book_judgment(
return None
async with AsyncSession(engine) as session:
if not await count_unjudged_candidates(session, source_id, config):
logger.info("ebook_candidate_phrase_judgment_book_skip_no_unjudged source_id=%s", source_id)
logger.info(f"ebook_candidate_phrase_judgment_book_skip_no_unjudged {source_id=}")
return None
existing_protected = await count_protected_phrases(session, source_id)
target_remaining: int | None = None
@@ -181,15 +171,13 @@ async def prepare_book_judgment(
target_remaining = max(config.phrase_target_protected_per_book - existing_protected, 0)
if target_remaining == 0:
logger.info(
"ebook_candidate_phrase_judgment_skipped_target_met source_id=%s existing_protected=%s target=%s",
source_id,
existing_protected,
config.phrase_target_protected_per_book,
f"ebook_candidate_phrase_judgment_skipped_target_met {source_id=} {existing_protected=} "
f"{config.phrase_target_protected_per_book=}"
)
return None
book_text = await load_book_text(session, source_id)
if not book_text:
logger.warning("ebook_candidate_phrase_judgment_book_empty source_id=%s", source_id)
logger.warning(f"ebook_candidate_phrase_judgment_book_empty {source_id=}")
return None
normalized_book_text = normalize_text(book_text)
# Stored rows may predate the current junk filters and score weights, so re-filter and
@@ -211,15 +199,8 @@ async def prepare_book_judgment(
normalized_book_text, candidate.phrase_norm
)
logger.info(
"ebook_candidate_phrase_judgment_candidates_loaded source_id=%s candidates=%s skipped_junk=%s "
"unjudged_rows=%s existing_protected=%s target_remaining=%s judgment_limit=%s",
source_id,
len(work_items),
skipped_junk,
len(rows),
existing_protected,
target_remaining,
judgment_limit,
f"ebook_candidate_phrase_judgment_candidates_loaded {source_id=} candidates={len(work_items)} {skipped_junk=} "
f"unjudged_rows={len(rows)} {existing_protected=} {target_remaining=} {judgment_limit=}"
)
return work_items, target_remaining
@@ -313,31 +294,20 @@ async def persist_book_judgments(
await upsert_protected_phrase(session, source_id, None, candidate, judgment, candidate_row)
)
logger.info(
"ebook_candidate_phrase_judgment_candidate_complete source_id=%s candidate_id=%s phrase=%r "
"keep=%s confidence=%.3f category=%r promoted=%s",
source_id,
candidate_id,
candidate.phrase_norm,
judgment.keep,
judgment.confidence,
judgment.category,
promote,
f"ebook_candidate_phrase_judgment_candidate_complete {source_id=} {candidate_id=} "
f"{candidate.phrase_norm=} {judgment.keep=} {judgment.confidence=:.3f} {judgment.category=} "
f"{promote=}"
)
await session.flush()
mentions = await index_chunk_phrase_mentions_for_book(session, source_id, config) if protected else 0
await session.commit()
except Exception:
await session.rollback()
logger.exception("ebook_candidate_phrase_judgment_book_persist_failed source_id=%s", source_id)
logger.exception(f"ebook_candidate_phrase_judgment_book_persist_failed {source_id=}")
return BookJudgmentResult(failed=True)
logger.info(
"ebook_candidate_phrase_judgment_book_committed source_id=%s judged=%s protected=%s mentions=%s "
"duration_ms=%.1f",
source_id,
len(judged),
len(protected),
mentions,
(perf_counter() - book_started_at) * 1000,
f"ebook_candidate_phrase_judgment_book_committed {source_id=} judged={len(judged)} protected={len(protected)} "
f"{mentions=} duration_ms={(perf_counter() - book_started_at) * 1000:.1f}"
)
return BookJudgmentResult(judged=len(judged), protected=len(protected), mentions=mentions, committed=True)
@@ -369,24 +339,14 @@ def should_protect_judged_candidate(
accepted_token_count = len(accepted_tokens)
if accepted_token_count < config.phrase_min_tokens:
logger.info(
"ebook_candidate_phrase_judgment_candidate_skip_short_canonical book_id=%s candidate_id=%s "
"phrase=%r canonical=%r token_count=%s min_tokens=%s",
book_id,
candidate_id,
candidate.phrase_norm,
accepted_norm,
accepted_token_count,
config.phrase_min_tokens,
f"ebook_candidate_phrase_judgment_candidate_skip_short_canonical {book_id=} {candidate_id=} "
f"{candidate.phrase_norm=} {accepted_norm=} {accepted_token_count=} {config.phrase_min_tokens=}"
)
return False
if is_most_common_word_phrase(accepted_tokens):
logger.info(
"ebook_candidate_phrase_judgment_candidate_skip_common_canonical book_id=%s candidate_id=%s "
"phrase=%r canonical=%r",
book_id,
candidate_id,
candidate.phrase_norm,
accepted_norm,
f"ebook_candidate_phrase_judgment_candidate_skip_common_canonical {book_id=} {candidate_id=} "
f"{candidate.phrase_norm=} {accepted_norm=}"
)
return False
return True
python/ebook_search/protected_phrases/matching.py
+1 -1
View File
@@ -393,7 +393,7 @@ async def index_chunk_phrase_mentions_for_book(
for chunk in chunks:
count += await index_chunk_phrase_mentions(session, chunk, lookup=active_lookup)
await session.flush()
logger.info("ebook_chunk_phrase_mentions_indexed book_id=%s mentions=%s", book_id, count)
logger.info(f"ebook_chunk_phrase_mentions_indexed {book_id=} {count=}")
return count
python/ebook_search/protected_phrases/pool.py
+1 -1
View File
@@ -45,7 +45,7 @@ def get_extraction_pool(max_workers: int) -> ProcessPoolExecutor:
max_workers=workers,
mp_context=multiprocessing.get_context("spawn"),
)
logger.info("ebook_phrase_extraction_pool_started workers=%s", workers)
logger.info(f"ebook_phrase_extraction_pool_started {workers=}")
return _extraction_pool.pool
python/ebook_search/protected_phrases/store.py
+4 -11
View File
@@ -615,11 +615,8 @@ async def prune_unstorable_unjudged_candidate_phrases(
)
if deleted:
logger.info(
"ebook_candidate_phrase_unstorable_pruned book_id=%s deleted=%s min_tokens=%s min_uses=%s",
book_id,
deleted,
config.phrase_min_tokens,
minimum_candidate_raw_count(config),
f"ebook_candidate_phrase_unstorable_pruned {book_id=} {deleted=} {config.phrase_min_tokens=} "
f"min_uses={minimum_candidate_raw_count(config)}"
)
return deleted
@@ -661,12 +658,8 @@ async def delete_phrase_data_for_book(session: AsyncSession, book_id: int) -> Ph
)
await session.flush()
logger.info(
"ebook_candidate_phrase_data_deleted book_id=%s candidates=%s protected=%s aliases=%s mentions=%s",
book_id,
deleted_candidates,
deleted_protected,
deleted_aliases,
deleted_mentions,
f"ebook_candidate_phrase_data_deleted {book_id=} {deleted_candidates=} {deleted_protected=} {deleted_aliases=} "
f"{deleted_mentions=}"
)
return PhraseRecalculationResult(
book_id=book_id,