From 59496cb08b045b4e7475b25dc011dce5b62deb46 Mon Sep 17 00:00:00 2001 From: Kral Date: Mon, 5 Oct 2026 19:47:16 +0200 Subject: [PATCH] Lock leak: controlled reproduction attempts and method (not reproduced), enqueue reader; restart plan for 12 October Co-Authored-By: Claude Sonnet 5.5 --- docs/epod-lock-leak.md | 73 +++++++++++++++++++++++++++-------- docs/restart-12-oktober.md | 62 +++++++++++++++++++++++++++++ harness/restart_plan.py | 77 +++++++++++++++++++++++++++++++++++++ scripts_probe/deltest.py | 41 ++++++++++++++++++++ scripts_probe/killcreate.py | 52 +++++++++++++++++++++++++ scripts_probe/killtabl.py | 51 ++++++++++++++++++++++++ scripts_probe/killtest.py | 71 ++++++++++++++++++++++++++++++++++ scripts_probe/killtwo.py | 42 ++++++++++++++++++++ scripts_probe/lockprobe.py | 58 ++++++++++++++++++++++++++++ 9 files changed, 510 insertions(+), 17 deletions(-) create mode 100644 docs/restart-12-oktober.md create mode 100644 harness/restart_plan.py create mode 100644 scripts_probe/deltest.py create mode 100644 scripts_probe/killcreate.py create mode 100644 scripts_probe/killtabl.py create mode 100644 scripts_probe/killtest.py create mode 100644 scripts_probe/killtwo.py create mode 100644 scripts_probe/lockprobe.py diff --git a/docs/epod-lock-leak.md b/docs/epod-lock-leak.md index eb99dc0..1215aac 100644 --- a/docs/epod-lock-leak.md +++ b/docs/epod-lock-leak.md @@ -1,22 +1,61 @@ -# EPOD: stale lock after a write (one case, not reproduced) +# EPOD: stale lock after a write (2 cases, not reproduced under control) -2026-10-05 15:09, run 200102 (task G1034, class `Z4AEE0SQ_STORAGE_PRICER`, two trajectory workers and three generators -running on A4H, one MCP session each): +Status 2026-10-05 evening. For Kral, to fix in the EPOD server (or to decide that it is not worth it). -1. `sap_push_source` main, `sap_push_source includeType=testclasses` (twice, the second with two activation warnings), - `sap_check_object`, `sap_run_unit_test` all returned success. -2. `sap_push_element` then failed: `[LOCK] The object ... could not be locked. HTTP 403, ExceptionResourceNoAccess. - Server message: User KESELI is currently editing Z4AEE0SQ_STORAGE_PRICER.` Twice, minutes apart. -3. Teardown (ADT deletion API, after the MCP session was closed) failed: `You are already editing ...`. The lock stayed - until it was deleted in SM12 (2026-10-05 evening). +## What happened (the two real cases) -So a lock was left behind by an earlier call of the same run and it did not end with the MCP session. The other -worker's `sap_run_unit_test` started 0.64 s after the second testclasses write (another session's call during a write). +| | Case 1 | Case 2 | +|---|---|---| +| When | 15:09, run 200102, task G1034 | 19:25, run 200273, task G1091 | +| Object | class `Z4AEE0SQ_STORAGE_PRICER` | table `Z4AJ50UB_PO_HEAD` (seed table of the task) | +| Situation | normal run; the second `sap_push_source includeType=testclasses` returned success (two activation warnings); the next `sap_push_element` failed `[LOCK] ... User KESELI is currently editing`, twice; teardown through ADT deletion said `You are already editing` | I started a second controller by mistake (same run number, same prefix, same seed table) and then killed both controller processes while the seed was installed. Teardown/deletion of the table said `You are already editing` | +| Lock gone | only after SM12 (Kral) | only after SM12 (Kral) | -Not reproduced (A4H, probe objects, 2026-10-05): 25 write cycles alone; 60 write cycles overlapping 2690 unit test calls of a -second session; 40 cycles of testclasses write + `sap_check_object` (ATC, unit tests, coverage) + `sap_object_members` + -second testclasses write + `push_element`, with a second session running `sap_check_object`; `push_element` on a method of -the test class (returns "lives in the testclasses include", no lock). Frequency: 1 in about 90 trajectory runs. +In both cases the lock outlived the MCP session and the run (hours). `ENQUEUE_READ` (see below) showed nothing after the SM12 delete. -Wish for EPOD: release the lock in a `finally` path of every write tool, also after a failed or warned activation, and -release all locks of a session when the MCP session ends. +## What we tried to reproduce (A4H, probe objects, no cloud, 2026-10-05) + +Every test: write through MCP, interfere, wait 3 s, read the enqueue table, write the same object again, delete it. +None left a lock. Scripts: `scripts_probe/` (`killtest.py`, `killtabl.py`, `killtwo.py`, `killcreate.py`, `deltest.py`, `lockprobe.py`). + +1. Client killed (`SIGKILL`) 0.03 to 0.8 s after `sap_push_source includeType=testclasses` was sent (the write needs about 0.7 s): 9 kills, no lock. The server finishes the write. +2. Client killed during `sap_push_source TABL` (DDL, activation): 6 kills at 0.5 to 4.5 s (the write takes about 0.7 s): no lock. +3. Two clients write the same table at the same time and both are killed: 8 delays (0.05 to 0.7 s): no lock. +4. Two clients both `sap_create_object` + `sap_push_source` the same table and both are killed (Case 2 as exactly as possible): 8 delays (0.05 to 1.0 s): no lock. +5. ADT deletion of the object while a write on it runs: the deletion is refused (`You are already editing`) or wins the race, no lock stays (6 delays). +6. Earlier: 25 write cycles alone; 60 cycles overlapping 2690 `sap_run_unit_test` calls of another session; 40 cycles of testclasses write + `sap_check_object` (ATC, unit tests, coverage) + `sap_object_members` + second testclasses write + `sap_push_element` with a second session on `sap_check_object`; `sap_push_element` on a method of the test class (error text only, no lock). + +So neither "client killed during a write" nor "two writers on one object" nor "delete during a write" leaks a lock on A4H in a short test. The two real cases may need a long running or slow call (the real runs were under load from 3 generators and 1 to 2 trajectory workers, calls then take seconds), or a state of the ADT stateful session that the probes did not reach. + +## How to see the enqueue state (exact method) + +A class with `IF_OO_ADT_CLASSRUN` calls `ENQUEUE_READ` and is run with `sap_run_class` (class `ZPROBE0EQ_LOCKS`, in `$TMP`; source in `scripts_probe/lockprobe.py`): + +```abap +CALL FUNCTION 'ENQUEUE_READ' + EXPORTING gclient = sy-mandt gname = '' garg = '' guname = '' + IMPORTING subrc = lv_subrc + TABLES enq = lt_enq "TYPE STANDARD TABLE OF seqg3 + EXCEPTIONS communication_failure = 1 system_failure = 2 OTHERS = 3. +``` + +A normal lock of a running write looks like this (seen in the 0.6 s test while a pipeline run was writing): +`GNAME=SEOCLSENQ GARG=Z4AJW0UK_CL_BERTH_FEE_TEST====...` (lock object of the class include, owner user KESELI). +After every probe the table was empty. A stale lock would show up as an entry that stays after the MCP session is closed: +read the table, close the session, read again. + +There is no function module on A4H to delete an enqueue entry (`TFDIR`: only `ENQUEUE_READ`, no `ENQUEUE_DELETE`): SM12 is the only way to release a stale lock, so every reproduction costs one SM12 delete. + +## What the harness does about it today + +- A write result with `[LOCK]` ("currently editing") is an infrastructure event: the run is not accepted, the trajectory workers go from 2 to 1, three equal events stop the pipeline. +- A failed teardown (`You are already editing`) is listed as a leftover (dashboard); the object needs an SM12 delete, then the harness deletes it. +- One controller only (flock on `runs/pipeline/controller.lock`), so two controllers cannot install the same run number twice any more (this was Case 2). +- Never kill a controller while it runs: it is drained through the budget guard or a STOP flag. + +## Wish for EPOD + +1. Release the lock in a `finally` path of every write tool (also after a failed or warned activation). +2. Release all locks of an MCP session when the session ends (`DELETE /mcp`) and when the connection breaks. +3. Return a clear error with the lock owner and the age of the lock, and a tool to release the locks of the caller's own session. +4. A short idle timeout for the stateful ADT session (the lock lasted hours). diff --git a/docs/restart-12-oktober.md b/docs/restart-12-oktober.md new file mode 100644 index 0000000..ddd4fb3 --- /dev/null +++ b/docs/restart-12-oktober.md @@ -0,0 +1,62 @@ +# Restart plan for 12 October 2026 (cloud work) + +Decision (Kral + Opus, 2026-10-05): when the budget guard stops, no cloud work (generation, trajectories) before the +Ollama reset on 12 October. Until then only no-cloud work. This is the plan for the restart. + +## 1. Before the start (5 minutes, no cloud call) + +1. Panel value after the reset (usage USD). Then: + `python3 -m harness.restart_plan --panel ` + It prints the `.env` values and the state below with live numbers. Put them in `.env`: + `BUDGET_CYCLE_START=2026-10-12`, `BUDGET_LIMIT_USD=`, `BUDGET_RESERVE_USD=8` (the 3 usage reserve for the + second teacher test stays). Ratio for the guard: 1.2 ledger per usage (trajectory runs; generation is about 2, so the + guard is on the safe side). Give the panel value again after about 2 hours and recompute (`python3 -m harness.dashboard panel `). +2. A4H up (`docker ps`), MCP answers, no stale lock: `python3 scripts_probe/lockprobe.py` must print 0 entries. +3. One controller only: `python3 -m harness.pipeline` refuses to start a second one (`runs/pipeline/controller.lock`). + Remove `runs/pipeline/STOP` and `STOPPED.txt` if they exist. +4. Dashboard: `python3 -m harness.dashboard` (5-minute page, `runs/dashboard/index.html`). + +## 2. Order of work (what the controller does by itself) + +Only kinds below their target share are generated and run (`harness/mix.py`, `below_target`); the kind with the biggest +deficit goes first. Target (percent of accepted tasks and of accepted trajectories): CLAS 28, INTF 7, DDLS 25, FUNC 15, +PROG 10, TABL 8, STRU 2, MSAG 2.5, exception 2.5. + +1. Trajectories for the new-type tasks that wait (INTF, TABL, STRU, MSAG, exception, PROG), then DDLS. +2. Second attempts: a task whose first attempt failed, or was accepted without a repair, gets one more attempt (at most two + attempts, at most two accepted trajectories per task). Failed DDLS and failed new-type tasks come first because they are + below target. +3. Generation (3 workers): the kind with the biggest deficit; a kind with more than 8 waiting tasks is not generated; a kind with + 6 or more tries and under 20 % accepted is skipped. 20 % error-targeted slots, 30 % hard slots. +4. CLAS and FUNC generation and trajectories wait until they are at or below their target share (CLAS is far above). +5. K variants (free text) resume at 10 % of the other accepted tasks when their kinds are below target. + +## 3. How much is needed (numbers of 2026-10-05 20:00, live: `restart_plan`) + +CLAS has 49 accepted trajectories. At a 28 % share that is a total of 175 accepted trajectories, so about 105 more are +needed, all on other kinds: INTF 12, DDLS about 35, FUNC about 15, PROG about 17, TABL 14, STRU 3, MSAG 4, exception 4. +Tasks needed (accepted, with about 1.3 trajectory runs per accepted trajectory): TABL +9, INTF +10, STRU +3, MSAG +4, +DDLS +20, PROG +5. About 130 trajectory runs at 0.25 ledger = 33 ledger = 27 usage, plus the generation (about 6 usage). +Second attempts are part of the 130 runs. If the new reset gives 60 usage, this fits with room for the second teacher test. + +## 4. Checks on the first runs of each new type (do not skip) + +- The first 5 runs of INTF, TABL, STRU, MSAG, exception: records complete (the proxy must pass `sap_push_message`), + Qwen conversion works (`train/to_qwen.py` on `accepted.jsonl`: tool call round trip), no harness event. +- Acceptance per kind in the summary; a kind under 20 % after 6 tries is skipped automatically: read why (prompt, harness, or the + teacher cannot do it) before starting it again. +- DDLS: 8 of 17 runs accepted on 2026-10-05; the rejections were budget (60 calls, now 100) and empty responses (32k output limit). + If empty responses stay high, lower the output limit for CDS runs or retry once more. + +## 5. Settings that stay + +- Trajectory workers 2 (a harness event sets 1); stop rules: acceptance under 50 % over the last 30 runs, the same harness + error three times, the budget guard. Generation deadline 2026-10-10 18:00 has passed: set `--gen-deadline` and + `--traj-deadline` on the controller command (for example `--gen-deadline 2026-10-20T18:00 --traj-deadline 2026-10-21T23:30`). +- Tool budget 100 for CDS tasks (eval stays 60). 20 tool schemas in every sample. Token note: p95 48k, max 72k. +- Summary every 50 accepted trajectories in `train/STATE.md` and `docs/yol-haritasi.md`, with a commit. + +## 6. After the restart + +Open decisions: second A4H (not started, multi-host code later), bf16 memory test at 48k, the second teacher test (the +reserve), the EPOD requests in `docs/epod-lock-leak.md` and `docs/epod-syntax-hint.md`. diff --git a/harness/restart_plan.py b/harness/restart_plan.py new file mode 100644 index 0000000..453be85 --- /dev/null +++ b/harness/restart_plan.py @@ -0,0 +1,77 @@ +"""State and suggested settings for restarting the cloud work after the budget reset (12 October). + + python3 -m harness.restart_plan [--panel 0.0] [--ratio 1.2] + +Prints (no cloud call, no file change): ledger, the suggested BUDGET_* values from the panel value, the object +type deficits, the tasks waiting for a first run per kind, the second attempt candidates, and the commands. +""" +import argparse +import json +import os + +from .adt_client import load_env +from . import mix +from .ledger import spent + +ROOT = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) +RESERVE_USAGE = 3.0 +LEDGER_RESERVE = 8 + + +def main(): + load_env(os.path.join(ROOT, ".env")) + ap = argparse.ArgumentParser() + ap.add_argument("--panel", type=float, default=0.0, help="Ollama panel usage after the reset (USD)") + ap.add_argument("--ratio", type=float, default=1.2, help="ledger per usage, pessimistic (trajectory runs 1.2)") + a = ap.parse_args() + s = spent("2026-10-12") + usable = 60 - a.panel - RESERVE_USAGE + limit = round(usable * a.ratio + LEDGER_RESERVE) + print(f"ledger since 2026-10-12: {s:.2f}") + print(f"panel {a.panel} of 60, reserve {RESERVE_USAGE} usage -> usable {usable:.1f} usage x {a.ratio} = {usable * a.ratio:.0f} ledger") + print(f"set in .env: BUDGET_CYCLE_START=2026-10-12 BUDGET_LIMIT_USD={limit + int(s)} BUDGET_RESERVE_USD={LEDGER_RESERVE}") + rows = [json.loads(l) for l in open(os.path.join(ROOT, "runs", "traj", "summary.jsonl"))] + import sys + sys.path.insert(0, os.path.join(ROOT, "train")) + import accept + acc_traj, runs = {}, {} + first = {} + for r in rows: + k = mix.kind_of_task_dir(r["task"]) + runs[k] = runs.get(k, 0) + 1 + ok = False + p = os.path.join(ROOT, "runs", "traj", r.get("run_dir") or "-", "record.json") + if os.path.exists(p): + ok = accept.judge(json.load(open(p)), r, 80)[0] + acc_traj[k] = acc_traj.get(k, 0) + ok + if r["attempt"] == 0: + first[r["task"]] = ok + tot_t = max(sum(acc_traj.values()), 1) + tasks = mix.accepted_task_counts() + ss = sum(mix.TYPE_SHARE.values()) + print("\nkind target tasks traj acc/runs (share) below target (generate + run)") + below_t, below_r = mix.below_target(tasks), mix.below_target(acc_traj) + for k, v in mix.TYPE_SHARE.items(): + print(f"{k:5s} {100 * v / ss:5.1f}% {tasks.get(k, 0):6d} {acc_traj.get(k, 0):4d}/{runs.get(k, 0):<4d} ({100 * acc_traj.get(k, 0) / tot_t:4.1f}%) " + f"tasks:{'yes' if k in below_t else 'no '} trajectories:{'yes' if k in below_r else 'no'}") + done0 = {r["task"] for r in rows if r["attempt"] == 0} + done1 = {r["task"] for r in rows if r["attempt"] == 1} + waiting, second = {}, {} + import glob + for f in glob.glob(os.path.join(ROOT, "tasks_gen", "train", "G*", "generation.json")): + tid = os.path.basename(os.path.dirname(f)) + if not json.load(open(f)).get("accepted"): + continue + k = mix.kind_of_task_dir(tid) + if tid not in done0: + waiting[k] = waiting.get(k, 0) + 1 + elif tid not in done1 and not first.get(tid): + second[k] = second.get(k, 0) + 1 + print("\nwaiting for a first run, per kind:", dict(sorted(waiting.items()))) + print("second attempt candidates (first attempt failed), per kind:", dict(sorted(second.items()))) + print("\nstart: python3 -m harness.pipeline (one controller only; it starts the generators, the K variants and the " + "trajectory workers; only kinds below target run; second attempts for failed tasks)") + + +if __name__ == "__main__": + main() diff --git a/scripts_probe/deltest.py b/scripts_probe/deltest.py new file mode 100644 index 0000000..c2f04c7 --- /dev/null +++ b/scripts_probe/deltest.py @@ -0,0 +1,41 @@ +"""Delete an object through ADT while a write on it is running (what happened on 2026-10-05 19:25).""" +import json, sys, threading, time +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness/scripts_probe") +from lockprobe import * +from killtest import MAIN, tc + +def attempt(delay, n, extra=40): + name = "ZPROBE0DL_%03d" % n + with McpClient() as m: + m.call("sap_create_object", {"objectType": "CLAS", "objectName": name, "packageName": "$TMP", "description": "delete race"}) + m.call("sap_push_source", {"objectType": "CLAS", "objectName": name, "source": MAIN.format(n=name.lower())}) + res = {} + def writer(): + with McpClient() as m: + res["t_write_start"] = time.time() + e, t = m.call("sap_push_source", {"objectType": "CLAS", "objectName": name, "includeType": "testclasses", "source": tc(extra)}) + res["write"] = t[:260] + res["t_write_end"] = time.time() + th = threading.Thread(target=writer); th.start() + time.sleep(delay) + res["delete_during_write"] = delete_uris(["/sap/bc/adt/oo/classes/" + name.lower()]) + th.join() + time.sleep(2) + with McpClient() as m: + res["enqueue"] = read_locks(m) + e, t = m.call("sap_push_element", {"objectType": "CLAS", "objectName": name, "element": "RUN", "source": " METHOD run.\n rv = 2.\n ENDMETHOD.\n"}) + res["follow_up"] = t[:200] + e, t = m.call("sap_search_object", {"query": name}) + res["still_exists"] = name in t + res["delete_after"] = delete_uris(["/sap/bc/adt/oo/classes/" + name.lower()]) if res["still_exists"] else "n/a" + res["name"], res["delay"] = name, delay + return res + +if __name__ == "__main__": + for i, d in enumerate(float(x) for x in sys.argv[1].split(",")): + r = attempt(d, int(sys.argv[2]) + i) + short = {k: v for k, v in r.items() if k not in ("t_write_start", "t_write_end")} + short["enqueue"] = short["enqueue"][:600] + print(json.dumps(short, indent=1)) + if "[LOCK]" in r["follow_up"] or "enqueue entries matching the probe prefixes: 0" not in r["enqueue"]: + print("POSSIBLE LEAK at delay", d, r["name"]); break diff --git a/scripts_probe/killcreate.py b/scripts_probe/killcreate.py new file mode 100644 index 0000000..3a3acee --- /dev/null +++ b/scripts_probe/killcreate.py @@ -0,0 +1,52 @@ +"""Two clients both CREATE and WRITE the same table at the same time (two controllers installing the seed of run 200273).""" +import json, os, signal, subprocess, sys, time +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness/scripts_probe") +from lockprobe import * +from killtabl import DDL + +VICTIM2 = r''' +import sys, json +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness") +from harness.adt_client import load_env; load_env("/Users/erhankeseli/projects/abap-llm/harness/.env") +from harness.mcp_client import McpClient +a = json.loads(sys.argv[1]) +m = McpClient().open() +print("SENT", flush=True) +m.call("sap_create_object", {"objectType": "TABL", "objectName": a["objectName"], "packageName": "$TMP", "description": "seed"}) +print("CREATED", flush=True) +m.call("sap_push_source", a) +print("DONE", flush=True) +''' +def attempt(delay, n): + name = "ZPROBE0K3_%03d" % n + args = {"objectType": "TABL", "objectName": name, "source": DDL.format(n=name.lower(), w=20 + n)} + ps = [subprocess.Popen([sys.executable, "-c", VICTIM2, json.dumps(args)], stdout=subprocess.PIPE, text=True) for _ in range(2)] + for p in ps: + assert p.stdout.readline().strip() == "SENT" + time.sleep(delay) + states = [] + for p in ps: + states.append("finished" if p.poll() is not None else "killed") + try: os.kill(p.pid, signal.SIGKILL) + except ProcessLookupError: pass + p.wait() + time.sleep(3) + out = {"name": name, "delay": delay, "victims": states} + with McpClient() as m: + out["enqueue"] = read_locks(m) + e, t = m.call("sap_push_source", {"objectType": "TABL", "objectName": name, "source": DDL.format(n=name.lower(), w=40 + n)}) + out["follow_up"] = t[:300] + e, t = m.call("sap_search_object", {"query": name}); out["exists"] = name in t + out["leak"] = "[LOCK]" in out["follow_up"] or "ZPROBE0K3" in out["enqueue"] + if out["exists"]: + out["delete"] = {k.split("/")[-1]: (v["deleted"], v["msg"]) for k, v in delete_uris(["/sap/bc/adt/ddic/tables/" + name.lower()]).items()} + return out + +if __name__ == "__main__": + n = int(sys.argv[2]) + for d in (float(x) for x in sys.argv[1].split(",")): + o = attempt(d, n); n += 1 + o["enqueue"] = o["enqueue"][:1200] + print(json.dumps(o, indent=1)) + if o["leak"]: + print("LEAK at delay", d, "object", o["name"]); break diff --git a/scripts_probe/killtabl.py b/scripts_probe/killtabl.py new file mode 100644 index 0000000..eb533a6 --- /dev/null +++ b/scripts_probe/killtabl.py @@ -0,0 +1,51 @@ +"""Controlled kill during the activation of a DDIC table (database table creation takes seconds).""" +import json, os, signal, subprocess, sys, time +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness/scripts_probe") +from lockprobe import * +from killtest import VICTIM + +DDL = """@EndUserText.label : 'kill test' +@AbapCatalog.enhancement.category : #NOT_EXTENSIBLE +@AbapCatalog.tableCategory : #TRANSPARENT +@AbapCatalog.deliveryClass : #A +@AbapCatalog.dataMaintenance : #RESTRICTED +define table {n} {{ + key client : abap.clnt not null; + key item_id : abap.char(10) not null; + qty : abap.int4; + name : abap.char({w}); +}}""" + +def attempt(delay, n): + name = "ZPROBE0KT_%03d" % n + with McpClient() as m: + print("create", m.call("sap_create_object", {"objectType": "TABL", "objectName": name, "packageName": "$TMP", "description": "kill table"})[1][:50]) + # first write alone, to learn how long it takes + args = {"objectType": "TABL", "objectName": name, "source": DDL.format(n=name.lower(), w=20 + n)} + p = subprocess.Popen([sys.executable, "-c", VICTIM, json.dumps(args)], stdout=subprocess.PIPE, text=True) + assert p.stdout.readline().strip() == "SENT" + t0 = time.time(); time.sleep(delay) + finished = p.poll() is not None + try: + os.kill(p.pid, signal.SIGKILL) + except ProcessLookupError: + finished = True + p.wait() + print("table write: victim %s after %.2f s" % ("had finished" if finished else "killed", time.time() - t0)) + time.sleep(3) + out = {"name": name, "delay": delay, "finished_before_kill": finished} + with McpClient() as m: + out["enqueue"] = read_locks(m) + e, t = m.call("sap_push_source", {"objectType": "TABL", "objectName": name, "source": DDL.format(n=name.lower(), w=40 + n)}) + out["second_write"] = t[:300] + out["leak"] = "[LOCK]" in out["second_write"] or ("ZPROBE0KT" in out["enqueue"] and "enqueue entries matching the probe prefixes: 0" not in out["enqueue"]) + out["delete"] = delete_uris(["/sap/bc/adt/ddic/tables/" + name.lower()]) + return out + +if __name__ == "__main__": + for i, d in enumerate(float(x) for x in sys.argv[1].split(",")): + o = attempt(d, int(sys.argv[2]) + i) + o["enqueue"] = o["enqueue"][:900] + print(json.dumps(o, indent=1)) + if o["leak"]: + print("LEAK at delay", d, "object", o["name"]); break diff --git a/scripts_probe/killtest.py b/scripts_probe/killtest.py new file mode 100644 index 0000000..86d7752 --- /dev/null +++ b/scripts_probe/killtest.py @@ -0,0 +1,71 @@ +"""Controlled kill: a client sends sap_push_source (testclasses include) and is killed with SIGKILL `delay` seconds +after the request left. Then the enqueue table is read and a second write is tried.""" +import json, os, signal, subprocess, sys, time +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness/scripts_probe") +from lockprobe import * + +MAIN = """CLASS {n} DEFINITION PUBLIC FINAL CREATE PUBLIC. + PUBLIC SECTION. + METHODS run RETURNING VALUE(rv) TYPE i. +ENDCLASS. +CLASS {n} IMPLEMENTATION. + METHOD run. + rv = 1. + ENDMETHOD. +ENDCLASS. +""" +def tc(extra): + body = "".join(" cl_abap_unit_assert=>assert_equals( act = %d exp = %d ).\n" % (i, i) for i in range(extra)) + return ("CLASS ltc DEFINITION FINAL FOR TESTING DURATION SHORT RISK LEVEL HARMLESS.\n PRIVATE SECTION.\n METHODS t1 FOR TESTING.\n" + "ENDCLASS.\nCLASS ltc IMPLEMENTATION.\n METHOD t1.\n" + body + " ENDMETHOD.\nENDCLASS.\n") + +VICTIM = r''' +import sys, json +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness") +from harness.adt_client import load_env; load_env("/Users/erhankeseli/projects/abap-llm/harness/.env") +from harness.mcp_client import McpClient +args = json.loads(sys.argv[1]) +m = McpClient().open() +print("SENT", flush=True) +m.call("sap_push_source", args) +print("DONE", flush=True) +''' + +def attempt(delay, n, extra=40): + name = "ZPROBE0KL_%03d" % n + with McpClient() as m: + print("create", m.call("sap_create_object", {"objectType": "CLAS", "objectName": name, "packageName": "$TMP", "description": "kill test"})[1][:60]) + print("main ", m.call("sap_push_source", {"objectType": "CLAS", "objectName": name, "source": MAIN.format(n=name.lower())})[1][:70]) + args = {"objectType": "CLAS", "objectName": name, "includeType": "testclasses", "source": tc(extra)} + p = subprocess.Popen([sys.executable, "-c", VICTIM, json.dumps(args)], stdout=subprocess.PIPE, text=True) + assert p.stdout.readline().strip() == "SENT" + t0 = time.time() + time.sleep(delay) + done_before_kill = p.poll() is not None + try: + os.kill(p.pid, signal.SIGKILL) + except ProcessLookupError: + done_before_kill = True + p.wait() + print("victim killed %.2f s after the request was sent (finished before kill: %s)" % (time.time() - t0, done_before_kill)) + time.sleep(3) + out = {"name": name, "delay": delay} + with McpClient() as m: + out["enqueue"] = read_locks(m) + e, t = m.call("sap_push_source", {"objectType": "CLAS", "objectName": name, "includeType": "testclasses", "source": tc(extra + 1)}) + out["second_write"] = t[:300] + e, t = m.call("sap_push_element", {"objectType": "CLAS", "objectName": name, "element": "RUN", "source": " METHOD run.\n rv = 2.\n ENDMETHOD.\n"}) + out["push_element"] = t[:300] + out["leak"] = "currently editing" in out["second_write"] or "[LOCK]" in out["second_write"] or "[LOCK]" in out["push_element"] + if not out["leak"]: + out["delete"] = delete_uris(["/sap/bc/adt/oo/classes/" + name.lower()]) + return out + +if __name__ == "__main__": + delays = [float(x) for x in sys.argv[1].split(",")] + n0 = int(sys.argv[2]) if len(sys.argv) > 2 else 1 + for i, d in enumerate(delays): + o = attempt(d, n0 + i, int(sys.argv[3]) if len(sys.argv) > 3 else 40) + print(json.dumps({k: (v if k != "enqueue" else v[:700]) for k, v in o.items()}, indent=1)) + if o["leak"]: + print("LEAK at delay", d, "- stopping, object", o["name"], "needs SM12"); break diff --git a/scripts_probe/killtwo.py b/scripts_probe/killtwo.py new file mode 100644 index 0000000..1e7cee3 --- /dev/null +++ b/scripts_probe/killtwo.py @@ -0,0 +1,42 @@ +"""Two clients write the same table at the same time (what two controllers did with run 200273); both are killed.""" +import json, os, signal, subprocess, sys, time +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness/scripts_probe") +from lockprobe import * +from killtest import VICTIM +from killtabl import DDL + +def attempt(delay, n): + name = "ZPROBE0K2_%03d" % n + with McpClient() as m: + m.call("sap_create_object", {"objectType": "TABL", "objectName": name, "packageName": "$TMP", "description": "two writers"}) + args = {"objectType": "TABL", "objectName": name, "source": DDL.format(n=name.lower(), w=20 + n)} + ps = [subprocess.Popen([sys.executable, "-c", VICTIM, json.dumps(args)], stdout=subprocess.PIPE, text=True) for _ in range(2)] + for p in ps: + assert p.stdout.readline().strip() == "SENT" + time.sleep(delay) + states = [] + for p in ps: + states.append("finished" if p.poll() is not None else "killed") + try: + os.kill(p.pid, signal.SIGKILL) + except ProcessLookupError: + pass + p.wait() + time.sleep(3) + out = {"name": name, "delay": delay, "victims": states} + with McpClient() as m: + out["enqueue"] = read_locks(m) + e, t = m.call("sap_push_source", {"objectType": "TABL", "objectName": name, "source": DDL.format(n=name.lower(), w=40 + n)}) + out["follow_up"] = t[:300] + out["leak"] = "[LOCK]" in out["follow_up"] or ("ZPROBE0K2" in out["enqueue"]) + out["delete"] = {k.split("/")[-1]: v["deleted"] for k, v in delete_uris(["/sap/bc/adt/ddic/tables/" + name.lower()]).items()} + return out + +if __name__ == "__main__": + n = int(sys.argv[2]) + for d in (float(x) for x in sys.argv[1].split(",")): + o = attempt(d, n); n += 1 + o["enqueue"] = o["enqueue"][:1200] + print(json.dumps(o, indent=1)) + if o["leak"]: + print("LEAK at delay", d, "object", o["name"]); break diff --git a/scripts_probe/lockprobe.py b/scripts_probe/lockprobe.py new file mode 100644 index 0000000..64e0df6 --- /dev/null +++ b/scripts_probe/lockprobe.py @@ -0,0 +1,58 @@ +"""Lock leak probe helpers (no cloud, A4H only): the enqueue reader class and a controlled kill of a writing client.""" +import json, os, signal, subprocess, sys, time +sys.path.insert(0, "/Users/erhankeseli/projects/abap-llm/harness") +from harness.adt_client import load_env +load_env("/Users/erhankeseli/projects/abap-llm/harness/.env") +from harness.mcp_client import McpClient +from harness.runner import delete_uris + +READER = "ZPROBE0EQ_LOCKS" +READER_SRC = """CLASS zprobe0eq_locks DEFINITION PUBLIC FINAL CREATE PUBLIC. + PUBLIC SECTION. + INTERFACES if_oo_adt_classrun. +ENDCLASS. +CLASS zprobe0eq_locks IMPLEMENTATION. + METHOD if_oo_adt_classrun~main. + DATA lt_enq TYPE STANDARD TABLE OF seqg3 WITH DEFAULT KEY. + DATA lv_subrc TYPE sy-subrc. + CALL FUNCTION 'ENQUEUE_READ' + EXPORTING gclient = sy-mandt gname = '' garg = '' guname = '' + IMPORTING subrc = lv_subrc + TABLES enq = lt_enq + EXCEPTIONS communication_failure = 1 system_failure = 2 OTHERS = 3. + DATA(lv_n) = 0. + LOOP AT lt_enq ASSIGNING FIELD-SYMBOL() WHERE garg CS 'ZPROBE0' OR garg CS 'Z4AJ' OR garg CS 'Z4AE'. + lv_n = lv_n + 1. + DATA(lv_line) = ||. + DO. + ASSIGN COMPONENT sy-index OF STRUCTURE TO FIELD-SYMBOL(). + IF sy-subrc <> 0. EXIT. ENDIF. + DATA(lo_d) = CAST cl_abap_structdescr( cl_abap_typedescr=>describe_by_data( ) ). + DATA(lv_name) = lo_d->components[ sy-index ]-name. + IF IS NOT INITIAL. + lv_line = lv_line && lv_name && '=' && condense( |{ }| ) && ' '. + ENDIF. + ENDDO. + out->write( lv_line ). + ENDLOOP. + out->write( |enqueue entries matching the probe prefixes: { lv_n } of { lines( lt_enq ) } (subrc { lv_subrc })| ). + ENDMETHOD. +ENDCLASS. +""" + +def ensure_reader(m): + e, t = m.call("sap_search_object", {"query": READER}) + if READER not in t: + m.call("sap_create_object", {"objectType": "CLAS", "objectName": READER, "packageName": "$TMP", "description": "enqueue reader probe"}) + e, t = m.call("sap_push_source", {"objectType": "CLAS", "objectName": READER, "source": READER_SRC}) + if '"success":true' not in t.replace(" ", ""): + print("reader activation:", t[:600]) + +def read_locks(m): + e, t = m.call("sap_run_class", {"className": READER}) + return t + +if __name__ == "__main__": + with McpClient() as m: + ensure_reader(m) + print(read_locks(m)[:2500])