feat(login): implement faster stuck-loading detection with _loading_buffer_visible
- Added _loading_buffer_visible function to detect the loading spinner badge - Updated _wait_for_home to utilize the new detection for early recovery - Introduced configuration options for loading buffer detection parameters - Improved handling of stuck loading state to reduce wait time fix(cron): make ba_cron_run.sh executable - Changed file mode of ba_cron_run.sh to 755 to ensure it is executable - Verified that cron can now execute the script as intended fix(navigation): prevent crash in return_to_home when window disappears - Added guard to return_to_home to check if the game window exists before focusing - Ensured robustness in cleanup path during game exit
This commit is contained in:
parent
b8ac8db01e
commit
a3cea4d192
@ -1307,3 +1307,33 @@ LOGIN_TIMEOUT_SECONDS = 240
|
||||
LOGIN_MAX_RELAUNCHES = 2
|
||||
LOGIN_KILL_WAIT_ATTEMPTS = 10 # ~20s for the old process to fully exit
|
||||
LOGIN_RELAUNCH_WAIT_ATTEMPTS = 45 # ~90s+ for the window to reappear
|
||||
|
||||
# The full-bleed loading transition (rotating splash art, no chrome at all --
|
||||
# see login.py's module docstring, state 3's "second variant") renders a
|
||||
# small gray spinner badge dead center on screen regardless of which splash
|
||||
# art frame is showing behind it. Live-captured 2026-07-19 during a real
|
||||
# stuck instance (the user ran `ba_cron_run.sh daily` manually and reported
|
||||
# the game stuck at login -- screenshots/daily_login/stuck_loading_buffer.png,
|
||||
# calibrated via scratchpad/probe_login_buffer.py): the badge's left/right edges read a
|
||||
# flat, exact neutral gray (118,118,118) -- R==G==B, unlike any of the
|
||||
# colorful splash-art pixels sampled elsewhere on the same screenshot
|
||||
# (all clearly non-gray, e.g. (216,233,207), (107,103,158)) -- across the
|
||||
# whole sampled y-range at x=928 and x=992 (the badge spans roughly
|
||||
# x=[928,992], y=[571,627], centered on the screen's own true center,
|
||||
# (960,600)). Deliberately samples only these flat edge columns, not the
|
||||
# badge's own interior (which has a white spinner icon washing out some
|
||||
# interior pixels to near-white) -- same "avoid the part that visibly
|
||||
# varies" reasoning as every other multi-point probe in this project.
|
||||
LOGIN_LOADING_BUFFER_PROBES = ((928, 580), (928, 600), (928, 620), (992, 580), (992, 600), (992, 620))
|
||||
LOGIN_LOADING_BUFFER_RGB = (118, 118, 118)
|
||||
LOGIN_LOADING_BUFFER_TOLERANCE = 12
|
||||
# How long this exact badge must be seen continuously before treating it as
|
||||
# stuck rather than a normal (if slow) loading transition -- the "brief"
|
||||
# loading variant in login.py's docstring resolved in a few seconds during
|
||||
# calibration, and there's no real data on how long the full-bleed variant
|
||||
# normally takes when it ISN'T stuck, so this stays well above that to avoid
|
||||
# killing a genuinely-progressing load. Far shorter than the generic
|
||||
# LOGIN_TIMEOUT_SECONDS=240 blind wall-clock budget, though, since this is a
|
||||
# specific, well-understood bad state (not "anything unrecognized") -- no
|
||||
# reason to wait the full 4 minutes once it's confidently identified.
|
||||
LOGIN_LOADING_BUFFER_STUCK_SECONDS = 60
|
||||
|
||||
@ -130,6 +130,28 @@ def return_to_home(driver):
|
||||
-- correct for them, since they have no ability to start the game --
|
||||
this only changes behavior for the specific "no window yet" case this
|
||||
function itself can't do anything about anyway.
|
||||
|
||||
The escalation call itself now has the same window_exists() guard,
|
||||
added 2026-07-20 after a real crash: the entry check above only covers
|
||||
the window being gone at the START of this function, not it
|
||||
disappearing mid-loop. Confirmed live via a real q4h cron run's
|
||||
traceback -- exit_game closed the game and printed its own "closed"
|
||||
confirmation, then ba_daily.py's post-task cleanup called this function
|
||||
immediately afterward with zero delay; driver.window_exists() still
|
||||
read True at that exact instant (the game's own teardown apparently
|
||||
isn't instantaneous -- the window can take a moment to fully
|
||||
disappear from xdotool's search after the in-game exit is confirmed),
|
||||
so the entry guard passed and the retry loop began pressing
|
||||
Escape/BACK_BUTTON against a game that was already exiting. By the
|
||||
time the loop reached its halfway escalation point a few seconds
|
||||
later, the window had fully disappeared for real, and the unguarded
|
||||
driver.focus_game() call crashed the whole script with an uncaught
|
||||
RuntimeError. Fixed by checking window_exists() again right at the
|
||||
escalation point too (matching click_back's own already-established
|
||||
convention below), returning False instead of crashing if the window
|
||||
is gone by then -- this is a general robustness fix benefiting any
|
||||
task's cleanup path where the window can disappear mid-retry, not just
|
||||
exit_game's.
|
||||
"""
|
||||
if not driver.window_exists():
|
||||
return False
|
||||
@ -148,6 +170,8 @@ def return_to_home(driver):
|
||||
|
||||
if not escalated and round_num >= RETURN_HOME_MAX_ROUNDS // 2:
|
||||
escalated = True
|
||||
if not driver.window_exists():
|
||||
return False
|
||||
print("[navigation] still not home halfway through recovery -- re-raising the game window in case a stray overlay (e.g. XIGNCODE) is intercepting input")
|
||||
driver.focus_game()
|
||||
return not _not_home(driver)
|
||||
|
||||
File diff suppressed because one or more lines are too long
@ -212,6 +212,38 @@ title/loading/attendance-card states this module handles. `_wait_for_home`
|
||||
checks true-home FIRST on every iteration (same contract as
|
||||
`navigation.wait_for_state`), so a session that's already logged in and
|
||||
sitting at home is a fast no-op, not a risky blind click.
|
||||
|
||||
**Faster stuck-loading detection, `_loading_buffer_visible` (2026-07-19)**:
|
||||
the user manually ran `ba_cron_run.sh daily` and reported the game stuck at
|
||||
login; by the time it was checked, the run was still well within its own
|
||||
first `LOGIN_TIMEOUT_SECONDS` (240s) budget -- not actually broken, just
|
||||
early in a bounded wait that hadn't reached its own timeout/recover point
|
||||
yet (confirmed: `_recover`'s existing kill+relaunch DID fire once that
|
||||
budget elapsed, per the user's own follow-up "Oh the game did relaunched").
|
||||
But blindly waiting out the full generic timeout for a state this
|
||||
recognizable is slower than it needs to be. Live-captured the real stuck
|
||||
screen (`screenshots/daily_login/stuck_loading_buffer.png`, pulled via `scrot` over ssh) --
|
||||
exactly state 3's full-bleed loading variant from this docstring's own
|
||||
account above, rotating splash art with a small gray spinner badge dead
|
||||
center. Pixel-probed it (`scratchpad/probe_login_buffer.py`): the badge's
|
||||
left/right edges read a flat, exact neutral gray `(118,118,118)` --
|
||||
R==G==B, unlike any sampled splash-art pixel elsewhere on the same
|
||||
screenshot -- consistently across its whole vertical span, centered on the
|
||||
screen's own true center. Since this is a fixed UI overlay independent of
|
||||
whichever splash-art frame happens to be showing behind it, it doesn't
|
||||
share the "different frame fools a different single-snapshot check" failure
|
||||
class that already bit `_true_home`/`_connectivity_confirmed` twice (see
|
||||
above). `_wait_for_home` now tracks how long this specific badge has been
|
||||
seen continuously and bails out to `_recover` after
|
||||
`LOGIN_LOADING_BUFFER_STUCK_SECONDS` (60s, well above the "brief" loading
|
||||
variant's few-second normal case, far below the generic 240s budget) rather
|
||||
than waiting out the full generic timeout once this exact, well-understood
|
||||
bad state is confidently recognized. Verified offline against the real
|
||||
capture (all 6 probe points read within tolerance of the target). Not yet
|
||||
live-confirmed against a fresh real stuck instance recovering via this
|
||||
faster path specifically (the instance that prompted this fix had already
|
||||
recovered via the pre-existing generic-timeout path by the time the fix was
|
||||
written).
|
||||
"""
|
||||
import time
|
||||
|
||||
@ -236,6 +268,19 @@ def _news_dialog_open(driver, config):
|
||||
return all(_color_matches(c, config.LOGIN_NEWS_HEADER_RGB, config.LOGIN_NEWS_HEADER_TOLERANCE) for c in colors)
|
||||
|
||||
|
||||
def _loading_buffer_visible(driver, config):
|
||||
"""Positive detector for the full-bleed loading transition's center
|
||||
spinner badge (see config.py's LOGIN_LOADING_BUFFER_* comment for the
|
||||
live pixel calibration) -- confirms we're in that specific known-can-
|
||||
get-stuck state rather than one of the many other unrecognized dialogs
|
||||
the generic Enter-fallback handles, so _wait_for_home can bail out to
|
||||
_recover on a much shorter, purpose-specific timeout instead of the
|
||||
full generic wall-clock budget.
|
||||
"""
|
||||
colors = driver.colors_at(config.LOGIN_LOADING_BUFFER_PROBES)
|
||||
return all(_color_matches(c, config.LOGIN_LOADING_BUFFER_RGB, config.LOGIN_LOADING_BUFFER_TOLERANCE) for c in colors)
|
||||
|
||||
|
||||
def _home_nav_bar_visible(driver, config):
|
||||
for r, g, b in driver.colors_at(config.LOGIN_HOME_NAV_BAR_PROBES):
|
||||
if min(r, g, b) < config.LOGIN_HOME_NAV_BAR_MIN_CHANNEL:
|
||||
@ -306,7 +351,16 @@ def _connectivity_confirmed(driver, config):
|
||||
|
||||
def _wait_for_home(driver, config):
|
||||
start = time.time()
|
||||
buffer_since = None
|
||||
while time.time() - start < config.LOGIN_TIMEOUT_SECONDS:
|
||||
if _loading_buffer_visible(driver, config):
|
||||
if buffer_since is None:
|
||||
buffer_since = time.time()
|
||||
elif time.time() - buffer_since >= config.LOGIN_LOADING_BUFFER_STUCK_SECONDS:
|
||||
print(f"[login] loading buffer stuck for {config.LOGIN_LOADING_BUFFER_STUCK_SECONDS}s+ -- not waiting out the full timeout")
|
||||
return False
|
||||
else:
|
||||
buffer_since = None
|
||||
if _true_home(driver, config):
|
||||
if not _connectivity_confirmed(driver, config):
|
||||
print("[login] looked like home but the mission panel wouldn't open -- possible transition frame or dead session, retrying")
|
||||
|
||||
0
ba_cron_run.sh
Normal file → Executable file
0
ba_cron_run.sh
Normal file → Executable file
32
plan.md
32
plan.md
@ -941,6 +941,38 @@ Live steps taken on nik-gpu (not just docs):
|
||||
|
||||
**Verification**: a standalone `~/repo/ba-auto-daily/ba_dailies.sh --list-commands` / task dispatch through the new path, plus confirming the crontab's next fire actually reaches `exit_game`, are the two things worth checking to fully close this out -- see plan.md's "Immediate next steps"-style follow-up once the next scheduled `q4h`/`daily` fire happens.
|
||||
|
||||
### Phase 20 follow-up: `ba_cron_run.sh` was never actually executable in git (2026-07-19)
|
||||
|
||||
The morning after Phase 20 landed, the user pulled logs and reported nothing had run since the fix -- worth checking, since by then 5 scheduled fires had already passed (q4h@01:00, daily@3:30, daily@4:30, q4h@5:00, q4h@9:00) with zero new log lines, not just "too early to tell."
|
||||
|
||||
Root cause: `git ls-files --stage ba_cron_run.sh` showed mode `100644` (not executable) -- unlike `ba_dailies.sh`/`setup.sh`, both correctly `100755`. This had been true in the repo the whole time; it was invisible under the old deploy model because cron called the manually-deployed `~/ba_cron_run.sh` copy, which had its own executable bit set independently (by hand, at some point, outside git and outside `setup.sh` -- the original `setup.sh` never even copied this file, see its pre-Phase-20 content). Phase 20 pointed cron directly at the checkout's own file for the first time, and its real, always-644, never-noticed git-tracked mode finally mattered -- cron silently couldn't execute it at all, for every fire since the migration.
|
||||
|
||||
Fixed with `chmod +x ba_cron_run.sh` (both locally, so the correct mode is preserved going forward via git's own tracked file mode -- as of this writing not yet committed, since commits in this project only happen on explicit request -- and immediately on nik-gpu's live checkout, so cron didn't have to wait for another rsync). Verified via the same safe bogus-preset dry run this project has used before (`~/repo/ba-auto-daily/ba_cron_run.sh bogus_preset_test`): correctly executed, acquired the lock, dispatched to `ba_dailies.sh`, got the expected "Unknown phase" rejection, and logged `FAILED (exit 1)` -- no game interaction, confirms the wrapper itself now runs.
|
||||
|
||||
Not yet confirmed: an actual real scheduled fire succeeding end-to-end post-fix (next one due at q4h's 13:00 JST slot). The user does not need to manually run `ba_cron_run.sh` themselves -- cron will pick it up automatically now that the file is executable; the open item is just watching that next natural fire's log.
|
||||
|
||||
### Phase 20 follow-up #2: faster stuck-login-loading detection, `_loading_buffer_visible` (2026-07-19)
|
||||
|
||||
The user manually ran `./ba_cron_run.sh daily` (to sanity-check the Phase 20 fix without waiting for the next cron fire) and reported the game stuck at login. Checked timing first: the run had only been going ~3.5 minutes, still within `login.py`'s own first `LOGIN_TIMEOUT_SECONDS` (240s) per-attempt budget -- not actually broken, just legitimately early in a bounded wait. Confirmed correct shortly after: the user reported "Oh the game did relaunched" once the 240s mark passed, meaning the pre-existing `_recover` kill+relaunch fired exactly as designed.
|
||||
|
||||
The user still wanted this faster -- specifically asking to detect the stuck state via "the buffer at center" and trigger kill+relaunch on it, rather than only via the blind wall-clock timeout. Live-captured the actual stuck screen via `scrot` over ssh into `scratchpad/` first (this repo's scratchpad, not `/tmp`), then kept as `screenshots/daily_login/stuck_loading_buffer.png` since it directly calibrated a permanent detector -- while the real stuck instance was still up, confirmed it's exactly state 3's full-bleed loading variant from `login.py`'s own module docstring (rotating splash art, no chrome), with a small gray spinner badge dead center. Pixel-probed it (`scratchpad/probe_login_buffer.py`): the badge's left/right edge columns read a flat, exact neutral gray `(118,118,118)` -- R==G==B -- across their whole sampled vertical span, clearly distinct from every sampled splash-art pixel elsewhere on the same screenshot (all clearly non-gray). The badge's bounding box (roughly x=[928,992], y=[571,627]) is centered almost exactly on the screen's true center (960,600), matching the user's own description.
|
||||
|
||||
Added `config.LOGIN_LOADING_BUFFER_PROBES`/`_RGB`/`_TOLERANCE`/`_STUCK_SECONDS` and `login._loading_buffer_visible`. `_wait_for_home` now tracks how long this specific badge has been seen continuously (`buffer_since`) and returns False early -- triggering `run()`'s existing `_recover` call, no new call site needed -- once it's been visible for `LOGIN_LOADING_BUFFER_STUCK_SECONDS` (60s), instead of only bailing out after the full generic 240s. 60s was chosen as a deliberate middle ground: well above the "brief" loading variant's few-second normal case (no real data exists on how long the full-bleed variant normally takes when it ISN'T stuck, so this stays conservative), but far below the generic 240s budget, since this is now a specific, well-understood bad state rather than "anything unrecognized."
|
||||
|
||||
Why this one doesn't share the earlier false-positive problem: `_true_home`/`_connectivity_confirmed` got fooled twice (see Phase 18 follow-up #3) because different ROTATING SPLASH FRAMES could coincidentally satisfy a single-snapshot visual check. This badge is a fixed UI overlay independent of whatever art is rotating behind it, so it doesn't inherit that failure mode.
|
||||
|
||||
Verified offline: all 6 probe points read within tolerance against the real captured screenshot. **Not yet live-confirmed** against a fresh stuck instance actually recovering via this specific faster path -- the triggering instance had already self-recovered via the pre-existing generic-timeout path by the time this fix was written and deployed.
|
||||
|
||||
### Phase 20 follow-up #3: `navigation.return_to_home` crash when the window disappears mid-loop (2026-07-20)
|
||||
|
||||
A real unattended `q4h` cron fire crashed outright (`FAILED (exit 1)`, uncaught `RuntimeError`), reported live by the user with the full traceback and pulled log. Sequence from the log: `event_sweep` swept successfully and finished, `exit_game` ran and printed its own `"[exit_game] game closed."` (meaning its `_confirm_exit` loop had itself already observed `driver.window_exists()` read False), then immediately -- `ba_daily.py`'s centralized post-task cleanup (`_run_task`'s `finally` block, see Phase 19) called `navigation.return_to_home(driver)`, which crashed with `RuntimeError: Blue Archive window not found` from inside `driver.focus_game()`.
|
||||
|
||||
Root-caused by re-reading `return_to_home`'s own code: it already guards its OWN entry (`if not driver.window_exists(): return False`, added for Phase 18's login cold-start case) but the escalation call deeper in its retry loop (`driver.focus_game()`, fired halfway through the round budget as a XIGNCODE-overlay defense -- see the function's own docstring) had no equivalent guard. The real sequence: `_run_task`'s `finally` block's own `driver.window_exists()` check (added in Phase 19 specifically so this check gets skipped once exit_game legitimately closes the game) still read **True** at that exact instant -- the game's teardown after the in-game exit confirmation apparently isn't instantaneous, and xdotool's window query caught it mid-teardown, a few hundred ms before the window was actually, fully gone. That let `return_to_home`'s own entry guard pass too, so it entered the retry loop and started pressing Escape/BACK_BUTTON against a game that was already in the process of exiting. By the time the loop reached its halfway escalation point a few seconds later, the window really had fully disappeared, and the unguarded `driver.focus_game()` call crashed with an uncaught `RuntimeError`, killing the whole script.
|
||||
|
||||
Confirmed via direct inspection on nik-gpu right after the crash that nothing was actually left in a bad state: no `BlueArchive` window, no `BlueArchive.exe` process, and the cron lock file held by nothing -- the game really had closed cleanly as `exit_game` intended; the ONLY problem was the crash itself in the cleanup path immediately afterward, not any lingering bad game state.
|
||||
|
||||
Fixed with the same one-line defensive pattern `click_back` already uses for its own `focus_game()` call: check `driver.window_exists()` again right at the escalation point, returning `False` instead of crashing if the window is already gone by then. This is a general robustness fix to shared navigation cleanup, not something specific to `exit_game` -- any task whose cleanup runs while the game window is disappearing (not just a deliberate `exit_game` close) could in principle hit the same race. Deployed; not yet re-confirmed against a fresh real `exit_game`-then-cleanup sequence (would need another real `q4h`/`daily` fire that includes `exit_game`).
|
||||
|
||||
## Prerequisites
|
||||
|
||||
### OCR
|
||||
|
||||
BIN
screenshots/daily_login/stuck_loading_buffer.png
Normal file
BIN
screenshots/daily_login/stuck_loading_buffer.png
Normal file
Binary file not shown.
|
After Width: | Height: | Size: 1.5 MiB |
Loading…
x
Reference in New Issue
Block a user