feat: guard against a dead Instagram session, show progress, fix missing pings

- check-session.py: preflight in gdl-cron.sh. No unexpired sessionid in the
  Chrome profile gdl reads -> abort before any request, ping /76 (red check).
- stories-streak.py: postflight. Every fetched stories source empty for 3
  consecutive days -> exit 77, for a session Instagram stopped honouring while
  the cookie is still present. The 2026-10-07 session death went unnoticed for
  a week because every run still exited 0.
- gdl-sync.py: [n/N] source headers, a 60s heartbeat with new-file counts, and
  per-source timing, so a healthy paced run no longer looks hung.
- gdl-sync@.service now runs run-%i.sh instead of gdl-cron.sh: HC_URL is set in
  the wrappers, so scheduled runs had never pinged Healthchecks.
- Tests for both guards (offline) and the progress helpers.
This commit is contained in:
2026-10-14 21:02:58 -04:00
parent fcfb8e5fd3
commit 4a2bd7aa19
7 changed files with 433 additions and 6 deletions
+70
View File
@@ -0,0 +1,70 @@
#!/usr/bin/env python3
"""
Preflight for gdl-cron.sh: is there a usable Instagram login in the cookie jar gdl reads?
gdl-sync.py runs gallery-dl with `--cookies-from-browser chrome:<profile>`, so what matters
is not what the interactive Chrome window LOOKS like (an open tab keeps showing its logged-in
UI long after the session died -- found 2026-10-14, stories had been empty for a week) but
whether the profile's cookie DB holds a `sessionid`. This reads the same DB, the same way.
Never prints cookie values -- only the name, expiry, and a verdict.
Exit 0 logged in (a non-expired sessionid exists)
Exit 1 logged out / unreadable -- the caller must not scrape
"""
import datetime as dt
import os
import shutil
import sqlite3
import sys
import tempfile
import time
from pathlib import Path
PROFILE = Path(os.environ.get("GDL_COOKIE_PROFILE",
str(Path.home() / ".config/google-chrome-devtools")))
WARN_DAYS = 7
def main() -> int:
src = PROFILE / "Default" / "Cookies"
if not src.exists():
print(f"no cookie DB at {src} -- Chrome profile missing?")
return 1
with tempfile.TemporaryDirectory() as tmp:
# Copy first: Chrome holds the live DB open, and a copy keeps this read-only.
for suffix in ("", "-journal", "-wal", "-shm"):
f = Path(str(src) + suffix)
if f.exists():
shutil.copy2(f, Path(tmp) / f.name)
try:
con = sqlite3.connect(str(Path(tmp) / "Cookies"))
rows = con.execute(
"SELECT expires_utc, has_expires FROM cookies "
"WHERE host_key LIKE '%instagram.com' AND name = 'sessionid'").fetchall()
except sqlite3.Error as exc:
print(f"cannot read cookie DB: {exc}")
return 1
if not rows:
print("NOT LOGGED IN: no Instagram sessionid in the Chrome profile "
f"{PROFILE}. Log in to Instagram in that Chrome window (the open tab can "
"look logged in while stale -- reload it), then re-run.")
return 1
expires, has_expires = rows[0]
if has_expires:
exp = dt.datetime.fromtimestamp(expires / 1_000_000 - 11644473600, dt.timezone.utc)
left = (exp.timestamp() - time.time()) / 86400
if left <= 0:
print(f"NOT LOGGED IN: the Instagram sessionid expired {exp:%Y-%m-%d}.")
return 1
note = f"expires {exp:%Y-%m-%d}"
if left < WARN_DAYS:
note += f" (WARNING: only {left:.1f} days left)"
print(f"session ok: sessionid present, {note}")
else:
print("session ok: sessionid present (session cookie, no expiry)")
return 0
if __name__ == "__main__":
sys.exit(main())
+28
View File
@@ -66,6 +66,24 @@ mkdir -p "$GDL_HOME/logs"
[ -n "$HC_URL" ] && curl -fsS -m 10 --retry 3 -o /dev/null "$HC_URL/start" || true [ -n "$HC_URL" ] && curl -fsS -m 10 --retry 3 -o /dev/null "$HC_URL/start" || true
# Preflight: refuse to scrape logged out. gdl reads the Chrome profile's cookie DB, and the
# session in it can die silently -- from 2026-10-07 every stories run fetched "No results"
# for all six profiles and still exited 0, so nothing alerted and a week of stories (which
# cannot be backfilled) was lost. An open Chrome tab keeps showing its logged-in UI after
# that, so only the cookie DB tells the truth. Exit 76 turns the Healthchecks check red.
SESSION_CHECK="$GDL_HOME/check-session.py"
if [ -x "$SESSION_CHECK" ]; then
if ! SESSION_MSG=$("$SESSION_CHECK" 2>&1); then
echo "=== $MODE run $(date -Is) ===" | tee -a "$LOG"
echo "ABORT (no requests sent): $SESSION_MSG" | tee -a "$LOG" >&2
echo "=== exit 76 at $(date -Is) ===" | tee -a "$LOG"
[ -n "$HC_URL" ] && curl -fsS -m 10 --retry 3 --data-binary "@$LOG" \
-o /dev/null "$HC_URL/76" || true
exit 76
fi
echo "preflight: $SESSION_MSG" | tee -a "$LOG"
fi
# Staging is wiped every run ON PURPOSE. What we already hold is decided by the # Staging is wiped every run ON PURPOSE. What we already hold is decided by the
# skip-archive (--download-archive), never by which files happen to be sitting # skip-archive (--download-archive), never by which files happen to be sitting
# in staging, so starting empty is correct -- and it keeps the publish rsync # in staging, so starting empty is correct -- and it keeps the publish rsync
@@ -111,6 +129,16 @@ if [ "$MODE" = "stories" ] && grep -q "sources : 0 to sync" "$RUNOUT"; then
[ "$status" -eq 0 ] && status=75 [ "$status" -eq 0 ] && status=75
fi fi
# Every stories source empty for several days running = a session Instagram stopped
# honouring while the cookie is still in the jar (the preflight cannot see that). Stories-only:
# other modes legitimately return few items per source. See stories-streak.py.
if [ "$MODE" = "stories" ] && [ "$status" -eq 0 ] && [ -x "$GDL_HOME/stories-streak.py" ]; then
if ! STREAK_MSG=$("$GDL_HOME/stories-streak.py" "$RUNOUT" "$GDL_HOME/stories-empty-streak" 2>&1); then
echo "WARNING: $STREAK_MSG" | tee -a "$LOG" >&2
status=77
fi
fi
echo "=== exit $status at $(date -Is) ===" | tee -a "$LOG" echo "=== exit $status at $(date -Is) ===" | tee -a "$LOG"
# The log becomes the ping body -- healthchecks.io keeps the last ping's body # The log becomes the ping body -- healthchecks.io keeps the last ping's body
+79 -5
View File
@@ -94,6 +94,7 @@ import re
import shutil import shutil
import subprocess import subprocess
import sys import sys
import threading
import time import time
from dataclasses import dataclass, field from dataclasses import dataclass, field
from pathlib import Path from pathlib import Path
@@ -460,6 +461,71 @@ def build_config(rate: str, sleep_request: list[float],
# Planning and execution # Planning and execution
# -------------------------------------------------------------------------- # --------------------------------------------------------------------------
def _fmt_elapsed(sec: float) -> str:
sec = int(sec)
h, rest = divmod(sec, 3600)
m, s = divmod(rest, 60)
return f"{h}h{m:02d}m" if h else (f"{m}m{s:02d}s" if m else f"{s}s")
def _count_new(root: Path, since: float) -> tuple[int, str | None]:
"""Media files under `root` written since `since`, and the newest one's name."""
n, newest, newest_t = 0, None, 0.0
for d, _dirs, files in os.walk(root):
for f in files:
if f.endswith((".txt", ".json", ".part")):
continue
try:
mt = os.stat(os.path.join(d, f)).st_mtime
except OSError:
continue
if mt >= since:
n += 1
if mt > newest_t:
newest, newest_t = f, mt
return n, newest
class Heartbeat:
"""
Prints a progress line every `every` seconds while a quiet step runs.
A healthy run looks hung otherwise: pacing is 12-20s between requests, the
generated config sets `output: null` (no per-file lines), and the live
listing probe captures gallery-dl output until it finishes. With `watch`
set, the line also reports how many files have landed there so far.
"""
def __init__(self, label: str, watch: Path | None = None, every: float = 60.0):
self.label, self.watch, self.every = label, watch, every
self._stop = threading.Event()
self._thread = threading.Thread(target=self._run, daemon=True)
self.t0 = time.time()
def _run(self) -> None:
while not self._stop.wait(self.every):
msg = f" ... {self.label}: {_fmt_elapsed(time.time() - self.t0)} elapsed"
if self.watch is not None:
n, newest = _count_new(self.watch, self.t0)
msg += f", {n} new file(s) so far"
if newest:
msg += f" (latest: {newest})"
print(msg, flush=True)
def __enter__(self) -> "Heartbeat":
self.t0 = time.time()
self._thread.start()
return self
def __exit__(self, *exc) -> None:
self._stop.set()
self._thread.join()
@property
def elapsed(self) -> float:
return time.time() - self.t0
def gdl_command(src: Source, staging: Path, config: Path, cookies: str, def gdl_command(src: Source, staging: Path, config: Path, cookies: str,
archive_db: Path | None) -> list[str]: archive_db: Path | None) -> list[str]:
cmd = [ cmd = [
@@ -1003,8 +1069,9 @@ def main() -> int:
0.0 if args.force else args.probe_ttl) 0.0 if args.force else args.probe_ttl)
failures = 0 failures = 0
for prof, src, seed in plan: for n_src, (prof, src, seed) in enumerate(plan, 1):
print(f"==> {prof.user} / {src.kind}") print(f"==> [{n_src}/{len(plan)}] {prof.user} / {src.kind} "
f"({dt.datetime.now().strftime('%H:%M:%S')})")
stage_dir = args.staging / (src.directory or ".") stage_dir = args.staging / (src.directory or ".")
stage_dir.mkdir(parents=True, exist_ok=True) stage_dir.mkdir(parents=True, exist_ok=True)
@@ -1016,7 +1083,10 @@ def main() -> int:
try: try:
live = probes.get(src.url, now_ts) live = probes.get(src.url, now_ts)
if live is None: if live is None:
live = probe_live(src, config_path, args.cookies) print(" listing live items (metadata only; quiet until done)...")
with Heartbeat("listing") as hb:
live = probe_live(src, config_path, args.cookies)
print(f" listed {len(live)} item(s) in {_fmt_elapsed(hb.elapsed)}")
probes.put(src.url, live, stamp) probes.put(src.url, live, stamp)
probes.save() probes.save()
else: else:
@@ -1034,12 +1104,16 @@ def main() -> int:
cmd = gdl_command(src, args.staging, config_path, args.cookies, cmd = gdl_command(src, args.staging, config_path, args.cookies,
args.archive_db) args.archive_db)
result = subprocess.run(cmd) with Heartbeat("fetching", watch=stage_dir) as hb:
result = subprocess.run(cmd)
n_new, _ = _count_new(stage_dir, hb.t0)
if result.returncode != 0: if result.returncode != 0:
failures += 1 failures += 1
# Keep going: one private or renamed profile must not abort the run. # Keep going: one private or renamed profile must not abort the run.
print(f" FAILED (exit {result.returncode})", file=sys.stderr) print(f" FAILED (exit {result.returncode}) after "
f"{_fmt_elapsed(hb.elapsed)}", file=sys.stderr)
else: else:
print(f" done in {_fmt_elapsed(hb.elapsed)}, {n_new} new file(s)")
# Recorded even for an empty fetch: the request was still spent. # Recorded even for an empty fetch: the request was still spent.
state.mark_fetched(src.url, stamp) state.mark_fetched(src.url, stamp)
state.save() state.save()
+57
View File
@@ -0,0 +1,57 @@
#!/usr/bin/env python3
"""
Detect a silently dead Instagram session from a stories run's output.
A dead session (killed server-side while the sessionid is still in the cookie jar, so
check-session.py passes) shows up as every fetched stories source returning
"No results" -- the daily run still exits 0. From 2026-10-07 all six profiles came back
empty every day and nothing alerted. One all-empty day is normal (nobody posted a story);
several in a row across ALL sources is not.
Usage: stories-streak.py <this run's output file> [state file]
Counts at most one day per calendar date (manual re-runs don't inflate it). Prints a message
and exits 1 once the streak reaches GDL_EMPTY_STREAK_FAIL days (default 3); exits 0 otherwise.
Runs that fetched nothing (all skipped / no sources) leave the streak untouched.
"""
import datetime as dt
import os
import re
import sys
from pathlib import Path
THRESHOLD = int(os.environ.get("GDL_EMPTY_STREAK_FAIL", "3"))
def main() -> int:
out = Path(sys.argv[1]).read_text(errors="replace")
state = Path(sys.argv[2] if len(sys.argv) > 2
else Path.home() / "gdl" / "stories-empty-streak")
m = re.search(r"sources\s*:\s*(\d+) to sync", out)
to_sync = int(m.group(1)) if m else 0
if to_sync == 0:
return 0 # nothing fetched: no evidence either way
empty = len(re.findall(r"No results for \S*/stories/", out))
today = dt.date.today().isoformat()
last_date, streak = "", 0
try:
last_date, s = state.read_text().split()
streak = int(s)
except (OSError, ValueError):
pass
if empty >= to_sync: # every fetched source came back empty
if last_date != today:
streak += 1
else:
streak = 0
state.write_text(f"{today} {streak}\n")
if streak >= THRESHOLD:
print(f"SESSION LIKELY DEAD: stories came back empty for ALL {to_sync} profile(s) on "
f"{streak} consecutive day(s). The cookie is present but Instagram is probably "
"no longer honouring it -- log in again in the Chrome window (reload the tab to "
"check) and re-run.")
return 1
return 0
if __name__ == "__main__":
sys.exit(main())
+1 -1
View File
@@ -8,7 +8,7 @@ Wants=network-online.target
[Service] [Service]
Type=oneshot Type=oneshot
ExecStart=%h/gdl/gdl-cron.sh %i ExecStart=%h/gdl/run-%i.sh
# A sync has no deadline and the pacing is deliberately slow; a full sweep can # A sync has no deadline and the pacing is deliberately slow; a full sweep can
# run for hours. Never let systemd kill one midway -- a half-published run is # run for hours. Never let systemd kill one midway -- a half-published run is
# the one state the publish step is designed to avoid. # the one state the publish step is designed to avoid.
+38
View File
@@ -343,5 +343,43 @@ class PostUrlsFile(unittest.TestCase):
]) ])
class ProgressOutput(unittest.TestCase):
"""The heartbeat that stops a healthy paced run (12-20s between requests, no per-file
output) from looking hung."""
def test_elapsed_formatting(self):
self.assertEqual(gdl._fmt_elapsed(5), "5s")
self.assertEqual(gdl._fmt_elapsed(125), "2m05s")
self.assertEqual(gdl._fmt_elapsed(7300), "2h01m")
def test_count_new_counts_media_written_since_and_ignores_sidecars(self):
with tempfile.TemporaryDirectory() as d:
root = Path(d)
(root / "sub").mkdir()
old = root / "old.jpg"
old.write_text("x")
import os
os.utime(old, (1, 1)) # long before `since`
(root / "sub" / "new.jpg").write_text("x")
(root / "sub" / "new.mp4").write_text("x")
for sidecar in ("new.txt", "new.json", "half.jpg.part"):
(root / "sub" / sidecar).write_text("x")
n, newest = gdl._count_new(root, since=1000)
self.assertEqual(n, 2)
self.assertIn(newest, ("new.jpg", "new.mp4"))
def test_heartbeat_prints_while_running_and_stops_cleanly(self):
with tempfile.TemporaryDirectory() as d:
with mock.patch("builtins.print") as pr:
with gdl.Heartbeat("fetching", watch=Path(d), every=0.05) as hb:
(Path(d) / "a.jpg").write_text("x")
import time
time.sleep(0.2)
lines = [str(c.args[0]) for c in pr.call_args_list]
self.assertTrue(any("fetching" in s and "new file(s) so far" in s for s in lines))
self.assertFalse(hb._thread.is_alive())
self.assertGreater(hb.elapsed, 0.1)
if __name__ == "__main__": if __name__ == "__main__":
unittest.main(verbosity=2) unittest.main(verbosity=2)
+160
View File
@@ -0,0 +1,160 @@
"""
Tests for the two guards that stop a dead Instagram session going unnoticed:
check-session.py preflight: is there a usable `sessionid` in the Chrome cookie DB?
stories-streak.py postflight: did every stories source come back empty for days running?
Both are run as subprocesses (the way gdl-cron.sh runs them); neither touches the network.
python3 -I -m unittest scripts/test_session_guards.py
"""
import datetime as dt
import os
import sqlite3
import subprocess
import sys
import tempfile
import time
import unittest
from pathlib import Path
HERE = Path(__file__).resolve().parent
CHROME_EPOCH = 11644473600 # seconds between 1601-01-01 and 1970-01-01
def run(script, *args, env=None):
e = {**os.environ, **(env or {})}
return subprocess.run([sys.executable, str(HERE / script), *args],
capture_output=True, text=True, env=e)
class CheckSession(unittest.TestCase):
def profile(self, rows):
"""A fake Chrome profile whose cookie DB holds `rows` = [(host, name, expires_unix|None)]."""
tmp = tempfile.TemporaryDirectory()
self.addCleanup(tmp.cleanup)
d = Path(tmp.name) / "Default"
d.mkdir()
con = sqlite3.connect(d / "Cookies")
con.execute("CREATE TABLE cookies (host_key TEXT, name TEXT, expires_utc INTEGER, has_expires INTEGER)")
for host, name, exp in rows:
con.execute("INSERT INTO cookies VALUES (?,?,?,?)",
(host, name, 0 if exp is None else (exp + CHROME_EPOCH) * 1_000_000,
0 if exp is None else 1))
con.commit()
con.close()
return tmp.name
def check(self, rows):
return run("check-session.py", env={"GDL_COOKIE_PROFILE": self.profile(rows)})
def test_valid_sessionid_passes(self):
r = self.check([(".instagram.com", "sessionid", time.time() + 200 * 86400)])
self.assertEqual(r.returncode, 0, r.stdout)
self.assertIn("session ok", r.stdout)
self.assertNotIn("WARNING", r.stdout)
def test_missing_sessionid_fails_even_with_other_instagram_cookies(self):
# What the real failure looked like: csrftoken/ds_user_id/mid linger after logout.
r = self.check([(".instagram.com", "csrftoken", time.time() + 86400),
(".instagram.com", "ds_user_id", time.time() + 86400),
(".instagram.com", "mid", time.time() + 86400)])
self.assertEqual(r.returncode, 1)
self.assertIn("NOT LOGGED IN", r.stdout)
def test_expired_sessionid_fails(self):
r = self.check([(".instagram.com", "sessionid", time.time() - 86400)])
self.assertEqual(r.returncode, 1)
self.assertIn("expired", r.stdout)
def test_near_expiry_warns_but_passes(self):
r = self.check([(".instagram.com", "sessionid", time.time() + 3 * 86400)])
self.assertEqual(r.returncode, 0)
self.assertIn("WARNING", r.stdout)
def test_session_cookie_without_expiry_passes(self):
r = self.check([(".instagram.com", "sessionid", None)])
self.assertEqual(r.returncode, 0)
def test_other_sites_sessionid_does_not_count(self):
r = self.check([(".example.com", "sessionid", time.time() + 86400)])
self.assertEqual(r.returncode, 1)
def test_missing_profile_fails_loudly(self):
r = run("check-session.py", env={"GDL_COOKIE_PROFILE": "/nonexistent/profile"})
self.assertEqual(r.returncode, 1)
self.assertIn("no cookie DB", r.stdout)
def test_never_prints_cookie_values(self):
# The fake DB has no value column at all; the script must not need one.
r = self.check([(".instagram.com", "sessionid", time.time() + 90 * 86400)])
self.assertNotIn("sessionid=", r.stdout + r.stderr)
class StoriesStreak(unittest.TestCase):
def setUp(self):
tmp = tempfile.TemporaryDirectory()
self.addCleanup(tmp.cleanup)
self.dir = Path(tmp.name)
self.state = self.dir / "streak"
self.today = dt.date.today().isoformat()
self.yesterday = (dt.date.today() - dt.timedelta(days=1)).isoformat()
def out(self, to_sync, empty, skipped=0):
lines = [f"sources : {to_sync} to sync, {skipped} skipped"]
lines += [f"[instagram][info] No results for https://www.instagram.com/stories/user{i}/"
for i in range(empty)]
p = self.dir / "run.out"
p.write_text("\n".join(lines) + "\n")
return p
def streak(self, to_sync, empty, skipped=0):
return run("stories-streak.py", str(self.out(to_sync, empty, skipped)), str(self.state))
def stored(self):
return self.state.read_text().split()
def test_all_empty_for_three_days_fails(self):
self.state.write_text(f"{self.yesterday} 2\n")
r = self.streak(6, 6)
self.assertEqual(r.returncode, 1)
self.assertIn("SESSION LIKELY DEAD", r.stdout)
self.assertEqual(self.stored(), [self.today, "3"])
def test_first_empty_day_is_quiet(self):
r = self.streak(6, 6)
self.assertEqual(r.returncode, 0)
self.assertEqual(self.stored(), [self.today, "1"])
def test_same_day_rerun_does_not_inflate_the_streak(self):
self.state.write_text(f"{self.today} 2\n")
r = self.streak(6, 6)
self.assertEqual(r.returncode, 0)
self.assertEqual(self.stored(), [self.today, "2"])
def test_any_story_resets_the_streak(self):
self.state.write_text(f"{self.yesterday} 2\n")
r = self.streak(6, 5) # one profile had a story
self.assertEqual(r.returncode, 0)
self.assertEqual(self.stored(), [self.today, "0"])
def test_run_that_fetched_nothing_leaves_state_alone(self):
self.state.write_text(f"{self.yesterday} 2\n")
r = self.streak(0, 0, skipped=6)
self.assertEqual(r.returncode, 0)
self.assertEqual(self.stored(), [self.yesterday, "2"])
def test_threshold_is_configurable(self):
r = run("stories-streak.py", str(self.out(6, 6)), str(self.state),
env={"GDL_EMPTY_STREAK_FAIL": "1"})
self.assertEqual(r.returncode, 1)
def test_corrupt_state_file_is_treated_as_no_history(self):
self.state.write_text("garbage\n")
r = self.streak(6, 6)
self.assertEqual(r.returncode, 0)
self.assertEqual(self.stored(), [self.today, "1"])
if __name__ == "__main__":
unittest.main()