switch the bot runtime from print to logging

Closes #14.

The runtime modules now log through the stdlib logging module. A new
log_utils.setup_logging is called once from main.py, and each module holds
its own logging.getLogger(__name__) so every line says which module it came
from.

The [INFO] and [WARNING] prefixes are gone, since the level field carries
that now. [OK], [SKIP] and [FAIL] stay in the message text: they are the
per-task outcome summary from complete_all_tasks rather than severities, and
folding them into the level would erase the run summary. They map to info,
warning and error, which is the one thing print could not express, a real
failure now sorts above a task the current UI variant simply does not ship.

Two things fall out of having levels at all:

- REWARDS_FARMER_LOG_LEVEL=DEBUG attaches the traceback to every [FAIL],
  which is the stack trace that bug reports keep having to be asked for.
- REWARDS_FARMER_LOG_FILE writes the same output to a file, so an unattended
  run can be read after the fact.

Both are off by default, so a normal run looks the same as before apart from
the timestamp and level columns.

The [FAIL] summary keeps only the first line of the exception message. A
selenium exception carries the whole msedgedriver stacktrace inside str(),
tens of lines of it, which would turn one task into one screenful and make
the log file impossible to scan. The full detail is still there with the
traceback on debug.

The console stream is stdout rather than the StreamHandler default of stderr,
so anyone already redirecting stdout keeps getting the output there, and its
error handler is set to replace. Card descriptions are scraped from the page
and are not ASCII outside the en-US market, and the Windows console encoding
raises on them.

check_selectors.py, fitts_law.py and analyze_keypresses.py are left on print.
Their output is formatted report text, and prefixing every row of a
diagnostic table with a timestamp and a level makes it harder to read.
This commit is contained in:
Ethan Stoner
2026-08-26 11:12:20 -07:00
parent e2a06275f3
commit 5c475cab05
7 changed files with 173 additions and 17 deletions
+37 -12
View File
@@ -1,3 +1,4 @@
import logging
import os
import random
import time
@@ -17,6 +18,8 @@ import element_selectors
VISUAL_SEARCH_IMAGE_PATH = os.path.abspath("visual_search.jpg")
logger = logging.getLogger(__name__)
class RewardsTaskUtils:
def __init__(self, driver: webdriver.Edge):
self.driver = driver
@@ -113,7 +116,10 @@ class RewardsTaskUtils:
for card in explore_on_bing_links:
if not self.elements.card_is_complete(card):
print(f"[WARNING] Explore on Bing Card [desc={self.elements.extract_card_descriptions(card)!r}] is not complete after searching. Please check manually.")
logger.warning(
"Explore on Bing Card [desc=%r] is not complete after searching. Please check manually.",
self.elements.extract_card_descriptions(card)
)
def complete_visual_search(self):
self.switch_to_earn_page()
@@ -154,7 +160,10 @@ class RewardsTaskUtils:
for card in misc_cards:
if not self.elements.card_is_complete(card) and self.elements.get_card_point_value(card) > 0:
print(f"[WARNING] Misc Card [desc={self.elements.extract_card_descriptions(card)!r}] is not complete after clicking. Please check manually.")
logger.warning(
"Misc Card [desc=%r] is not complete after clicking. Please check manually.",
self.elements.extract_card_descriptions(card)
)
self.tab_utils.close_all_other_tabs()
@@ -170,7 +179,7 @@ class RewardsTaskUtils:
# Measure, search, measure again.
points_earned, max_pts = self.read_search_points()
print(f"[INFO] Search points before: {points_earned}/{max_pts}")
logger.info("Search points before: %s/%s", points_earned, max_pts)
for round_number in range(1, max_rounds + 1):
if points_earned >= max_pts:
@@ -184,16 +193,19 @@ class RewardsTaskUtils:
previous = points_earned
points_earned, max_pts = self.read_search_points()
print(f"[INFO] Round {round_number}: {searches} searches -> {points_earned}/{max_pts}")
logger.info(
"Round %s: %s searches -> %s/%s",
round_number, searches, points_earned, max_pts
)
if points_earned <= previous:
print("[WARNING] Round produced no points, stopping instead of searching pointlessly.")
logger.warning("Round produced no points, stopping instead of searching pointlessly.")
break
if points_earned < max_pts:
print(f"[WARNING] Search quota not filled: {points_earned}/{max_pts}")
logger.warning("Search quota not filled: %s/%s", points_earned, max_pts)
else:
print(f"Search quota complete: {points_earned}/{max_pts}")
logger.info("Search quota complete: %s/%s", points_earned, max_pts)
def read_search_points(self):
"""Open the points breakdown, read the Bing search row, close it again."""
@@ -230,7 +242,10 @@ class RewardsTaskUtils:
try: self.wait_for_then_click(self.elements.get_clear_bing_search_query_button)
except StaleElementReferenceException:
print(f"[WARNING] StaleElementReferenceException when trying to click the clear button for query {i+1}. Trying again...")
logger.warning(
"StaleElementReferenceException when trying to click the clear button for query %s. Trying again...",
i + 1
)
self.wait_for_then_click(self.elements.get_clear_bing_search_query_button)
self.driver.get("https://rewards.bing.com/")
@@ -244,7 +259,7 @@ class RewardsTaskUtils:
try:
self.wait_for_then_click(self.elements.get_claim_bonus_points_button)
except TimeoutException:
print("[WARNING] Could not find the 'Claim Bonus Points' button. There are likely no bonus points to claim at this time.")
logger.warning("Could not find the 'Claim Bonus Points' button. There are likely no bonus points to claim at this time.")
def complete_all_tasks(self):
# Each task is run independently. The Rewards UI differs by market and
@@ -260,13 +275,23 @@ class RewardsTaskUtils:
)
for name, step in steps:
# The tags stay in the message rather than being folded into the
# level, they are the per-task outcome summary and reading a run
# means scanning for them.
try:
step()
print(f"[OK] {name}")
logger.info("[OK] %s", name)
except (NoSuchElementException, TimeoutException) as exc:
print(f"[SKIP] {name}: not available in this UI variant ({type(exc).__name__})")
logger.warning("[SKIP] %s: not available in this UI variant (%s)", name, type(exc).__name__)
except Exception as exc:
print(f"[FAIL] {name}: {type(exc).__name__}: {exc}")
# A selenium exception carries the whole msedgedriver stacktrace
# in str(), tens of lines of it, so keep the summary to the
# first line and let the traceback on debug hold the rest.
message = str(exc).strip().splitlines()
logger.error(
"[FAIL] %s: %s: %s", name, type(exc).__name__, message[0] if message else "",
exc_info=logger.isEnabledFor(logging.DEBUG)
)
# Leave a clean tab state behind for the next task.
try: