Merge pull request #36 from ethanstoner/feat/query-sources

logging, a query source without an LLM, multi-account and docker

src/accounts.py

@@ -0,0 +1,111 @@
+"""Which accounts a run works through.
+
+Rewards is per Microsoft account, and the browser profile is what holds the
+sign-in, so an account here is just a profile directory. One directory per
+account keeps their cookies apart, which is the whole requirement.
+
+    REWARDS_ACCOUNTS=personal,spare python src/main.py
+
+Unset, the run uses the single profile in constants.py exactly as before, so
+nothing about an existing setup changes.
+"""
+
+import os
+import re
+from dataclasses import dataclass
+
+from constants import USER_DATA_DIR, PROFILE_NAME
+
+ENV_VAR = "REWARDS_ACCOUNTS"
+
+# Names become directory names, so keep them to something a filesystem and a
+# command line both handle without quoting. The character set alone is not
+# enough: "." and ".." are made of allowed characters and still walk out of the
+# directory, so they are rejected by name below and the resolved path is
+# checked as well.
+SAFE_NAME = re.compile(r"^[A-Za-z0-9._-]+$")
+
+# Reserved by every filesystem that has directories at all.
+RESERVED_NAMES = {".", ".."}
+
+
+@dataclass(frozen=True)
+class Account:
+	"""A named browser profile to run the tasks against."""
+
+	name: str
+	user_data_dir: str
+	profile_name: str
+
+	@property
+	def is_default(self) -> bool:
+		return self.user_data_dir == USER_DATA_DIR
+
+
+def _named(name: str) -> Account:
+	# Each account gets its own directory under the configured one, so the
+	# existing data-dir stays where it is and the new ones sit beside the
+	# profile it already holds.
+	user_data_dir = os.path.join(USER_DATA_DIR, name)
+
+	# The name passed the character check, but that only constrains the
+	# characters, not where they end up pointing. Confirm against the resolved
+	# path, which is the thing Edge is actually handed. realpath rather than
+	# abspath, so a link or a junction under the profile directory is followed
+	# to where it really goes instead of being taken at face value.
+	root = os.path.realpath(USER_DATA_DIR)
+	resolved = os.path.realpath(user_data_dir)
+
+	if os.path.commonpath([root, resolved]) != root or resolved == root:
+		raise ValueError(
+			f"{ENV_VAR} entry {name!r} resolves outside the profile directory"
+		)
+
+	return Account(
+		name=name,
+		user_data_dir=user_data_dir,
+		profile_name=PROFILE_NAME,
+	)
+
+
+def configured() -> list[Account]:
+	"""Accounts for this run, in order.
+
+	Raises ValueError on a name that cannot be a directory, rather than
+	silently creating something surprising next to the real profiles.
+	"""
+	raw = os.environ.get(ENV_VAR, "").strip()
+
+	if not raw:
+		return [Account(name="default", user_data_dir=USER_DATA_DIR, profile_name=PROFILE_NAME)]
+
+	names = [part.strip() for part in raw.split(",")]
+	names = [name for name in names if name]
+
+	if not names:
+		return [Account(name="default", user_data_dir=USER_DATA_DIR, profile_name=PROFILE_NAME)]
+
+	seen: set[str] = set()
+	accounts: list[Account] = []
+
+	for name in names:
+		# The trailing dot is not cosmetic. Win32 strips one off a path
+		# component and python's normalisation does not, so such a name means a
+		# different directory than it reads as: "work." is "work", and "..." is
+		# the profile directory itself. Either way two entries end up sharing
+		# one profile, which is the one thing this module exists to prevent.
+		if not SAFE_NAME.match(name) or name in RESERVED_NAMES or name.endswith("."):
+			raise ValueError(
+				f"{ENV_VAR} entry {name!r} is not usable as a directory name; "
+				"use letters, digits, dot, dash or underscore, and do not end in a dot"
+			)
+
+		# Duplicates would run the same profile twice, which earns nothing the
+		# second time and doubles the run length.
+		if name.lower() in seen:
+			continue
+
+		seen.add(name.lower())
+		accounts.append(_named(name))
+
+	return accounts

src/llm_utils.py

@@ -1,7 +1,10 @@
 from typing import Generator
+import logging
 import random
 import ollama
 
