diff --git a/CLAUDE.md b/CLAUDE.md index a7f4013..305533a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -659,6 +659,42 @@ paths; don't unify them. --- +## The town timeline — `grep "TOWN>"` + +Every town-maintenance step reports start and outcome in one stable, machine-readable +shape, so a whole town visit reads as a sequence: + +```bash +grep "TOWN>" log/log.txt +``` +``` +TOWN> g2 r2 | maintenance | start | at a5_town_start +TOWN> g2 r2 | town_heal | start +TOWN> g2 r2 | inspect_inventory | ok | in pack=0 keep=0 sell=0 gold_full=False +TOWN> g2 r2 | buy_consumables | start | needs id=0 tp=0 hp=4 mana=0 rejuv=0 | sell_pending=0 +TOWN> g2 r2 | buy_consumables | ok | at a4_jamella | after: Consumables(...) +TOWN> g2 r2 | stash_items | skip | nothing kept and gold not full +TOWN> g2 r2 | repair | skip | no repair due and nothing to sell +TOWN> g2 r2 | resurrect_merc | start +TOWN> g2 r2 | gamble | skip | stash not full / gambling not configured +TOWN> g2 r2 | maintenance | ok | done in 21s | at a4_jamella +``` + +- `status` is one of **start | ok | skip | fail**. `skip` says *why* it was skipped, so a + step that silently did nothing is now distinguishable from one that never ran. +- Individual item transfers mirror into the same stream from + `inventory/personal.py::transfer_items` as `item_sell` / `item_stash` / `item_drop`, so + vendoring a rare and stashing a rune appear inline with the steps around them. +- The `maintenance ok` line carries total duration — the fastest way to spot a slow town + visit. Example from the first run after this landed: `done in 225s` with + `buy_consumables | fail` versus `done in 21s` with `ok` the next game. + +Emitted by `_step()` inside `Bot.on_maintenance` (`src/bot.py`). **Keep the format stable** — +it is meant to be grepped, not read as prose. The `>` in the prefix matters: a bare `TOWN` +also matches template names like `A5_TOWN_0`. + +--- + ## Verifying a boss run actually worked Learned the hard way (Bug 24). Log lines and `failed:false` are **not** proof of a kill. diff --git a/src/bot.py b/src/bot.py index 617abd2..256700b 100644 --- a/src/bot.py +++ b/src/bot.py @@ -463,6 +463,25 @@ class Bot: return True return False + def _step(step: str, status: str = "start", detail: str = "") -> None: + """Emit one line of the town-maintenance timeline. + + Every step reports start and outcome in the same shape so a whole town visit + can be read (or grepped) as a sequence: + grep "TOWN>" log/log.txt + status is one of: start | ok | skip | fail. Keep the format stable — it is + meant to be machine-readable, not prose. + """ + if status == "start": + self._maintenance_step = step + gs = self._game_stats + head = f"TOWN> g{getattr(gs, '_game_counter', 0)} r{getattr(gs, '_run_counter', 0)} | {step:<16} | {status:<5}" + line = f"{head} | {detail}" if detail else head + (Logger.warning if status == "fail" else Logger.info)(line) + + self._step_fn = _step + _step("maintenance", "start", f"at {self._curr_loc}") + # Dismiss skill/quest/help/stats icon if they are on screen if not view.dismiss_skills_icon(): view.return_to_play() @@ -473,7 +492,7 @@ class Bot: # Drinks health first (cheaper), then rejuv as fallback if health is unavailable. # Happens before update_pot_needs so the reduced belt is accurately counted # and the buy step will restock whatever was drunk. - self._maintenance_step = "town_heal" + _step("town_heal") _town_heal_threshold = 0.95 _town_heal_max_drinks = 5 for _drink_attempt in range(_town_heal_max_drinks): @@ -501,7 +520,7 @@ class Bot: Logger.info(f"We are running trav and have full rejuvs so skipping {skipped_run}") # Inspect inventory - self._maintenance_step = "inspect_inventory" + _step("inspect_inventory") items = None need_inspect = self._picked_up_items or self._previous_run_failed if Config().char["runs_per_stash"]: @@ -535,21 +554,26 @@ class Bot: if any([item.need_id for item in items]): if _maint_timed_out("identify_items"): return Logger.info("ID items at cain") - self._maintenance_step = "identify_items" + _step("identify_items", "start", f"items needing id={sum(1 for i in items if getattr(i, 'need_id', False))}") self._curr_loc = self._town_manager.identify(self._curr_loc) if self._curr_loc is True: Logger.warning("identify() returned True (unexpected location) — re-detecting town act") self._curr_loc = self._verify_town_location() if not self._curr_loc: + _step("identify_items", "fail", "Cain not available — continuing unidentified") Logger.warning("Could not identify items (Cain not available). Continuing without ID.") self._curr_loc = self._verify_town_location() else: # recheck inventory items = personal.inspect_items(game_stats=self._game_stats) + _step("identify_items", "ok", f"at {self._curr_loc}") keep_items = any([item.keep for item in items]) if items else None sell_items = any([item.sell for item in items]) if items else None sell_count = sum(1 for item in items if item.sell) if items else 0 stash_gold = personal.get_inventory_gold_full() + _step("inspect_inventory", "ok", + f"in pack={len(items) if items else 0} keep={sum(1 for i in items if i.keep) if items else 0} " + f"sell={sell_count} gold_full={bool(stash_gold)}") # Check if should need some healing img = grab() @@ -573,7 +597,10 @@ class Bot: if need_refill or sell_count >= 3: if _maint_timed_out("buy_consumables"): return Logger.info("Buy consumables and/or sell items") - self._maintenance_step = "buy_consumables" + _step("buy_consumables", "start", + f"needs id={consumables.get_needs('id')} tp={consumables.get_needs('tp')} " + f"hp={consumables.get_needs('health')} mana={consumables.get_needs('mana')} " + f"rejuv={consumables.get_needs('rejuv')} | sell_pending={sell_count}") prev_buy_loc = self._curr_loc # A5 Malah is unreliable in the current patch (wandering NPC, stale body # templates — fails most games). Buy at A4 Jamella instead when in A5. @@ -592,6 +619,7 @@ class Bot: items = result_items sell_items = any([item.sell for item in items]) if items else None Logger.debug(f"Needs: {consumables.get_needs()}") + _step("buy_consumables", "ok", f"at {self._curr_loc} | after: {consumables.get_needs()}") else: Logger.warning("Buy consumables failed, retrying in current act") wait(0.5, 0.6) @@ -622,12 +650,13 @@ class Bot: # here — that skips the stash step and strands picked-up runes/items # in inventory forever. Re-anchor and fall through to stash. reason = "Buy consumables failed (vendor not found) — continuing to stash without buying" + _step("buy_consumables", "fail", "vendor not found after retries — continuing to stash") Logger.warning(reason) self._save_error_screenshot("maintenance", reason) self._curr_loc = self._verify_town_location(prev_buy_loc) elif meters.get_health(img) <= Config().char["take_rejuv_potion_health"] or meters.get_mana(img) <= Config().char["take_rejuv_potion_mana"]: Logger.info("Healing at next possible Vendor") - self._maintenance_step = "heal" + _step("heal") prev_heal_loc = self._curr_loc self._curr_loc = self._town_manager.heal(self._curr_loc) if not self._curr_loc: @@ -635,6 +664,7 @@ class Bot: wait(0.5, 0.6) self._curr_loc = self._town_manager.heal(self._verify_town_location(prev_heal_loc)) if not self._curr_loc: + _step("heal", "fail", "healer not reachable") Logger.warning("Heal failed after retry, continuing without heal") self._curr_loc = self._verify_town_location(prev_heal_loc) @@ -646,10 +676,12 @@ class Bot: belt.update_pot_needs() # Stash stuff + if not (keep_items or stash_gold): + _step("stash_items", "skip", "nothing kept and gold not full") if keep_items or stash_gold: if _maint_timed_out("stash_items"): return Logger.info("Stashing items") - self._maintenance_step = "stash_items" + _step("stash_items", "start", f"keep_items={bool(keep_items)} gold_full={bool(stash_gold)}") prev_loc = self._curr_loc self._curr_loc, result_items = self._town_manager.stash(self._curr_loc, items=items, game_stats=self._game_stats) if not self._curr_loc: @@ -659,6 +691,7 @@ class Bot: self._curr_loc, result_items = self._town_manager.stash(self._verify_town_location(prev_loc), items=items, game_stats=self._game_stats) if not self._curr_loc: reason = "Maintenance failed [step: stash_items] — stash NPC not found after retry" + _step("stash_items", "fail", "stash not found after retry — ending game") Logger.error(reason) self._save_error_screenshot("maintenance", reason) if not self._game_stats.get_failure_reason(): @@ -666,6 +699,7 @@ class Bot: self.trigger_or_stop("end_game", failed=True) return sell_items = any([item.sell for item in result_items]) if result_items else None + _step("stash_items", "ok", f"at {self._curr_loc} | left in pack={len(result_items) if result_items else 0}") #Acquire mutex to prevent controller from killing thread during transmutes self._stash_mutex.acquire() Logger.info("Running transmutes") @@ -704,6 +738,8 @@ class Bot: need_repair = is_visible(ScreenObjects.NeedRepair) need_routine_repair = False if not Config().char["runs_per_repair"] else self._game_stats._run_counter % Config().char["runs_per_repair"] == 0 need_refill_teleport = self._char.capabilities.can_teleport_with_charges and (not self._char.select_tp() or self._char.is_low_on_teleport_charges()) + if not (need_repair or need_routine_repair or need_refill_teleport or sell_items): + _step("repair", "skip", "no repair due and nothing to sell") if need_repair or need_routine_repair or need_refill_teleport or sell_items: if _maint_timed_out("repair"): return if need_repair: @@ -714,7 +750,10 @@ class Bot: Logger.info("Teleport charges ran out. Need to repair") elif sell_items: Logger.info("Selling items at repair vendor") - self._maintenance_step = "repair" + _reason = ("gear about to break" if need_repair else + "routine" if need_routine_repair else + "tp charges" if need_refill_teleport else "sell items") + _step("repair", "start", f"reason={_reason} sell_pending={bool(sell_items)}") prev_repair_loc = self._curr_loc self._curr_loc, result_items = self._town_manager.repair(self._curr_loc, items) if not self._curr_loc: @@ -723,7 +762,9 @@ class Bot: self._curr_loc, result_items = self._town_manager.repair(self._verify_town_location(prev_repair_loc), items) if self._curr_loc: items = result_items + _step("repair", "ok", f"at {self._curr_loc}") if not self._curr_loc: + _step("repair", "fail", "vendor not found — non-fatal, continuing") # Keep maintenance best-effort for stability: avoid killing runs on flaky NPC/vendor detection. # IMPORTANT: re-detect the act — a failed repair trip may have left us in A4, # and assuming A5 here poisons the next run's waypoint pathing AND the act @@ -738,7 +779,7 @@ class Bot: # Check if merc needs to be revived if _maint_timed_out("resurrect_merc"): return - self._maintenance_step = "resurrect_merc" + _step("resurrect_merc") if Config().char["use_merc"]: merc_visible = False try: @@ -764,6 +805,7 @@ class Bot: f"Skipping merc resurrect until game {skip_until} " f"(resurrect NPC unreachable {getattr(gs, '_merc_resurrect_fail_streak', 0)}x in a row)" ) + _step("resurrect_merc", "skip", f"breaker active until game {skip_until}") merc_visible = True # suppress this game's attempt without touching state if not merc_visible and not self._game_stats._merc_resurrect_failed: Logger.info("Resurrect merc") @@ -779,6 +821,7 @@ class Bot: Logger.warning("Resurrect failed — skipping the retry, this NPC has been unreachable") if new_loc is False: # Failed to resurrect (can't afford or other error) - don't log death, just continue + _step("resurrect_merc", "fail", "NPC not reachable — continuing mercless") Logger.warning("Failed to resurrect merc after retry, continuing without merc") self._game_stats._merc_resurrect_failed = True gs._merc_resurrect_fail_streak = getattr(gs, "_merc_resurrect_fail_streak", 0) + 1 @@ -799,6 +842,7 @@ class Bot: Logger.warning("Resurrect returned None, continuing at current location") pass else: + _step("resurrect_merc", "ok", f"at {new_loc}") self._game_stats.log_merc_death() self._curr_loc = new_loc # It worked — clear the breaker so a transient failure never @@ -808,11 +852,15 @@ class Bot: # Gamble if needed if _maint_timed_out("gamble"): return - self._maintenance_step = "gamble" + if not (vendor.get_gamble_status() and Config().char["gamble_items"]): + _step("gamble", "skip", "stash not full / gambling not configured") + else: + _step("gamble") while vendor.get_gamble_status() and Config().char["gamble_items"]: Logger.debug("Head to gamble") self._curr_loc = self._town_manager.gamble(self._curr_loc) if not self._curr_loc: + _step("gamble", "fail", "gamble vendor not reachable") Logger.warning("Gamble failed, skipping gamble") self._curr_loc = self._verify_town_location() break @@ -825,6 +873,8 @@ class Bot: self._curr_loc = self._verify_town_location() break + _step("maintenance", "ok", f"done in {time.time() - _maint_start:.0f}s | at {self._curr_loc}") + # Start a new run started_run = False self._previous_run_failed = False diff --git a/src/inventory/personal.py b/src/inventory/personal.py index d40c649..82d1b43 100644 --- a/src/inventory/personal.py +++ b/src/inventory/personal.py @@ -541,6 +541,9 @@ def transfer_items(items: list, action: str = "drop", img: np.ndarray = None) -> # item successfully transferred, delete from list item_label = f" '{item.name}'" if item.name else "" Logger.debug(f"Confirmed {action}{item_label} at position {item.pos}") + # Mirror into the TOWN timeline so sells/stashes/drops of individual items + # appear in the same greppable sequence as the maintenance steps. + Logger.info(f"TOWN> | item_{action:<11} | ok | {item.name or '?'} @ {item.pos}") for cnt, o_item in enumerate(items): if o_item.pos == item.pos: items.pop(cnt)