From 6c378d36e15eefc4bb7180132c205625e93ad2be Mon Sep 17 00:00:00 2001 From: timlichtenberg Date: Thu, 22 Oct 2026 20:08:13 +0200 Subject: [PATCH 1/3] Guard value reads, hold back emptied places, run once an hour A board read now also counts as short when an issue item has no field values or fewer than its total, since every item holds at least its title. A read of issue field values is short when it returns fewer issues than asked for, or fewer values than the issue's total; it is read again like a board. An issue that lacks the value of a synced field whose latest event set it counts as unread. An issue place whose synced fields held 2 or more values and now all read empty is held back for the run and listed in the report, so a lost read of one item clears nothing at the other places. A run with apply stops before the read, with exit code 5, when it starts less than 50 minutes after the last run with apply. The workflow runs once an hour at minute 11 and shows that stop as a notice. --- .github/workflows/sync.yml | 6 +- README.md | 12 +++- board_sync/__main__.py | 40 +++++++++++- board_sync/config.py | 4 ++ board_sync/core.py | 49 +++++++++++++++ board_sync/github.py | 126 +++++++++++++++++++++++++------------ tests/test_cli.py | 3 + tests/test_github.py | 72 ++++++++++++++++++--- tests/test_sync_rules.py | 98 +++++++++++++++++++++++++++++ 9 files changed, 355 insertions(+), 55 deletions(-) diff --git a/.github/workflows/sync.yml b/.github/workflows/sync.yml index 1841640..e1f60e7 100644 --- a/.github/workflows/sync.yml +++ b/.github/workflows/sync.yml @@ -2,7 +2,7 @@ name: Board sync on: schedule: - - cron: "7,37 * * * *" + - cron: "11 * * * *" workflow_dispatch: inputs: apply: @@ -76,6 +76,10 @@ jobs: echo "::warning::Some writes are parked after repeated failures; see report.txt in the state repository." code=0 fi + if [ "$code" = 5 ]; then + echo "::notice::Skipped: the last apply run started less than 50 minutes ago." + code=0 + fi exit "$code" - name: Store state, snapshot and report diff --git a/README.md b/README.md index 99653f1..df2b207 100644 --- a/README.md +++ b/README.md @@ -40,9 +40,13 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that On a field that was created again, the first value counts as a change, as on a new board. An issue that is on no board for 90 days is dropped from the state. - A list longer than one page of the API (fields of a board, values of an item, issue fields, issue field values) stops the read with an error, so a cut-off list is never read as empty values. -- A board read is short when it finds no items, a number of items other than the board's total, or a total that changes between pages, since the API can return an empty page without an error. +- A board read is short when it finds no items, a number of items other than the board's total, a total that changes between pages, or an issue item with no values or a number of values other than its total (every item holds at least its title), since the API can return an empty page without an error. The board is then read again, up to 6 reads in all, 10 seconds apart, and the run stops with exit code 2 before any write when all 6 are short. So a board with no items stops every run, and the retries count against the 10 minutes of a run. + A read of issue field values is short when it returns fewer issues than asked for, or an issue with a number of values other than its total; it is read again in the same way. + An issue that lacks the value of a synced field whose latest event set it counts as unread for its issue fields. +- An issue place whose synced fields held 2 or more values in the state and all read empty now is held back for the run, as if the place did not hold the issue, and `report.txt` lists it. + So a read that drops the values of one item clears nothing; when the place reads empty in the next run too, it receives the agreed values. - A run that plans more than 20 writes stops and writes nothing (exit code 3). Read the plan in `report.txt` in the state repository, then start the workflow by hand with `apply` and `allow_bulk`. The state then holds the approved writes that are not done yet, and the scheduled runs write them, at most 400 values per run. @@ -58,7 +62,9 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that Issue links, values and error text stay in the state repository. - A run reads the places one after the other and then writes. An edit made in the minutes of a run can be overwritten by that run; the next run then sees the written value as agreed. -- Exit codes: 0 done, 1 some writes failed, 2 the read, the state file, a token or the run failed, 3 too many changes, 4 done but some writes are parked (the workflow shows it as a warning), 143 or 130 stopped by a signal. +- A run with `apply` that starts less than 50 minutes after the start of the last run with `apply` stops before the read with exit code 5, and the workflow shows it as a notice; a run without `apply` is not limited. + This holds for runs started by hand too, and a stored start time later than the run's own start also stops the run. +- Exit codes: 0 done, 1 some writes failed, 2 the read, the state file, a token or the run failed, 3 too many changes, 4 done but some writes are parked (the workflow shows it as a warning), 5 too soon after the last run with `apply` (the workflow shows it as a notice), 143 or 130 stopped by a signal. ## Setup @@ -72,7 +78,7 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that 4. Create `Interra-Project/board-sync-state` as a private repository with one commit on `main`, for example a README. 5. Store all 3 values in the environment only, not as repository secrets: the App client id as the variable `BOARD_SYNC_CLIENT_ID`, the App private key as the secret `BOARD_SYNC_PRIVATE_KEY`, and the private key of an SSH deploy key with write access to `Interra-Project/board-sync-state` as the secret `STATE_DEPLOY_KEY`. -The workflow runs at minute 7 and 37 of every hour on `main`; a run on another branch is skipped. +The workflow runs at minute 11 of every hour on `main`; a run on another branch is skipped. A run started by hand from the Actions tab only plans, unless `apply` is set. GitHub turns off scheduled workflows in a public repository after 60 days without activity in that repository. Check the date of the last run in the Actions tab of this repository, and enable the workflow again there when it is off. diff --git a/board_sync/__main__.py b/board_sync/__main__.py index 930af90..ee0e3f9 100644 --- a/board_sync/__main__.py +++ b/board_sync/__main__.py @@ -5,7 +5,9 @@ writes the plan, unless the plan has more than ``--max-changes`` writes; then it stops with exit code 3. A person reads the plan and reruns with ``--allow-bulk``; the state then holds the approved writes, and the next runs -write them in batches of ``--limit``. +write them in batches of ``--limit``. A run with ``--apply`` that starts less +than ``--min-interval`` minutes after the start of the last one stops before +the read, with exit code 5. """ import argparse @@ -201,6 +203,7 @@ def apply(args, clients, snap, result, active, parked, state, now, summary, deta idle = 0 if progress else (0 if args.allow_bulk else state.get("bulk_idle", 0)) + 1 keep = left and idle < BULK_IDLE_RUNS result.state["bulk_keys"], result.state["bulk_idle"] = (left, idle) if keep else ([], 0) + result.state["applied_at"] = args.started_at.isoformat(timespec="seconds") save_state(args.state, result.state) if in_row >= STOP_AFTER_FAILURES: summary.append(f"stopped after {in_row} failed writes in a row") @@ -240,6 +243,12 @@ def plan_and_apply(args, clients, snap, out): summary += [f"reset: {key} / {fkey} is treated as new, its old values are ignored" for key, fkey in result.resets] if result.skipped: summary.append(f"skipped: {len(result.skipped)} values without an option at the place") + if result.held: + summary.append(f"held back: {len(result.held)} issue places with no synced value read, listed in the report") + detail += [ + f"held back {snap['items'][i]['url']} {config.BOARDS.get(p, {}).get('title', 'issue field')}: no synced value" + for i, p in result.held + ] if parked: summary.append(f"parked: {len(parked)} writes that failed in {PARK_AFTER} runs, listed in the report") approved_keys = set(state.get("bulk_keys", [])) @@ -257,6 +266,19 @@ def plan_and_apply(args, clients, snap, out): return code or (4 if parked and args.apply else 0) +def too_soon(args): + """Return the start time of the last apply run when it is less than ``args.min_interval`` minutes ago. + + A start time later than this run's start also counts as too soon. + """ + if not args.apply or args.min_interval <= 0: + return None + last = load_state(args.state).get("applied_at") + if last and args.started_at - datetime.fromisoformat(last) < timedelta(minutes=args.min_interval): + return last + return None + + def safe_emit(args, line, detail, out): """Report a failed run; if even that fails, print the line alone.""" try: @@ -285,8 +307,17 @@ def run(args, clients, out=sys.stdout): ------- int Exit code: 0 done, 1 some writes failed, 2 the read or the run failed, - 3 too many changes, 4 done but some writes are parked. + 3 too many changes, 4 done but some writes are parked, 5 too soon + after the last apply run. """ + try: + last = too_soon(args) + except Exception as exc: # noqa: BLE001 the summary names the error type only + safe_emit(args, f"run failed: {type(exc).__name__}", traceback.format_exc(), out) + return 2 + if last: + print(f"skipped: the last apply run started at {last}, less than {args.min_interval:g} minutes ago", file=out) + return 5 try: snap = github.read_all(clients) except Exception as exc: # noqa: BLE001 the summary names the error type only @@ -315,10 +346,13 @@ def main(argv=None, env=os.environ): parser.add_argument("--limit", type=int, default=400, help="most writes in one run; the rest wait") parser.add_argument("--pause", type=float, default=0.0, help="seconds between writes") parser.add_argument("--deadline", type=float, default=600.0, help="seconds from start after which writes stop") + parser.add_argument( + "--min-interval", type=float, default=50.0, help="minutes from the start of the last apply run to the next" + ) parser.add_argument("--summary", action="store_true", help="print counts only, no issue data") parser.add_argument("--report", help="file for the full report with issue data") args = parser.parse_args(argv) - args.started = time.monotonic() + args.started, args.started_at = time.monotonic(), datetime.now(UTC) if env.get("GITHUB_ACTIONS") == "true": args.summary = True # a job log can be public old = signal.signal(signal.SIGTERM, _terminate) diff --git a/board_sync/config.py b/board_sync/config.py index 5056f46..436d7c8 100644 --- a/board_sync/config.py +++ b/board_sync/config.py @@ -76,5 +76,9 @@ # treated as a new, empty field, not as a mass clear. RESET_MIN = 5 +# An issue place that held at least this many synced values and now reads +# none is held back for the run, not read as a clear of each field. +WIPE_MIN = 2 + # An issue that is on no board for this many days is dropped from the state. GONE_DAYS = 90 diff --git a/board_sync/core.py b/board_sync/core.py index a594c62..16b9d84 100644 --- a/board_sync/core.py +++ b/board_sync/core.py @@ -35,6 +35,8 @@ class Plan: Values that cannot be written because the place lacks the option. resets : list of tuple ``(place_key, fkey)`` pairs treated as new fields in this run. + held : list of tuple + ``(issue, place)`` pairs held back in this run, see ``held_places``. """ writes: list = field(default_factory=list) @@ -42,6 +44,7 @@ class Plan: conflicts: list = field(default_factory=list) skipped: list = field(default_factory=list) resets: list = field(default_factory=list) + held: list = field(default_factory=list) def to_place(fkey, place, value): @@ -231,6 +234,45 @@ def reset_places(snap, state): return reset +def held_places(snap, state, reset): + """Find issue places whose synced values all read empty while the state holds several. + + A place counts when its synced fields held at least ``config.WIPE_MIN`` + values in the state, not counting reset fields and places marked gone, + and every synced field there reads empty now. Such a place is treated as + if it did not hold the issue in this run, so the empty read clears no + other place; when it reads empty again, it receives the agreed values. + + Parameters + ---------- + snap : dict + Snapshot of all places. + state : dict + State of the previous run. + reset : set of tuple + ``(place_key, fkey)`` pairs from ``reset_places``. + + Returns + ------- + set of tuple + ``(issue, place)`` pairs to hold back. + """ + out, old = set(), state.get("items", {}) + for iid, item in snap["items"].items(): + for place in item["places"]: + held = filled = 0 + for fkey, spec in config.FIELDS.items(): + if place not in scope(snap, item, fkey): + continue + filled += raw_value(item, place, spec["places"][place])[0] is not None + rec = old.get(iid, {}).get(fkey, {}) + if (place_key(item, place), fkey) not in reset and place not in rec.get("gone", ()): + held += rec.get("seen", {}).get(place) is not None + if held >= config.WIPE_MIN and filled == 0: + out.add((iid, place)) + return out + + def _newest(places, times): """Pick the place with the newest change time; ties go by ``PLACE_ORDER``.""" return max(places, key=lambda p: (times[p] or "", -config.PLACE_ORDER.index(p))) @@ -333,6 +375,13 @@ def plan(snap, state): result = Plan(state={"items": {}, "fields": field_ids(snap, state.get("fields"))}) reset = reset_places(snap, state) result.resets = sorted(reset) + held = held_places(snap, state, reset) + result.held = sorted(held) + if held: + items = {iid: dict(item) for iid, item in snap["items"].items()} + for iid, place in held: + items[iid]["places"] = {p: v for p, v in items[iid]["places"].items() if p != place} + snap = {**snap, "items": items} old = state.get("items", {}) now = snap.get("read_at") for iid, entry in old.items(): diff --git a/board_sync/github.py b/board_sync/github.py index 56dd3f0..06a807e 100644 --- a/board_sync/github.py +++ b/board_sync/github.py @@ -25,7 +25,7 @@ ... on ProjectV2SingleSelectField { options { id name } } } } items(first: 100, after: $after) { totalCount pageInfo { hasNextPage endCursor } nodes { id content { ... on Issue { id url repository { owner { login } } } } - fieldValues(first: 100) { pageInfo { hasNextPage } nodes { + fieldValues(first: 100) { totalCount pageInfo { hasNextPage } nodes { ... on ProjectV2ItemFieldDateValue { date updatedAt field { ... on ProjectV2FieldCommon { name } } } ... on ProjectV2ItemFieldSingleSelectValue { name updatedAt field { ... on ProjectV2FieldCommon { name } } } } } } } } } @@ -41,7 +41,7 @@ ISSUE_VALUES_QUERY = ( """ query($ids: [ID!]!) { nodes(ids: $ids) { ... on Issue { id - issueFieldValues(first: 50) { pageInfo { hasNextPage } nodes { + issueFieldValues(first: 50) { totalCount pageInfo { hasNextPage } nodes { ... on IssueFieldDateValue { value field { ... on IssueFieldDate { name } } } ... on IssueFieldSingleSelectValue { name field { ... on IssueFieldSingleSelect { name } } } } } timelineItems(last: 100, itemTypes: [ISSUE_FIELD_ADDED_EVENT, ISSUE_FIELD_CHANGED_EVENT, @@ -71,13 +71,24 @@ class TruncatedRead(RuntimeError): """A list in a response was longer than the request asked for.""" -class ShortBoardRead(RuntimeError): - """A board read gave no items, or a number of items other than the board total.""" +class ShortRead(RuntimeError): + """A read gave fewer entries than the API reports, or none where there must be some.""" -# Attempts of one board read, and seconds between them, when a read comes back short. -BOARD_READ_ATTEMPTS = 6 -BOARD_READ_WAIT = 10 +class ShortBoardRead(ShortRead): + """A board read gave no items, a number of items other than the board total, or an item without values.""" + + +class ShortIssueRead(ShortRead): + """A read of issue field values gave fewer values or issues than asked for.""" + + +# Attempts of one read, and seconds between them, when a read comes back short. +READ_ATTEMPTS = 6 +READ_WAIT = 10 + +# Issue field names that the sync reads, for the check of values against their latest events. +ISSUE_NAMES = frozenset(spec["places"]["issue"] for spec in config.FIELDS.values() if "issue" in spec["places"]) def _check_page(conn, what): @@ -86,6 +97,16 @@ def _check_page(conn, what): raise TruncatedRead(what) +def _read_again(read): + """Call ``read`` until it does not raise ``ShortRead``, at most ``READ_ATTEMPTS`` times in all.""" + for _ in range(READ_ATTEMPTS - 1): + try: + return read() + except ShortRead: + time.sleep(READ_WAIT) + return read() + + class Client: """Minimal GraphQL client for one token. @@ -194,9 +215,10 @@ def read_board(client, owner, number): """Read the fields and the issue items of one project board. A read that finds no items, a number of items other than the board's - ``totalCount``, or a ``totalCount`` that changes between pages, is short: - the board is read up to ``BOARD_READ_ATTEMPTS`` times in all, since the - API can return an empty page with no error. + ``totalCount``, a ``totalCount`` that changes between pages, or an issue + item whose values are none or other than their ``totalCount``, is short: + the board is read up to ``READ_ATTEMPTS`` times in all, since the API can + return an empty page with no error. Every item holds at least its title. Parameters ---------- @@ -221,14 +243,9 @@ def read_board(client, owner, number): TruncatedRead If a board has more fields, or an item more values, than one page. ShortBoardRead - If every attempt reads no items, or a number of items other than the total. + If every attempt is short. """ - for _ in range(BOARD_READ_ATTEMPTS - 1): - try: - return _read_board_once(client, owner, number) - except ShortBoardRead: - time.sleep(BOARD_READ_WAIT) - return _read_board_once(client, owner, number) + return _read_again(lambda: _read_board_once(client, owner, number)) def _read_board_once(client, owner, number): @@ -263,7 +280,10 @@ def _read_board_once(client, owner, number): if "id" not in content: skipped += 1 # draft issue, pull request, or an issue the token cannot read continue - _check_page(node["fieldValues"], f"values of an item on board {number}") + fv = node["fieldValues"] + _check_page(fv, f"values of an item on board {number}") + if fv["totalCount"] == 0 or len(fv["nodes"]) != fv["totalCount"]: + raise ShortBoardRead(f"board {number}: an item has {len(fv['nodes'])} values, total {fv['totalCount']}") values = {} for v in node["fieldValues"]["nodes"]: if v and v.get("field"): @@ -310,7 +330,10 @@ def read_issue_values(client, ids, batch=25): """Read org issue field values and their change times. A field whose latest event is a removal reads as ``[None, removed_at]``, - so a clear has its own time. + so a clear has its own time. A batch that returns fewer issues than + asked for, or an issue with fewer values than its ``totalCount``, is + read again, up to ``READ_ATTEMPTS`` times in all. An issue that lacks + the value of a synced field whose latest event set it counts as unread. Parameters ---------- @@ -326,30 +349,53 @@ def read_issue_values(client, ids, batch=25): tuple Issue id to ``{field name: [value, changed_at]}``, and the number of issues that could not be read. + + Raises + ------ + ShortIssueRead + If every attempt of a batch is short. """ out, unread = {}, 0 for i in range(0, len(ids), batch): - data = client.post(ISSUE_VALUES_QUERY, {"ids": ids[i : i + batch]}, allow_not_found=True) - for node in data["nodes"]: - if not node: - unread += 1 - continue - _check_page(node["issueFieldValues"], "issue field values") - times, removed = {}, set() - for ev in node["timelineItems"]["nodes"]: - name = ((ev or {}).get("issueField") or {}).get("name") - if name and ev["createdAt"] >= times.get(name, ""): - times[name] = ev["createdAt"] - if ev.get("__typename") == "IssueFieldRemovedEvent": - removed.add(name) - else: - removed.discard(name) - values = {name: [None, times[name]] for name in removed} - for v in node["issueFieldValues"]["nodes"]: - if v and v.get("field"): - name = v["field"]["name"] - values[name] = [v.get("value", v.get("name")), times.get(name)] - out[node["id"]] = values + part = ids[i : i + batch] + values, n = _read_again(lambda part=part: _read_issue_batch(client, part)) + out.update(values) + unread += n + return out, unread + + +def _read_issue_batch(client, ids): + """Read the issue field values of one batch once; see ``read_issue_values``.""" + out, unread = {}, 0 + data = client.post(ISSUE_VALUES_QUERY, {"ids": ids}, allow_not_found=True) + if len(data["nodes"]) != len(ids): + raise ShortIssueRead(f"{len(data['nodes'])} issues read, {len(ids)} asked for") + for node in data["nodes"]: + if not node: + unread += 1 + continue + conn = node["issueFieldValues"] + _check_page(conn, "issue field values") + if len(conn["nodes"]) != conn["totalCount"]: + raise ShortIssueRead(f"an issue has {len(conn['nodes'])} field values, total {conn['totalCount']}") + times, removed = {}, set() + for ev in node["timelineItems"]["nodes"]: + name = ((ev or {}).get("issueField") or {}).get("name") + if name and ev["createdAt"] >= times.get(name, ""): + times[name] = ev["createdAt"] + if ev.get("__typename") == "IssueFieldRemovedEvent": + removed.add(name) + else: + removed.discard(name) + values = {name: [None, times[name]] for name in removed} + for v in conn["nodes"]: + if v and v.get("field"): + name = v["field"]["name"] + values[name] = [v.get("value", v.get("name")), times.get(name)] + if any(name not in values for name in (ISSUE_NAMES & times.keys()) - removed): + unread += 1 # a value that its latest event set is absent from the read + continue + out[node["id"]] = values return out, unread diff --git a/tests/test_cli.py b/tests/test_cli.py index b8f301d..30e61e5 100644 --- a/tests/test_cli.py +++ b/tests/test_cli.py @@ -4,6 +4,7 @@ import io import json import time +from datetime import UTC, datetime import pytest @@ -54,6 +55,8 @@ def args(tmp_path, **kw): "pause": 0.0, "deadline": 600.0, "started": time.monotonic(), + "started_at": datetime.now(UTC), + "min_interval": 0.0, "summary": False, "report": None, } diff --git a/tests/test_github.py b/tests/test_github.py index 3fe64aa..ccc3ac8 100644 --- a/tests/test_github.py +++ b/tests/test_github.py @@ -168,6 +168,7 @@ def board_item(iid, org="FormingWorlds"): "id": f"item-{iid}", "content": {"id": iid, "url": f"u/{iid}", "repository": {"owner": {"login": org}}}, "fieldValues": { + "totalCount": 3, "pageInfo": DONE, "nodes": [ {"date": "2026-01-01", "updatedAt": "t1", "field": {"name": "Start date"}}, @@ -181,7 +182,7 @@ def board_item(iid, org="FormingWorlds"): def issue_node(iid, values=(), events=()): return { "id": iid, - "issueFieldValues": {"pageInfo": DONE, "nodes": list(values)}, + "issueFieldValues": {"totalCount": len(values), "pageInfo": DONE, "nodes": list(values)}, "timelineItems": {"nodes": list(events)}, } @@ -248,7 +249,7 @@ def test_read_issue_values_batches(): class C: def post(self, q, v, allow_not_found=False): calls.append(v["ids"]) - return {"nodes": []} + return {"nodes": [None] * len(v["ids"])} github.read_issue_values(C(), ["a", "b", "c"], batch=2) assert calls == [["a", "b"], ["c"]] @@ -288,8 +289,10 @@ def test_removed_issue_field_reads_as_clear_with_time(): assert values == {"A": {"Target date": [None, "2026-02-01"], "Start date": ["2026-01-01", "2026-03-01"]}} -def test_board_query_asks_for_the_item_total(): +def test_queries_ask_for_the_totals(): assert "items(first: 100, after: $after) { totalCount pageInfo" in github.BOARD_QUERY + assert "fieldValues(first: 100) { totalCount pageInfo" in github.BOARD_QUERY + assert "issueFieldValues(first: 50) { totalCount pageInfo" in github.ISSUE_VALUES_QUERY @pytest.mark.parametrize("where", ["fields", "values", "issue_fields", "issue_values"]) @@ -331,22 +334,75 @@ def post(self, q, v): [page(FULL[:1], more=True, total=2), page(FULL[1:], total=3)], # the total changed [page([], more=True, total=2), page(FULL[1:], total=2)], # an empty first page [page(FULL + [board_item("C")], total=2)], # more items than the total + [page([board_item("A") | {"fieldValues": {"totalCount": 0, "pageInfo": DONE, "nodes": []}}, FULL[1]])], + [page([board_item("A") | {"fieldValues": {"totalCount": 3, "pageInfo": DONE, "nodes": [{}]}}, FULL[1]])], ], ) def test_short_board_read_is_tried_again(short, slept): fake = Fake(pages=[*short, page(FULL)]) _, _, items, skipped = github.read_board(fake, "Interra-Project", 2) assert [i[0] for i in items] == ["A", "B"] and skipped == 0 - assert slept == [github.BOARD_READ_WAIT] + assert slept == [github.READ_WAIT] def test_short_board_read_stops_after_the_attempts(slept): - fake = Fake(pages=[page([], total=0)] * github.BOARD_READ_ATTEMPTS) + fake = Fake(pages=[page([], total=0)] * github.READ_ATTEMPTS) with pytest.raises(github.ShortBoardRead, match="0 items read, total 0"): github.read_board(fake, "Interra-Project", 1) - assert (github.BOARD_READ_ATTEMPTS, github.BOARD_READ_WAIT) == (6, 10) # the README states both - assert len(fake.cursors) == github.BOARD_READ_ATTEMPTS - assert slept == [github.BOARD_READ_WAIT] * (github.BOARD_READ_ATTEMPTS - 1) + assert (github.READ_ATTEMPTS, github.READ_WAIT) == (6, 10) # the README states both + assert len(fake.cursors) == github.READ_ATTEMPTS + assert slept == [github.READ_WAIT] * (github.READ_ATTEMPTS - 1) + + +START = {"value": "2026-02-01", "field": {"name": "Start date"}} +SET_START = {"__typename": "IssueFieldAddedEvent", "createdAt": "t1", "issueField": {"name": "Start date"}} + + +@pytest.mark.parametrize( + "short", + [ + {"nodes": []}, # fewer issues than asked for + {"nodes": [issue_node("A") | {"issueFieldValues": {"totalCount": 1, "pageInfo": DONE, "nodes": []}}]}, + ], +) +def test_short_issue_read_is_tried_again(short, slept): + answers = [short, {"nodes": [issue_node("A", values=[START])]}] + + class C: + def post(self, q, v, allow_not_found=False): + return answers.pop(0) + + values, unread = github.read_issue_values(C(), ["A"]) + assert values == {"A": {"Start date": ["2026-02-01", None]}} and unread == 0 + assert slept == [github.READ_WAIT] + + +def test_short_issue_read_stops_after_the_attempts(slept): + calls = [] + + class C: + def post(self, q, v, allow_not_found=False): + calls.append(v) + return {"nodes": []} + + with pytest.raises(github.ShortIssueRead, match="0 issues read, 1 asked for"): + github.read_issue_values(C(), ["A"]) + assert len(calls) == github.READ_ATTEMPTS and slept == [github.READ_WAIT] * (github.READ_ATTEMPTS - 1) + + +def test_issue_without_a_value_its_latest_event_set_is_unread(): + other = {"__typename": "IssueFieldAddedEvent", "createdAt": "t1", "issueField": {"name": "Notes"}} + gone = {"__typename": "IssueFieldRemovedEvent", "createdAt": "t2", "issueField": {"name": "Start date"}} + nodes = [ + issue_node("A", events=[SET_START]), # the read lost the value + issue_node("B", values=[START], events=[SET_START]), + issue_node("C", events=[other]), # not a synced field + issue_node("D", events=[SET_START, gone]), # removed after it was set + ] + values, unread = github.read_issue_values(Fake(values=nodes), ["A", "B", "C", "D"]) + assert unread == 1 and sorted(values) == ["B", "C", "D"] + assert values["B"] == {"Start date": ["2026-02-01", "t1"]} and values["D"] == {"Start date": [None, "t2"]} + assert github.ISSUE_NAMES == {"Start date", "Target date", "Priority"} def test_missing_page_info_is_an_error(): diff --git a/tests/test_sync_rules.py b/tests/test_sync_rules.py index ae956d9..8875b6f 100644 --- a/tests/test_sync_rules.py +++ b/tests/test_sync_rules.py @@ -777,3 +777,101 @@ def test_skip_line_names_the_derived_field(mk, monkeypatch, tmp_path): out = io.StringIO() cli.run(args(tmp_path), {}, out) assert "issue Effort: no option 'Low'" in out.getvalue() + + +B1 = {"Category": ("Tech", "t1"), "Start date": ("2026-01-01", "t1")} + + +def two_values(mk, **extra): + return mk.item( + b1={"Category": ("Tech", "t1"), "Start date": ("2026-01-01", "t1")}, + b2={"Category": ("Tech", "t1"), "Start date": ("2026-01-01", "t1")}, + b7={"Start date": ("2026-01-01", "t1")}, + **extra, + ) + + +def test_place_with_all_values_lost_is_held_back(mk): + state = core.plan(mk.snap([two_values(mk)]), {}).state + lost = mk.item(b1=B1, b2={}, b7={"Start date": ("2026-01-01", "t1")}) + r = core.plan(mk.snap([lost]), state) + assert r.writes == [] and r.held == [("I1", "b2")] + assert config.WIPE_MIN == 2 # the README states it + # Read in full again: no change. Read empty again: the place receives the agreed values. + again = core.plan(mk.snap([two_values(mk)]), r.state) + assert again.writes == [] and again.held == [] + refill = core.plan(mk.snap([lost]), r.state) + assert writes(refill) == {("b2", "Category"): "Tech", ("b2", "Start date"): "2026-01-01"} and refill.held == [] + + +def test_place_with_one_value_cleared_is_not_held_back(mk): + a = mk.item(b1={"Category": ("Tech", "t1")}, b2={"Category": ("Tech", "t1")}) + state = core.plan(mk.snap([a]), {}).state + r = core.plan(mk.snap([mk.item(b1={"Category": ("Tech", "t1")}, b2={})]), state) + assert writes(r) == {("b1", "Category"): None} and r.held == [] + + +def test_place_with_a_value_left_or_a_new_value_is_not_held_back(mk): + state = core.plan(mk.snap([two_values(mk)]), {}).state + one_left = mk.item(b1=B1, b2={"Category": ("Tech", "t1")}, b7={"Start date": ("2026-01-01", "t1")}) + assert core.plan(mk.snap([one_left]), state).held == [] + new = mk.item(b1=B1, b2={"Release": ("Interra 2027", "t2")}, b7={"Start date": ("2026-01-01", "t1")}) + assert core.plan(mk.snap([new]), state).held == [] + + +def test_reset_fields_do_not_count_for_held_back(mk): + state = core.plan(mk.snap([two_values(mk)]), {}).state + s = mk.snap([mk.item(b1=B1, b2={}, b7={"Start date": ("2026-01-01", "t1")})]) + s["fields"]["b2"]["Category"]["id"] = "NEW" # created again: only Start date counts + r = core.plan(s, state) + assert r.held == [] and ("b2", "category") in r.resets + + +def test_held_back_place_is_named_in_the_report(mk, monkeypatch, tmp_path): + state = core.plan(mk.snap([two_values(mk)]), {}).state + (tmp_path / "state.json").write_text(json.dumps(state)) + lost = mk.snap([mk.item(b1=B1, b2={}, b7={"Start date": ("2026-01-01", "t1")})]) + monkeypatch.setattr(github, "read_all", lambda clients: lost) + out, report = io.StringIO(), tmp_path / "r.txt" + assert cli.run(args(tmp_path, summary=True, report=str(report)), {}, out) == 0 + assert "held back: 1 issue places" in out.getvalue() and "github.com" not in out.getvalue() + assert "held back https://github.com/Interra-Project/repo/issues/1 Interra Collaboration" in report.read_text() + + +def test_apply_run_too_soon_after_the_last_stops_before_the_read(mk, monkeypatch, tmp_path): + from datetime import timedelta + + s = mk.snap(many(mk, 1)) + reads = [] + monkeypatch.setattr(github, "read_all", lambda clients: reads.append(1) or s) + monkeypatch.setattr(github, "write", lambda c, snap, w: None) + first = args(tmp_path, apply=True, min_interval=50.0) + assert cli.run(first, {}, io.StringIO()) == 0 + stamp = json.loads((tmp_path / "state.json").read_text())["applied_at"] + assert stamp == first.started_at.isoformat(timespec="seconds") + for gap, code in ((49, 5), (-1, 5), (51, 0)): + later = args(tmp_path, apply=True, min_interval=50.0, started_at=first.started_at + timedelta(minutes=gap)) + out = io.StringIO() + assert cli.run(later, {}, out) == code + if code == 5: + assert out.getvalue() == f"skipped: the last apply run started at {stamp}, less than 50 minutes ago\n" + assert len(reads) == 1 + first = later if code == 0 else first + assert cli.run(args(tmp_path, min_interval=50.0), {}, io.StringIO()) == 0 # a plan without apply is not limited + assert cli.run(args(tmp_path, apply=True, min_interval=0.0), {}, io.StringIO()) == 0 + + +def test_too_soon_check_on_a_damaged_state_fails_the_run(monkeypatch, tmp_path): + (tmp_path / "state.json").write_text("[1]") + monkeypatch.setattr(github, "read_all", lambda clients: pytest.fail("read after a state error")) + out = io.StringIO() + assert cli.run(args(tmp_path, apply=True, min_interval=50.0, summary=True), {}, out) == 2 + assert out.getvalue().strip() == "run failed: StateError" + + +def test_min_interval_defaults_to_50_minutes(monkeypatch): + seen = [] + monkeypatch.setattr(cli, "make_clients", lambda env: {}) + monkeypatch.setattr(cli, "run", lambda a, c: seen.append(a) or 0) + assert cli.main([], env={}) == 0 + assert seen[0].min_interval == 50.0 and seen[0].started_at.tzinfo is not None From 798141c5b9d76a8e8c527cd3e2db11dec1bb1cc6 Mon Sep 17 00:00:00 2001 From: timlichtenberg Date: Thu, 22 Oct 2026 20:18:06 +0200 Subject: [PATCH 2/3] Hold issue fields lost without a removal event, stamp only writing runs The issue fields of an issue are held back when one synced field that held a value reads empty with no removal event, since a clear of an issue field always has one; the count rule applies to boards only, so a hand clear on the issue still reaches the other places. Null value lists and null entries count as short reads. Only a run that tries a write stores its start time, so a run without writes leaves the state as it was and makes no commit. A stored start time more than 5 minutes after the run's own start is a state error. A run started by hand that is too soon fails instead of showing a notice, so a bulk approval is not lost without a sign. --- .github/workflows/sync.yml | 7 ++++-- README.md | 15 ++++++----- board_sync/__main__.py | 44 ++++++++++++++++++++++---------- board_sync/config.py | 4 +-- board_sync/core.py | 25 +++++++++++-------- board_sync/github.py | 20 ++++++++++----- tests/test_github.py | 9 +++++++ tests/test_sync_rules.py | 51 +++++++++++++++++++++++++++++++++++--- 8 files changed, 133 insertions(+), 42 deletions(-) diff --git a/.github/workflows/sync.yml b/.github/workflows/sync.yml index e1f60e7..3aa13c8 100644 --- a/.github/workflows/sync.yml +++ b/.github/workflows/sync.yml @@ -65,6 +65,7 @@ jobs: BOARD_SYNC_TOKEN_INTERRA_PROJECT: ${{ steps.interra.outputs.token }} BOARD_SYNC_TOKEN_FORMINGWORLDS: ${{ steps.formingworlds.outputs.token }} APPLY: ${{ github.event_name == 'schedule' || inputs.apply }} + EVENT: ${{ github.event_name }} BULK: ${{ github.event_name == 'workflow_dispatch' && inputs.allow_bulk }} run: | flags="--state state/state.json --snapshot-dir state --report state/report.txt --summary --pause 1" @@ -76,9 +77,11 @@ jobs: echo "::warning::Some writes are parked after repeated failures; see report.txt in the state repository." code=0 fi - if [ "$code" = 5 ]; then - echo "::notice::Skipped: the last apply run started less than 50 minutes ago." + if [ "$code" = 5 ] && [ "$EVENT" = schedule ]; then + echo "::notice::Skipped: the last run that wrote started less than 50 minutes ago." code=0 + elif [ "$code" = 5 ]; then + echo "::error::Nothing done: the last run that wrote started less than 50 minutes ago; start this run again later." fi exit "$code" diff --git a/README.md b/README.md index df2b207..b544ee1 100644 --- a/README.md +++ b/README.md @@ -31,7 +31,7 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that A board does not record when a value was cleared, so a cleared board value loses to a value set at another place in the same interval. The issue timeline read covers the last 100 field events; an older change has no time and loses. - A value that every changed place already shows, after the name map, wins without a conflict. -- A cleared value is cleared in the other places too. +- A cleared value is cleared in the other places too, except where a place is held back (see below). A field that is emptied as a whole at one place (all of its 5 or more values, see below) is filled again from the others. - A field that is missing at a place is skipped there, never read as empty, and the run log names it; a value without a matching option is listed in `report.txt` as skipped. A field with a new id (deleted and created again), or a field that held 5 or more values and now holds none, does not clear the other places. @@ -45,8 +45,10 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that So a board with no items stops every run, and the retries count against the 10 minutes of a run. A read of issue field values is short when it returns fewer issues than asked for, or an issue with a number of values other than its total; it is read again in the same way. An issue that lacks the value of a synced field whose latest event set it counts as unread for its issue fields. -- An issue place whose synced fields held 2 or more values in the state and all read empty now is held back for the run, as if the place did not hold the issue, and `report.txt` lists it. - So a read that drops the values of one item clears nothing; when the place reads empty in the next run too, it receives the agreed values. +- A board place of an issue whose synced fields held 2 or more values in the state and all read empty now is held back for the run, as if the place did not hold the issue, and `report.txt` lists it; fields that were created again or emptied as a whole do not count. + The issue fields of an issue are held back in the same way when one synced field that held a value reads empty without a removal event, since a clear of an issue field always has one. + So a read that drops the values of one item clears nothing; when the place reads the same in the next run, it receives the agreed values. + A hand clear of all synced fields of an issue on one board is therefore undone; clear them one by one in different runs, or on the issue. - A run that plans more than 20 writes stops and writes nothing (exit code 3). Read the plan in `report.txt` in the state repository, then start the workflow by hand with `apply` and `allow_bulk`. The state then holds the approved writes that are not done yet, and the scheduled runs write them, at most 400 values per run. @@ -62,9 +64,10 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that Issue links, values and error text stay in the state repository. - A run reads the places one after the other and then writes. An edit made in the minutes of a run can be overwritten by that run; the next run then sees the written value as agreed. -- A run with `apply` that starts less than 50 minutes after the start of the last run with `apply` stops before the read with exit code 5, and the workflow shows it as a notice; a run without `apply` is not limited. - This holds for runs started by hand too, and a stored start time later than the run's own start also stops the run. -- Exit codes: 0 done, 1 some writes failed, 2 the read, the state file, a token or the run failed, 3 too many changes, 4 done but some writes are parked (the workflow shows it as a warning), 5 too soon after the last run with `apply` (the workflow shows it as a notice), 143 or 130 stopped by a signal. +- A run with `apply` that starts less than 50 minutes after the start of the last run that tried a write stops before the read with exit code 5 (`--min-interval`, 0 turns the check off); a run without `apply` is not limited. + A scheduled run that stops this way shows a notice; a run started by hand fails, so start it again later. + A stored start time more than 5 minutes later than the run's own start is an error (exit code 2). +- Exit codes: 0 done, 1 some writes failed, 2 the read, the state file, a token or the run failed, 3 too many changes, 4 done but some writes are parked (the workflow shows it as a warning), 5 too soon after the last run that wrote, 143 or 130 stopped by a signal. ## Setup diff --git a/board_sync/__main__.py b/board_sync/__main__.py index ee0e3f9..cde8122 100644 --- a/board_sync/__main__.py +++ b/board_sync/__main__.py @@ -6,8 +6,8 @@ it stops with exit code 3. A person reads the plan and reruns with ``--allow-bulk``; the state then holds the approved writes, and the next runs write them in batches of ``--limit``. A run with ``--apply`` that starts less -than ``--min-interval`` minutes after the start of the last one stops before -the read, with exit code 5. +than ``--min-interval`` minutes after the start of the last run that wrote +stops before the read, with exit code 5. """ import argparse @@ -203,7 +203,10 @@ def apply(args, clients, snap, result, active, parked, state, now, summary, deta idle = 0 if progress else (0 if args.allow_bulk else state.get("bulk_idle", 0)) + 1 keep = left and idle < BULK_IDLE_RUNS result.state["bulk_keys"], result.state["bulk_idle"] = (left, idle) if keep else ([], 0) - result.state["applied_at"] = args.started_at.isoformat(timespec="seconds") + # Only a run that tried a write starts the interval, so a run without writes changes no state. + last = args.started_at.isoformat(timespec="seconds") if done else state.get("applied_at") + if last: + result.state["applied_at"] = last save_state(args.state, result.state) if in_row >= STOP_AFTER_FAILURES: summary.append(f"stopped after {in_row} failed writes in a row") @@ -244,9 +247,9 @@ def plan_and_apply(args, clients, snap, out): if result.skipped: summary.append(f"skipped: {len(result.skipped)} values without an option at the place") if result.held: - summary.append(f"held back: {len(result.held)} issue places with no synced value read, listed in the report") + summary.append(f"held back: {len(result.held)} places of an issue that read empty, listed in the report") detail += [ - f"held back {snap['items'][i]['url']} {config.BOARDS.get(p, {}).get('title', 'issue field')}: no synced value" + f"held back {snap['items'][i]['url']} {config.BOARDS.get(p, {}).get('title', 'issue field')}: read empty" for i, p in result.held ] if parked: @@ -266,17 +269,27 @@ def plan_and_apply(args, clients, snap, out): return code or (4 if parked and args.apply else 0) +# A stored start time later than this run's start by more than this is a damaged state. +CLOCK_SLACK = timedelta(minutes=5) + + def too_soon(args): - """Return the start time of the last apply run when it is less than ``args.min_interval`` minutes ago. + """Return the start time of the last run that wrote, when it is less than ``args.min_interval`` minutes ago. - A start time later than this run's start also counts as too soon. + Raises + ------ + StateError + If the stored time is more than ``CLOCK_SLACK`` later than this run's start. """ if not args.apply or args.min_interval <= 0: return None last = load_state(args.state).get("applied_at") - if last and args.started_at - datetime.fromisoformat(last) < timedelta(minutes=args.min_interval): - return last - return None + if not last: + return None + gap = args.started_at - datetime.fromisoformat(last) + if gap < -CLOCK_SLACK: + raise StateError(f"the last run that wrote started at {last}, after this run") + return last if gap < timedelta(minutes=args.min_interval) else None def safe_emit(args, line, detail, out): @@ -308,7 +321,7 @@ def run(args, clients, out=sys.stdout): int Exit code: 0 done, 1 some writes failed, 2 the read or the run failed, 3 too many changes, 4 done but some writes are parked, 5 too soon - after the last apply run. + after the last run that wrote. """ try: last = too_soon(args) @@ -316,7 +329,9 @@ def run(args, clients, out=sys.stdout): safe_emit(args, f"run failed: {type(exc).__name__}", traceback.format_exc(), out) return 2 if last: - print(f"skipped: the last apply run started at {last}, less than {args.min_interval:g} minutes ago", file=out) + print( + f"skipped: the last run that wrote started at {last}, less than {args.min_interval:g} minutes ago", file=out + ) return 5 try: snap = github.read_all(clients) @@ -347,7 +362,10 @@ def main(argv=None, env=os.environ): parser.add_argument("--pause", type=float, default=0.0, help="seconds between writes") parser.add_argument("--deadline", type=float, default=600.0, help="seconds from start after which writes stop") parser.add_argument( - "--min-interval", type=float, default=50.0, help="minutes from the start of the last apply run to the next" + "--min-interval", + type=float, + default=50.0, + help="minutes from the start of the last run that wrote to the next run with --apply", ) parser.add_argument("--summary", action="store_true", help="print counts only, no issue data") parser.add_argument("--report", help="file for the full report with issue data") diff --git a/board_sync/config.py b/board_sync/config.py index 436d7c8..2708dbe 100644 --- a/board_sync/config.py +++ b/board_sync/config.py @@ -76,8 +76,8 @@ # treated as a new, empty field, not as a mass clear. RESET_MIN = 5 -# An issue place that held at least this many synced values and now reads -# none is held back for the run, not read as a clear of each field. +# A board place of an issue that held at least this many synced values and +# now reads none is held back for the run, not read as a clear of each field. WIPE_MIN = 2 # An issue that is on no board for this many days is dropped from the state. diff --git a/board_sync/core.py b/board_sync/core.py index 16b9d84..d2f2e8a 100644 --- a/board_sync/core.py +++ b/board_sync/core.py @@ -235,13 +235,15 @@ def reset_places(snap, state): def held_places(snap, state, reset): - """Find issue places whose synced values all read empty while the state holds several. + """Find places of an issue whose synced values read empty with no sign of a clear. - A place counts when its synced fields held at least ``config.WIPE_MIN`` + A board counts when its synced fields held at least ``config.WIPE_MIN`` values in the state, not counting reset fields and places marked gone, - and every synced field there reads empty now. Such a place is treated as - if it did not hold the issue in this run, so the empty read clears no - other place; when it reads empty again, it receives the agreed values. + and every synced field there reads empty now. The issue place counts when + one such field reads empty without a removal time, since a clear of an + issue field always has one. Such a place is treated as if it did not + hold the issue in this run, so the empty read clears no other place; when + it reads the same in the next run, it receives the agreed values. Parameters ---------- @@ -260,15 +262,18 @@ def held_places(snap, state, reset): out, old = set(), state.get("items", {}) for iid, item in snap["items"].items(): for place in item["places"]: - held = filled = 0 + held = filled = lost = 0 for fkey, spec in config.FIELDS.items(): if place not in scope(snap, item, fkey): continue - filled += raw_value(item, place, spec["places"][place])[0] is not None + value, at = raw_value(item, place, spec["places"][place]) + filled += value is not None rec = old.get(iid, {}).get(fkey, {}) - if (place_key(item, place), fkey) not in reset and place not in rec.get("gone", ()): - held += rec.get("seen", {}).get(place) is not None - if held >= config.WIPE_MIN and filled == 0: + counted = (place_key(item, place), fkey) not in reset and place not in rec.get("gone", ()) + if counted and rec.get("seen", {}).get(place) is not None: + held += 1 + lost += value is None and at is None + if lost if place == "issue" else held >= config.WIPE_MIN and filled == 0: out.add((iid, place)) return out diff --git a/board_sync/github.py b/board_sync/github.py index 06a807e..b382f2c 100644 --- a/board_sync/github.py +++ b/board_sync/github.py @@ -97,6 +97,11 @@ def _check_page(conn, what): raise TruncatedRead(what) +def _count(nodes): + """Number of entries in a node list that are not null; a null list counts 0.""" + return sum(n is not None for n in nodes or ()) + + def _read_again(read): """Call ``read`` until it does not raise ``ShortRead``, at most ``READ_ATTEMPTS`` times in all.""" for _ in range(READ_ATTEMPTS - 1): @@ -280,10 +285,11 @@ def _read_board_once(client, owner, number): if "id" not in content: skipped += 1 # draft issue, pull request, or an issue the token cannot read continue - fv = node["fieldValues"] + fv = node.get("fieldValues") or {"totalCount": 0, "pageInfo": {"hasNextPage": False}, "nodes": []} _check_page(fv, f"values of an item on board {number}") - if fv["totalCount"] == 0 or len(fv["nodes"]) != fv["totalCount"]: - raise ShortBoardRead(f"board {number}: an item has {len(fv['nodes'])} values, total {fv['totalCount']}") + got = _count(fv["nodes"]) + if fv["totalCount"] == 0 or got != fv["totalCount"]: + raise ShortBoardRead(f"board {number}: an item has {got} values, total {fv['totalCount']}") values = {} for v in node["fieldValues"]["nodes"]: if v and v.get("field"): @@ -374,10 +380,12 @@ def _read_issue_batch(client, ids): if not node: unread += 1 continue - conn = node["issueFieldValues"] + conn = node.get("issueFieldValues") + if conn is None or conn.get("nodes") is None: + raise ShortIssueRead("an issue has no field value list") _check_page(conn, "issue field values") - if len(conn["nodes"]) != conn["totalCount"]: - raise ShortIssueRead(f"an issue has {len(conn['nodes'])} field values, total {conn['totalCount']}") + if _count(conn["nodes"]) != conn["totalCount"]: + raise ShortIssueRead(f"an issue has {_count(conn['nodes'])} field values, total {conn['totalCount']}") times, removed = {}, set() for ev in node["timelineItems"]["nodes"]: name = ((ev or {}).get("issueField") or {}).get("name") diff --git a/tests/test_github.py b/tests/test_github.py index ccc3ac8..0e217bf 100644 --- a/tests/test_github.py +++ b/tests/test_github.py @@ -336,6 +336,10 @@ def post(self, q, v): [page(FULL + [board_item("C")], total=2)], # more items than the total [page([board_item("A") | {"fieldValues": {"totalCount": 0, "pageInfo": DONE, "nodes": []}}, FULL[1]])], [page([board_item("A") | {"fieldValues": {"totalCount": 3, "pageInfo": DONE, "nodes": [{}]}}, FULL[1]])], + [page([board_item("A") | {"fieldValues": {"totalCount": 1, "pageInfo": DONE, "nodes": [{}] * 3}}, FULL[1]])], + [page([board_item("A") | {"fieldValues": {"totalCount": 3, "pageInfo": DONE, "nodes": [None] * 3}}, FULL[1]])], + [page([board_item("A") | {"fieldValues": {"totalCount": 3, "pageInfo": DONE, "nodes": None}}, FULL[1]])], + [page([board_item("A") | {"fieldValues": None}, FULL[1]])], ], ) def test_short_board_read_is_tried_again(short, slept): @@ -363,6 +367,11 @@ def test_short_board_read_stops_after_the_attempts(slept): [ {"nodes": []}, # fewer issues than asked for {"nodes": [issue_node("A") | {"issueFieldValues": {"totalCount": 1, "pageInfo": DONE, "nodes": []}}]}, + {"nodes": [issue_node("A") | {"issueFieldValues": {"totalCount": 1, "pageInfo": DONE, "nodes": [START] * 2}}]}, + {"nodes": [issue_node("A") | {"issueFieldValues": {"totalCount": 1, "pageInfo": DONE, "nodes": [None]}}]}, + {"nodes": [issue_node("A") | {"issueFieldValues": {"totalCount": 0, "pageInfo": DONE, "nodes": None}}]}, + {"nodes": [issue_node("A") | {"issueFieldValues": None}]}, + {"nodes": [None, None]}, # more issues than asked for ], ) def test_short_issue_read_is_tried_again(short, slept): diff --git a/tests/test_sync_rules.py b/tests/test_sync_rules.py index 8875b6f..c0c1ee5 100644 --- a/tests/test_sync_rules.py +++ b/tests/test_sync_rules.py @@ -834,7 +834,7 @@ def test_held_back_place_is_named_in_the_report(mk, monkeypatch, tmp_path): monkeypatch.setattr(github, "read_all", lambda clients: lost) out, report = io.StringIO(), tmp_path / "r.txt" assert cli.run(args(tmp_path, summary=True, report=str(report)), {}, out) == 0 - assert "held back: 1 issue places" in out.getvalue() and "github.com" not in out.getvalue() + assert "held back: 1 places of an issue" in out.getvalue() and "github.com" not in out.getvalue() assert "held back https://github.com/Interra-Project/repo/issues/1 Interra Collaboration" in report.read_text() @@ -849,12 +849,14 @@ def test_apply_run_too_soon_after_the_last_stops_before_the_read(mk, monkeypatch assert cli.run(first, {}, io.StringIO()) == 0 stamp = json.loads((tmp_path / "state.json").read_text())["applied_at"] assert stamp == first.started_at.isoformat(timespec="seconds") - for gap, code in ((49, 5), (-1, 5), (51, 0)): + for gap, code in ((49, 5), (-4, 5), (-6, 2), (50, 0)): later = args(tmp_path, apply=True, min_interval=50.0, started_at=first.started_at + timedelta(minutes=gap)) out = io.StringIO() assert cli.run(later, {}, out) == code + if code == 2: + assert "the last run that wrote started at" in out.getvalue() and len(reads) == 1 if code == 5: - assert out.getvalue() == f"skipped: the last apply run started at {stamp}, less than 50 minutes ago\n" + assert out.getvalue() == f"skipped: the last run that wrote started at {stamp}, less than 50 minutes ago\n" assert len(reads) == 1 first = later if code == 0 else first assert cli.run(args(tmp_path, min_interval=50.0), {}, io.StringIO()) == 0 # a plan without apply is not limited @@ -875,3 +877,46 @@ def test_min_interval_defaults_to_50_minutes(monkeypatch): monkeypatch.setattr(cli, "run", lambda a, c: seen.append(a) or 0) assert cli.main([], env={}) == 0 assert seen[0].min_interval == 50.0 and seen[0].started_at.tzinfo is not None + + +def test_run_without_writes_keeps_the_stamp_and_the_state(mk, monkeypatch, tmp_path): + from datetime import timedelta + + s = mk.snap(many(mk, 1)) + monkeypatch.setattr(github, "read_all", lambda clients: s) + + def write(clients, snap, w): + snap["items"][w["issue"]]["places"][w["place"]]["values"][w["field"]] = [w["value"], "t9"] + + monkeypatch.setattr(github, "write", write) + first = args(tmp_path, apply=True) + cli.run(first, {}, io.StringIO()) + before = (tmp_path / "state.json").read_text() + later = args(tmp_path, apply=True, started_at=first.started_at + timedelta(minutes=70)) + assert cli.run(later, {}, io.StringIO()) == 0 # nothing left to write + assert (tmp_path / "state.json").read_text() == before + assert json.loads(before)["applied_at"] == first.started_at.isoformat(timespec="seconds") + + +def test_issue_place_with_a_value_lost_without_a_removal_time_is_held_back(mk): + a = mk.item(b1={"Priority": ("Priority: high", "t1")}, issue={"Priority": ("High", "t1")}) + state = core.plan(mk.snap([a]), {}).state + lost = core.plan(mk.snap([mk.item(b1={"Priority": ("Priority: high", "t1")}, issue={})]), state) + assert lost.writes == [] and lost.held == [("I1", "issue")] + cleared = mk.item(b1={"Priority": ("Priority: high", "t1")}, issue={"Priority": (None, "t2")}) + r = core.plan(mk.snap([cleared]), state) + assert writes(r) == {("b1", "Priority"): None} and r.held == [] + + +def test_issue_place_with_all_values_cleared_by_hand_is_not_held_back(mk): + a = mk.item( + b1={"Start date": ("2026-01-01", "t1"), "Target date": ("2026-02-01", "t1")}, + issue={"Start date": ("2026-01-01", "t1"), "Target date": ("2026-02-01", "t1")}, + ) + state = core.plan(mk.snap([a]), {}).state + b = mk.item( + b1={"Start date": ("2026-01-01", "t1"), "Target date": ("2026-02-01", "t1")}, + issue={"Start date": (None, "t2"), "Target date": (None, "t2")}, + ) + r = core.plan(mk.snap([b]), state) + assert r.held == [] and writes(r) == {("b1", "Start date"): None, ("b1", "Target date"): None} From d18d1cc8b9bd5858ddf8ba08dfb1ac992c3aec8b Mon Sep 17 00:00:00 2001 From: timlichtenberg Date: Thu, 22 Oct 2026 21:27:52 +0200 Subject: [PATCH 3/3] Keep issue clears made during a hold, stamp a stopped first write An issue field that comes back to the sync after a hold and was cleared after the agreed value now counts as a clear, since its removal event has a time; before, the agreed value was written back. A board clear has no time, so an empty board place still receives. The start time is stored as soon as a write is sent, so a run stopped by a signal during its first write still starts the interval. A stored time in the future names applied_at in the error, and the README says how to recover. The workflow notices no longer repeat the interval, and the README states which short reads the hold does not catch. --- .github/workflows/sync.yml | 4 +-- README.md | 7 +++--- board_sync/__main__.py | 13 +++++----- board_sync/core.py | 7 +++--- board_sync/github.py | 2 +- tests/test_sync_rules.py | 51 +++++++++++++++++++++++++++++++++++++- 6 files changed, 68 insertions(+), 16 deletions(-) diff --git a/.github/workflows/sync.yml b/.github/workflows/sync.yml index 3aa13c8..832894a 100644 --- a/.github/workflows/sync.yml +++ b/.github/workflows/sync.yml @@ -78,10 +78,10 @@ jobs: code=0 fi if [ "$code" = 5 ] && [ "$EVENT" = schedule ]; then - echo "::notice::Skipped: the last run that wrote started less than 50 minutes ago." + echo "::notice::Skipped: too soon after the last run that wrote; see the log above." code=0 elif [ "$code" = 5 ]; then - echo "::error::Nothing done: the last run that wrote started less than 50 minutes ago; start this run again later." + echo "::error::Nothing done: too soon after the last run that wrote (see the log above); start this run again later." fi exit "$code" diff --git a/README.md b/README.md index b544ee1..d6e5e53 100644 --- a/README.md +++ b/README.md @@ -36,7 +36,7 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that - A field that is missing at a place is skipped there, never read as empty, and the run log names it; a value without a matching option is listed in `report.txt` as skipped. A field with a new id (deleted and created again), or a field that held 5 or more values and now holds none, does not clear the other places. - An issue that is not on a board, or cannot be read, keeps its record for that board. - When it is there again with the field, its empty fields receive the agreed values, an unchanged value counts as no change, and a different value wins only when it is newer than the agreed value (an agreed value of unknown time keeps its place). + When it is there again with the field, its empty fields receive the agreed values, an unchanged value counts as no change, and a different value wins only when it is newer than the agreed value (an agreed value of unknown time keeps its place); an issue field that was cleared after the agreed value counts as a clear, since its removal event has a time. On a field that was created again, the first value counts as a change, as on a new board. An issue that is on no board for 90 days is dropped from the state. - A list longer than one page of the API (fields of a board, values of an item, issue fields, issue field values) stops the read with an error, so a cut-off list is never read as empty values. @@ -47,7 +47,8 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that An issue that lacks the value of a synced field whose latest event set it counts as unread for its issue fields. - A board place of an issue whose synced fields held 2 or more values in the state and all read empty now is held back for the run, as if the place did not hold the issue, and `report.txt` lists it; fields that were created again or emptied as a whole do not count. The issue fields of an issue are held back in the same way when one synced field that held a value reads empty without a removal event, since a clear of an issue field always has one. - So a read that drops the values of one item clears nothing; when the place reads the same in the next run, it receives the agreed values. + So a read that drops all values of a board item that held 2 or more, or a value of an issue field, clears nothing; when the place reads the same in the next run, it receives the agreed values. + A board item with 1 synced value that reads empty, or a read that drops some but not all values of a board item, is not caught: it counts as a clear. A hand clear of all synced fields of an issue on one board is therefore undone; clear them one by one in different runs, or on the issue. - A run that plans more than 20 writes stops and writes nothing (exit code 3). Read the plan in `report.txt` in the state repository, then start the workflow by hand with `apply` and `allow_bulk`. @@ -66,7 +67,7 @@ Effort follows Workload in one direction: a hand edit of Effort on an issue that An edit made in the minutes of a run can be overwritten by that run; the next run then sees the written value as agreed. - A run with `apply` that starts less than 50 minutes after the start of the last run that tried a write stops before the read with exit code 5 (`--min-interval`, 0 turns the check off); a run without `apply` is not limited. A scheduled run that stops this way shows a notice; a run started by hand fails, so start it again later. - A stored start time more than 5 minutes later than the run's own start is an error (exit code 2). + A stored start time more than 5 minutes later than the run's own start is an error (exit code 2) on every run with `apply`; to recover, delete `applied_at` from `state.json` in the state repository. - Exit codes: 0 done, 1 some writes failed, 2 the read, the state file, a token or the run failed, 3 too many changes, 4 done but some writes are parked (the workflow shows it as a warning), 5 too soon after the last run that wrote, 143 or 130 stopped by a signal. ## Setup diff --git a/board_sync/__main__.py b/board_sync/__main__.py index cde8122..9674288 100644 --- a/board_sync/__main__.py +++ b/board_sync/__main__.py @@ -166,7 +166,7 @@ def apply(args, clients, snap, result, active, parked, state, now, summary, deta """ old_fails = state.get("failures", {}) batch, later = active[: args.limit], active[args.limit :] - failed, done_keys, done, in_row, late = [], set(), 0, 0, False + failed, done_keys, done, in_row, late, tried = [], set(), 0, 0, False, False try: for n, w in enumerate(batch): if in_row >= STOP_AFTER_FAILURES: @@ -176,6 +176,7 @@ def apply(args, clients, snap, result, active, parked, state, now, summary, deta break if n and args.pause: time.sleep(args.pause) + tried = True try: github.write(clients, snap, w) done_keys.add(write_key(w)) @@ -203,8 +204,8 @@ def apply(args, clients, snap, result, active, parked, state, now, summary, deta idle = 0 if progress else (0 if args.allow_bulk else state.get("bulk_idle", 0)) + 1 keep = left and idle < BULK_IDLE_RUNS result.state["bulk_keys"], result.state["bulk_idle"] = (left, idle) if keep else ([], 0) - # Only a run that tried a write starts the interval, so a run without writes changes no state. - last = args.started_at.isoformat(timespec="seconds") if done else state.get("applied_at") + # Only a run that tried a write moves the start of the interval. + last = args.started_at.isoformat(timespec="seconds") if tried else state.get("applied_at") if last: result.state["applied_at"] = last save_state(args.state, result.state) @@ -247,9 +248,9 @@ def plan_and_apply(args, clients, snap, out): if result.skipped: summary.append(f"skipped: {len(result.skipped)} values without an option at the place") if result.held: - summary.append(f"held back: {len(result.held)} places of an issue that read empty, listed in the report") + summary.append(f"held back: {len(result.held)} places of an issue with values missing, listed in the report") detail += [ - f"held back {snap['items'][i]['url']} {config.BOARDS.get(p, {}).get('title', 'issue field')}: read empty" + f"held back {snap['items'][i]['url']} {config.BOARDS.get(p, {}).get('title', 'issue field')}: values missing from the read" for i, p in result.held ] if parked: @@ -288,7 +289,7 @@ def too_soon(args): return None gap = args.started_at - datetime.fromisoformat(last) if gap < -CLOCK_SLACK: - raise StateError(f"the last run that wrote started at {last}, after this run") + raise StateError(f"applied_at: the last run that wrote started at {last}, after this run") return last if gap < timedelta(minutes=args.min_interval) else None diff --git a/board_sync/core.py b/board_sync/core.py index d2f2e8a..844153a 100644 --- a/board_sync/core.py +++ b/board_sync/core.py @@ -341,10 +341,11 @@ def decide(fkey, places, current, raw, times, record): for p in places: before = seen.get(p, _NEW) if p in gone and before is not _NEW: - # A returning place: empty receives, its old value is no change, and a new - # value counts only when it is newer than the agreed value (of known time). + # A returning place: its old value is no change, and a new value or a clear counts + # only when it is newer than the agreed value (of known time); a board clear has + # no time, so an empty board place receives. newer = record.get("t") is not None and (times[p] or "") > record["t"] - if current[p] is not None and current[p] != before and newer: + if current[p] != before and newer: changed.append(p) elif before is _NEW: # A place that joins with a value counts as a change; an empty one receives. diff --git a/board_sync/github.py b/board_sync/github.py index b382f2c..d45d0fa 100644 --- a/board_sync/github.py +++ b/board_sync/github.py @@ -291,7 +291,7 @@ def _read_board_once(client, owner, number): if fv["totalCount"] == 0 or got != fv["totalCount"]: raise ShortBoardRead(f"board {number}: an item has {got} values, total {fv['totalCount']}") values = {} - for v in node["fieldValues"]["nodes"]: + for v in fv["nodes"]: if v and v.get("field"): values[v["field"]["name"]] = [v.get("date", v.get("name")), v.get("updatedAt")] org = content["repository"]["owner"]["login"] diff --git a/tests/test_sync_rules.py b/tests/test_sync_rules.py index c0c1ee5..c0e7ff2 100644 --- a/tests/test_sync_rules.py +++ b/tests/test_sync_rules.py @@ -834,7 +834,9 @@ def test_held_back_place_is_named_in_the_report(mk, monkeypatch, tmp_path): monkeypatch.setattr(github, "read_all", lambda clients: lost) out, report = io.StringIO(), tmp_path / "r.txt" assert cli.run(args(tmp_path, summary=True, report=str(report)), {}, out) == 0 - assert "held back: 1 places of an issue" in out.getvalue() and "github.com" not in out.getvalue() + assert ( + "held back: 1 places of an issue with values missing" in out.getvalue() and "github.com" not in out.getvalue() + ) assert "held back https://github.com/Interra-Project/repo/issues/1 Interra Collaboration" in report.read_text() @@ -853,6 +855,8 @@ def test_apply_run_too_soon_after_the_last_stops_before_the_read(mk, monkeypatch later = args(tmp_path, apply=True, min_interval=50.0, started_at=first.started_at + timedelta(minutes=gap)) out = io.StringIO() assert cli.run(later, {}, out) == code + if code in (2, 5): # a run that stops before the read leaves the stamp as it was + assert json.loads((tmp_path / "state.json").read_text())["applied_at"] == stamp if code == 2: assert "the last run that wrote started at" in out.getvalue() and len(reads) == 1 if code == 5: @@ -920,3 +924,48 @@ def test_issue_place_with_all_values_cleared_by_hand_is_not_held_back(mk): ) r = core.plan(mk.snap([b]), state) assert r.held == [] and writes(r) == {("b1", "Start date"): None, ("b1", "Target date"): None} + + +def test_issue_field_cleared_by_hand_while_the_issue_place_is_held_is_cleared_after(mk): + dates = {"Start date": ("2026-01-01", "t1"), "Target date": ("2026-02-01", "t1")} + state = core.plan(mk.snap([mk.item(b1=dates, issue=dates)]), {}).state + held = mk.item(b1=dates, issue={"Target date": (None, "t2")}) # Start date lost, Target date cleared + r = core.plan(mk.snap([held]), state) + assert r.writes == [] and r.held == [("I1", "issue")] + back = mk.item(b1=dates, issue={"Start date": ("2026-01-01", "t1"), "Target date": (None, "t2")}) + r = core.plan(mk.snap([back]), r.state) + assert writes(r) == {("b1", "Target date"): None} and r.held == [] + + +def test_issue_place_held_for_one_lost_field_of_two_and_reset_fields_do_not_count(mk): + dates = {"Start date": ("2026-01-01", "t1"), "Target date": ("2026-02-01", "t1")} + state = core.plan(mk.snap([mk.item(b1=dates, issue=dates)]), {}).state + one = mk.item(b1=dates, issue={"Start date": ("2026-01-01", "t1")}) + assert core.plan(mk.snap([one]), state).held == [("I1", "issue")] + s = mk.snap([one], ids={("issue:Interra-Project", "Target date"): "NEW"}) + assert core.plan(s, state).held == [] + + +def test_stamp_moves_when_a_write_fails_or_is_stopped(mk, monkeypatch, tmp_path): + s = mk.snap(many(mk, 1)) + monkeypatch.setattr(github, "read_all", lambda clients: s) + + def refused(clients, snap, w): + raise RuntimeError("refused") + + monkeypatch.setattr(github, "write", refused) + first = args(tmp_path, apply=True) + assert cli.run(first, {}, io.StringIO()) == 1 + stamp = json.loads((tmp_path / "state.json").read_text())["applied_at"] + assert stamp == first.started_at.isoformat(timespec="seconds") + (tmp_path / "state.json").unlink() + + def stopped(clients, snap, w): + raise SystemExit(143) # a signal while the first write is on its way + + monkeypatch.setattr(github, "write", stopped) + second = args(tmp_path, apply=True) + with pytest.raises(SystemExit): + cli.run(second, {}, io.StringIO()) + stamp = json.loads((tmp_path / "state.json").read_text())["applied_at"] + assert stamp == second.started_at.isoformat(timespec="seconds")