+logger = logging.getLogger(__name__)
+
 DEFAULT_SYSTEM_PROMPT_FOR_SEARCH_QUEST = (
 	"You are a helpful assistant tasked with creating a search query based on a directive. "
 	"Output nothing but the search query you create, and do not include any additional commentary or explanation. "
@@ -55,7 +58,7 @@ def get_nonempty_ollama_response(messages: list[dict[str, str]]) -> str:
 		if response and response.strip():
 			return response
 
-		print(f"[WARNING] Empty LLM response, retry {attempt + 1}/{MAX_EMPTY_RETRIES}")
+		logger.warning("Empty LLM response, retry %s/%s", attempt + 1, MAX_EMPTY_RETRIES)
 
 	raise RuntimeError(f"LLM returned nothing usable after {MAX_EMPTY_RETRIES} attempts")
 

src/log_utils.py

@@ -0,0 +1,131 @@
+"""Central logging configuration.
+
+`setup_logging` is called once from `main.py`. Every other module just does
+`logger = logging.getLogger(__name__)` at import time, which is safe to do
+before this runs, so import order does not matter.
+"""
+
+import logging
+import os
+import re
+import sys
+
+LEVEL_ENV_VAR = "REWARDS_FARMER_LOG_LEVEL"
+FILE_ENV_VAR = "REWARDS_FARMER_LOG_FILE"
+
+DEFAULT_LEVEL = "INFO"
+
+# Configuring the root logger switches on output for every library that logs,
+# not just ours. httpx emits an info line per ollama call, which buries the
+# task summary and puts the ollama endpoint in the log file. print never did
+# this because it never touched logging at all, so leaving these at their
+# default would make the output noisier than what it replaces.
+NOISY_LIBRARIES = ("httpx", "httpcore", "urllib3", "selenium")
+
+# Longest a one-line exception summary may get before it is cut. Long enough
+# for any real selenium message, short enough that a pathological one cannot
+# push a whole screen of text into a single record.
+MAX_SUMMARY_LENGTH = 300
+
+_SESSION_INFO = re.compile(r"\s*\(Session info:[^)]*\)")
+
+
+def exception_summary(exc: BaseException) -> str:
+	"""One short line describing an exception, safe to put in a log record.
+
+	str() on a selenium exception is multi-line: the message, then a session
+	info line, then the whole msedgedriver stacktrace. Only the first line is
+	worth showing in a per-task summary, and the full detail is still attached
+	as a traceback when the level is debug.
+	"""
+	text = str(exc).strip()
+
+	if not text:
+		return ""
+
+	text = _SESSION_INFO.sub("", text.splitlines()[0]).strip()
+
+	if len(text) > MAX_SUMMARY_LENGTH:
+		# ASCII, because this can land on a Windows console whose encoding
+		# cannot represent an ellipsis character.
+		text = text[:MAX_SUMMARY_LENGTH - 3].rstrip() + "..."
+
+	return text
+
+# CRITICAL is the longest level name at 8 characters, so pad to that and the
+# message column stays aligned no matter what is being logged.
+LOG_FORMAT = "%(asctime)s %(levelname)-8s %(name)s: %(message)s"
+DATE_FORMAT = "%H:%M:%S"
+
+_configured = False
+
+
+def _resolve_level(level: str | int | None) -> int:
+	"""Turn a level name, a level number or None into a level number.
+
+	An unusable value falls back to the default rather than raising. A typo in
+	an environment variable must not be able to take down an unattended run.
+	"""
+	if level is None:
+		level = os.environ.get(LEVEL_ENV_VAR, DEFAULT_LEVEL)
+
+	if isinstance(level, int):
+		return level
+
+	resolved = logging.getLevelNamesMapping().get(str(level).strip().upper())
+
+	if resolved is None:
+		logging.getLogger(__name__).warning(
+			"Unknown log level %r, falling back to %s", level, DEFAULT_LEVEL
+		)
+
+		return logging.getLevelNamesMapping()[DEFAULT_LEVEL]
+
+	return resolved
+
+
+def setup_logging(level: str | int | None = None, log_file: str | None = None) -> None:
+	"""Configure the root logger. Calling this more than once is a no-op.
+
+	`level` defaults to $REWARDS_FARMER_LOG_LEVEL, then to INFO.
+	`log_file` defaults to $REWARDS_FARMER_LOG_FILE, and no file is written
+	when neither is set.
+	"""
+	global _configured
+
+	if _configured:
+		return
+
+	root = logging.getLogger()
+	root.setLevel(_resolve_level(level))
+
+	formatter = logging.Formatter(LOG_FORMAT, datefmt=DATE_FORMAT)
+
+	# Card descriptions are scraped from the page and are not ASCII outside the
+	# en-US market, which the Windows console encoding cannot represent. Replace
+	# those characters instead of letting the write raise.
+	if hasattr(sys.stdout, "reconfigure"):
+		sys.stdout.reconfigure(errors="replace")
+
+	# stdout rather than the StreamHandler default of stderr, because this
+	# replaces print and anyone already redirecting stdout to a file should
+	# keep getting the same output there.
+	console = logging.StreamHandler(sys.stdout)
+	console.setFormatter(formatter)
+	root.addHandler(console)
+
+	if log_file is None:
+		log_file = os.environ.get(FILE_ENV_VAR)
+
+	if log_file:
+		# utf-8 explicitly. Card descriptions are scraped from the page and are
+		# not ASCII outside the en-US market, and the Windows default encoding
+		# would raise on them.
+		file_handler = logging.FileHandler(log_file, encoding="utf-8")
+		file_handler.setFormatter(formatter)
+		root.addHandler(file_handler)
+
+	for name in NOISY_LIBRARIES:
+		logging.getLogger(name).setLevel(logging.WARNING)
+
+	_configured = True

src/main.py

@@ -1,26 +1,115 @@
+import logging
+import os
+import sys
+
+import log_utils
+import accounts
 import rewards_tasks
-import mouse_trajectory
-import mimic_typing
 from selenium import webdriver
-from constants import USER_DATA_DIR, PROFILE_NAME
+from selenium.common.exceptions import SessionNotCreatedException
 
-options = webdriver.EdgeOptions()
+HEADLESS = os.environ.get("REWARDS_HEADLESS", "").strip().lower() in ("1", "true", "yes")
 
-options.add_experimental_option("excludeSwitches", ["enable-automation"])
-options.add_experimental_option('useAutomationExtension', False)
-options.add_argument("--disable-blink-features=AutomationControlled")
-options.add_argument(f"--user-data-dir={USER_DATA_DIR}")
-options.add_argument(f"--profile-directory={PROFILE_NAME}")
+logger = logging.getLogger(__name__)
 
-driver = webdriver.Edge(options=options)
 
-mouse = mouse_trajectory.MouseUtils(driver)
-keyboard = mimic_typing.KeyboardUtils(driver)
+def build_options(account: accounts.Account) -> webdriver.EdgeOptions:
+	options = webdriver.EdgeOptions()
 
-rewards = rewards_tasks.RewardsTaskUtils(driver)
+	options.add_experimental_option("excludeSwitches", ["enable-automation"])
+	options.add_experimental_option('useAutomationExtension', False)
+	options.add_argument("--disable-blink-features=AutomationControlled")
+	options.add_argument(f"--user-data-dir={account.user_data_dir}")
+	options.add_argument(f"--profile-directory={account.profile_name}")
 
-rewards.complete_all_tasks()
+	if HEADLESS:
+		# A container has no display. The window size is set explicitly because
+		# the pointer code works in viewport coordinates, and the default
+		# headless window is small enough to put cards out of reach.
+		options.add_argument("--headless=new")
+		options.add_argument("--window-size=1920,1080")
+		options.add_argument("--no-sandbox")
+		options.add_argument("--disable-dev-shm-usage")
 
-input("Press Enter to exit...")
+	return options
 
-driver.quit()
+
+def run_account(account: accounts.Account) -> bool:
+	"""Work one account. Returns whether the browser started."""
+	try:
+		driver = webdriver.Edge(options=build_options(account))
+	except SessionNotCreatedException as exc:
+		# Chromium allows one process per user data directory. When the profile
+		# is already open the driver's copy exits during startup, and selenium
+		# reports it as the browser crashing with a message that names neither
+		# the profile nor the other window.
+		logger.error("[FAIL] %s: could not start Edge with this profile.", account.name)
+		logger.error("       profile directory: %s", account.user_data_dir)
+		logger.error("       The usual cause is that this profile is already open in another")
+		logger.error("       Edge window, including one left over from a previous run.")
+		logger.error("       driver said: %s", log_utils.exception_summary(exc))
+
+		return False
+
+	try:
+		rewards = rewards_tasks.RewardsTaskUtils(driver)
+		rewards.complete_all_tasks()
+	finally:
+		try:
+			driver.quit()
+		except Exception as exc:
+			# quit() raises when the browser is already gone. Letting it out
+			# here would replace whatever actually went wrong with the tidy-up's
+			# own error, and the process it is meant to end is dead anyway.
+			logger.warning(
+				"%s: the driver did not shut down cleanly: %s",
+				account.name, log_utils.exception_summary(exc)
+			)
+
+	return True
+
+
+def main() -> int:
+	log_utils.setup_logging()
+
+	try:
+		configured = accounts.configured()
+	except ValueError as exc:
+		logger.error("[FAIL] %s", exc)
+
+		return 2
+
+	started = 0
+
+	for account in configured:
+		if len(configured) > 1:
+			logger.info("=== account: %s ===", account.name)
+
+		# One account must not be able to end the batch. complete_all_tasks
+		# already contains a task that fails, and run_account names the profile
+		# that is already open, but everything else - a driver that will not
+		# start for some other reason, the browser dying mid-run, a page that
+		# never loads - reached here and took the remaining accounts with it.
+		# KeyboardInterrupt is deliberately not caught: Ctrl-C means stop.
+		try:
+			if run_account(account):
+				started += 1
+		except Exception as exc:
+			logger.error(
+				"[FAIL] %s: %s: %s",
+				account.name, type(exc).__name__, log_utils.exception_summary(exc),
+				exc_info=logger.isEnabledFor(logging.DEBUG)
+			)
+
+	if len(configured) > 1:
+		logger.info("%s/%s accounts ran", started, len(configured))
+
+	# Nothing is watching a container, and stdin is not a terminal there.
+	if not HEADLESS:
+		input("Press Enter to exit...")
+
+	return 0 if started else 1
+
+
+if __name__ == "__main__":
+	sys.exit(main())

src/queries.py

@@ -0,0 +1,76 @@
+"""Where search queries come from.
+
+Two backends. `llm` is the default and is unchanged, so nothing about an
+existing setup moves. `trends` uses public feeds and needs no account, no
+model and no key, which is the difference between running this in five
+minutes and installing Ollama first.
+
+    QUERY_SOURCE=trends python src/main.py
+
+The LLM's whole job in this project is producing short strings to type into
+Bing, and Bing's own autosuggest answers that question directly.
+"""
+
+import logging
+import os
+
+import query_sources
+
+# llm_utils is imported inside the llm branch rather than here. It imports
+# ollama at module scope, so importing it eagerly would make the ollama package
+# a hard requirement even for a run that never touches a model, which is the
+# opposite of the point. A trends-only install, the Docker image for instance,
+# does not ship it.
+
+logger = logging.getLogger(__name__)
+
+LLM = "llm"
+TRENDS = "trends"
+
+DEFAULT_SOURCE = LLM
+
+ENV_VAR = "QUERY_SOURCE"
+
+
+def selected_source() -> str:
+	"""Read on each call so a test can change it without reimporting."""
+	choice = os.environ.get(ENV_VAR, DEFAULT_SOURCE).strip().lower()
+
+	return choice if choice in (LLM, TRENDS) else DEFAULT_SOURCE
+
+
+def search_query_for_task(task_description: str) -> str:
+	"""A query for one "Search on Bing for X" card."""
+	if selected_source() == TRENDS:
+		query = query_sources.query_from_task_description(task_description)
+
+		if query:
+			return query
+
+		# Every feed was unreachable. The description still contains the topic,
+		# so a trimmed version beats skipping the card entirely.
+		logger.warning("No query source reachable, using the lowercased task description.")
+
+		return task_description.lower()
+
+	import llm_utils
+
+	return llm_utils.get_search_query_from_task_description(task_description)
+
+
+def related_queries(count: int):
+	"""`count` queries for the daily search quota."""
+	if selected_source() == TRENDS:
+		queries = query_sources.related_queries(count)
+
+		if queries:
+			return queries
+
+		logger.warning("No query source reachable, falling back to the wordlist.")
+
+		# nouns.txt is already in the repo for exactly this kind of seed.
+		return query_sources.wordlist_queries(count)
+
+	import llm_utils
+
+	return llm_utils.get_related_search_queries(llm_utils.get_random_noun(), num_queries=count)

src/query_sources.py

@@ -0,0 +1,216 @@
+"""Search queries from public feeds instead of a language model.
+
+The LLM in this project has one job: produce short strings to type into Bing.
+That is worth an Ollama account and a model download if you want it, but it is
+not the only way to get a search query, and it is the piece that stops someone
+running the bot in five minutes.
+
+Three keyless sources, all stdlib, no new dependencies:
+
+  Google Trends RSS   real queries people are typing right now
+  Wikipedia most-read topic seeds, useful when trends is unavailable
+  Bing autosuggest    expands a seed into related queries
+
+Autosuggest is what makes the chaining work. Asking Bing what follows a term
+gives queries Bing itself expects, which is closer to what the LLM prompt was
+reaching for than a model guessing in the dark.
+
+Every source degrades rather than raises. A search that does not happen costs
+points; a run that dies costs the rest of the day's points too.
+"""
+
+import json
+import random
+import re
+import urllib.error
+import urllib.parse
+import urllib.request
+from datetime import date, timedelta
+
+TRENDS_URL = "https://trends.google.com/trending/rss?geo={geo}"
+WIKIPEDIA_URL = "https://en.wikipedia.org/api/rest_v1/feed/featured/{y}/{m:02d}/{d:02d}"
+AUTOSUGGEST_URL = "https://api.bing.com/osjson.aspx?query={query}"
+
+# A browser agent: trends and the Wikipedia REST feed both answer differently
+# to an unfamiliar client, and one of them refuses outright.
+USER_AGENT = (
+	"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 "
+	"(KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36"
+)
+
+REQUEST_TIMEOUT = 15
+
+# Words that make a query read as an instruction rather than a search. The
+# task descriptions are phrased at the user, "Search on Bing to compare
+# checking accounts", and typing that verbatim searches for the sentence.
+INSTRUCTION_WORDS = {
+	"search", "searching", "bing", "on", "to", "the", "a", "an", "for", "your",
+	"you", "use", "using", "find", "get", "with", "and", "or", "of", "in",
+	"at", "by", "now", "today", "this", "that", "these", "those", "learn",
+	"discover", "explore", "check", "see", "our", "more", "about", "how",
+}
+
+
+def _fetch(url: str) -> str | None:
+	"""Body of a GET, or None. Never raises: callers fall through to the next source."""
+	request = urllib.request.Request(url, headers={"User-Agent": USER_AGENT})
+
+	try:
+		with urllib.request.urlopen(request, timeout=REQUEST_TIMEOUT) as response:
+			return response.read().decode("utf-8", "replace")
+	except (urllib.error.URLError, urllib.error.HTTPError, OSError, ValueError):
+		return None
+
+
+def trending_queries(geo: str = "US") -> list[str]:
+	"""Queries currently trending on Google, most popular first.
+
+	These are real searches rather than descriptions of searches, which is
+	exactly the shape wanted here.
+	"""
+	body = _fetch(TRENDS_URL.format(geo=urllib.parse.quote(geo)))
+
+	if not body:
+		return []
+
+	# The channel carries a <title> of its own before any item, so the first
+	# match is the feed name rather than a query.
+	titles = re.findall(r"<title>(?:<!\[CDATA\[)?(.*?)(?:\]\]>)?</title>", body, re.S)
+
+	return [_clean(t) for t in titles[1:] if _clean(t)]
+
+
+def wikipedia_topics(days_ago: int = 1) -> list[str]:
+	"""Most-read Wikipedia articles, as topic seeds.
+
+	Yesterday by default: today's feed is not published until the day is over.
+	"""
+	day = date.today() - timedelta(days=days_ago)
+	body = _fetch(WIKIPEDIA_URL.format(y=day.year, m=day.month, d=day.day))
+
+	if not body:
+		return []
+
+	try:
+		payload = json.loads(body)
+	except json.JSONDecodeError:
+		return []
+
+	articles = payload.get("mostread", {}).get("articles", [])
+	titles = [a.get("titles", {}).get("normalized", "") for a in articles]
+
+	# Wikipedia's own chrome outranks real topics most days.
+	skipped = ("Main Page", "Special:", "Wikipedia:", "Portal:")
+
+	return [
+		_clean(t) for t in titles
+		if t and not t.startswith(skipped) and _clean(t)
+	]
+
+
+def suggestions(seed: str) -> list[str]:
+	"""What Bing suggests for a term, which is what Bing expects to be asked."""
+	if not seed.strip():
+		return []
+
+	body = _fetch(AUTOSUGGEST_URL.format(query=urllib.parse.quote(seed)))
+
+	if not body:
+		return []
+
+	try:
+		payload = json.loads(body)
+	except json.JSONDecodeError:
+		return []
+
+	# Opensearch shape: [term, [suggestions], ...]
+	if not isinstance(payload, list) or len(payload) < 2 or not isinstance(payload[1], list):
+		return []
+
+	return [_clean(s) for s in payload[1] if _clean(s)]
+
+
+def wordlist_queries(count: int) -> list[str]:
+	"""Seeds from nouns.txt, the last resort when nothing is reachable.
+
+	Read here rather than borrowed from llm_utils so that a trends-only install
+	never has to import the model client.
+	"""
+	try:
+		with open("nouns.txt", encoding="utf-8") as handle:
+			nouns = [line.strip().lower() for line in handle if len(line.strip()) >= 3]
+	except OSError:
+		return []
+
+	if not nouns:
+		return []
+
+	return random.sample(nouns, min(count, len(nouns)))
+
+
+def _clean(text: str) -> str:
+	"""Strip markup, collapse whitespace and drop punctuation Bing does not need."""
+	text = re.sub(r"<[^>]+>", " ", text or "")
+	text = re.sub(r"[\"'?!,;:]", " ", text)
+
+	return " ".join(text.split()).strip().lower()
+
+
+def query_from_task_description(description: str) -> str | None:
+	"""A search query for a task phrased as an instruction.
+
+	"Search on Bing to compare checking and savings account options" becomes
+	the content words, then whatever Bing suggests for them, so the query is
+	one Bing already recognises rather than the sentence itself.
+	"""
+	words = [w for w in _clean(description).split() if w not in INSTRUCTION_WORDS]
+
+	if not words:
+		return None
+
+	seed = " ".join(words[:6])
+	options = suggestions(seed)
+
+	# Prefer a suggestion, since it is a query Bing has seen. The trimmed
+	# sentence is a reasonable fallback and still beats typing the imperative.
+	return options[0] if options else seed
+
+
+def related_queries(count: int, seed: str | None = None) -> list[str]:
+	"""`count` distinct queries, branching out the way the LLM prompt asks for.
+
+	Trending queries first, since they need no expansion at all, then Bing's
+	suggestions for each to reach the requested number.
+	"""
+	collected: list[str] = []
+	seen: set[str] = set()
+
+	def take(candidates):
+		for candidate in candidates:
+			if candidate and candidate not in seen and len(candidate) > 2:
+				seen.add(candidate)
+				collected.append(candidate)
+
+				if len(collected) >= count:
+					return True
+		return False
+
+	if seed:
+		take(suggestions(seed))
+
+	if len(collected) < count and take(trending_queries()):
+		return collected[:count]
+
+	if len(collected) < count:
+		take(wikipedia_topics())
+
+	# Expand what we have until the count is met. Iterating over a snapshot
+	# because take() appends to the same list.
+	for term in list(collected):
+		if len(collected) >= count:
+			break
+
+		take(suggestions(term))
+
+	# Nothing reachable: let the caller decide, rather than typing junk.
+	return collected[:count]

src/rewards_tasks.py

@@ -1,3 +1,5 @@
+import logging
+import log_utils
 import os
 import random
 import time
@@ -9,13 +11,15 @@ from selenium.webdriver.common.keys import Keys
 from selenium.webdriver.remote.webelement import WebElement
 from selenium.common.exceptions import StaleElementReferenceException, TimeoutException, NoSuchElementException
 import tab_utils
-import llm_utils
+import queries
 import mouse_trajectory
 import mimic_typing
 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
@@ -77,7 +81,10 @@ class RewardsTaskUtils:
 		except TimeoutException:
 			daily_set_links = self.elements.get_daily_set_elements()
 
-			print(f"[WARNING] Daily set panel only shows {len(daily_set_links)} of {expected_activities} activities")
+			logger.warning(
+				"Daily set panel only shows %s of %s activities",
+				len(daily_set_links), expected_activities
+			)
 
 		# Re-read the panel per index: clicking an activity can re-render it and
 		# stale the captured references.
@@ -107,7 +114,7 @@ class RewardsTaskUtils:
 
 		for card in explore_on_bing_links:
 			desc = self.elements.extract_card_descriptions(card)
-			query = llm_utils.get_search_query_from_task_description(desc)
+			query = queries.search_query_for_task(desc)
 
 			self.move_to_and_click(card)
 			self.tab_utils.switch_to_other_tab()
@@ -127,7 +134,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()
@@ -164,7 +174,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()
 
@@ -179,7 +192,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:
@@ -193,16 +206,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."""
@@ -240,9 +256,7 @@ class RewardsTaskUtils:
 		# search bar should be auto-focused
 
 		for i, query in enumerate(
-			llm_utils.get_related_search_queries(
-				llm_utils.get_random_noun(), num_queries=count
-			)
+			queries.related_queries(count)
 		):
 			self.keyboard.send_keys(f"{query} -noai{Keys.ENTER}")
 
@@ -250,7 +264,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/")
@@ -264,7 +281,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
@@ -280,13 +297,19 @@ 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}")
+				logger.error(
+					"[FAIL] %s: %s: %s", name, type(exc).__name__, log_utils.exception_summary(exc),
+					exc_info=logger.isEnabledFor(logging.DEBUG)
+				)
 
 			# Leave a clean tab state behind for the next task.
 			try:

src/tab_utils.py

@@ -1,6 +1,9 @@
+import logging
 from selenium.common.exceptions import WebDriverException, JavascriptException, NoSuchWindowException
 from selenium import webdriver
 
+logger = logging.getLogger(__name__)
+
 GHOST_TAB_URLS = (
 	"https://ntp.msn.com/edge/ntp?locale=en-US&title=New%20tab&fre=1&dsp=1&sp=Bing&feed_dis=always&en_widget_reg=false&prerender=1&PC=U531", # has fre
 	"https://ntp.msn.com/edge/ntp?locale=en-US&title=New%20tab&dsp=1&sp=Bing&feed_dis=always&en_widget_reg=false&prerender=1&PC=U531" # no fre
@@ -30,7 +33,7 @@ document.dispatchEvent(new Event('visibilitychange'));
 				self.driver.switch_to.window(handle)
 
 				if self.driver.current_url in GHOST_TAB_URLS:
-					print(f"[INFO] Found ghost tab with handle {handle} and URL {self.driver.current_url}.")
+					logger.debug("Found ghost tab with handle %s and URL %s.", handle, self.driver.current_url)
 					continue
 
 				self.ensure_focus()
@@ -47,17 +50,21 @@ document.dispatchEvent(new Event('visibilitychange'));
 				self.driver.switch_to.window(handle)
 
 				if self.driver.current_url in GHOST_TAB_URLS:
-					print(f"[INFO] Found ghost tab with handle {handle} and URL {self.driver.current_url}, not closing.")
+					logger.debug("Found ghost tab with handle %s and URL %s, not closing.", handle, self.driver.current_url)
 					continue
 
 				tab_url = self.driver.current_url
 
 				try:
 					self.driver.close()
-					print(f"[INFO] Closed tab with handle {handle} and URL {tab_url}.")
+					# Routine bookkeeping, one line per tab. At info it drowned
+					# the task summary: 19 of the 33 records in a full run were
+					# these. The warning below stays at warning, a tab that will
+					# not close is a real problem.
+					logger.debug("Closed tab with handle %s and URL %s.", handle, tab_url)
 
 				except (WebDriverException, NoSuchWindowException):
-					print(f"[WARNING] Could not close tab with handle {handle} and URL {tab_url}.")
+					logger.warning("Could not close tab with handle %s and URL %s.", handle, tab_url)
 					self.problematic_tabs.add(handle)
 					pass