learn: engine_trace worker renders request params through the production _render; records query stderr

The worker sent tuple params as JSON arrays; taint.sc expects comma-joined
strings (ujson InvalidData, exit 1). Implemented with Codex.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

benchmarks/learn/engine_trace_worker.py

@@ -18,7 +18,7 @@ import time
 from collections import Counter
 from pathlib import Path
 
-from openultrasast.cpg.backend import JoernBackend
+from openultrasast.cpg.backend import JoernBackend, _render
 from openultrasast.model.trace import parse_trace
 
 
@@ -141,6 +141,17 @@ class MeasuredBackend(JoernBackend):
                 "oom": b"OutOfMemoryError" in output,
             }
             self.stages.append(stage)
+            if query and process.returncode != 0:
+                # stderr is merged into stdout above; drop JVM frames before taking
+                # the tail so they cannot crowd out the exception's message.
+                lines = [
+                    line.strip()
+                    for line in output.decode(errors="replace").splitlines()
+                    if line.strip() and not line.strip().startswith(("at ", "... "))
+                ]
+                stage["output_tail"] = "\n".join(lines[-20:])
+                if not self.timed_out:
+                    self.fatal = f"joern query exited {process.returncode}"
             if frontend:
                 # Capture the exact frontend output before build failure cleanup or overlays.
                 output_arg = next((i + 1 for i, arg in enumerate(command[:-1]) if arg in {"-o", "--output"}), None)
@@ -149,7 +160,7 @@ class MeasuredBackend(JoernBackend):
                 stage["cpg_bytes"] = cpg_path.stat().st_size if cpg_path is not None and cpg_path.is_file() else 0
                 if stage["cpg_bytes"] <= MIN_CPG_BYTES:
                     self.fatal = "frontend wrote no CPG"
-            elif elapsed < 5:
+            elif elapsed < 5 and not self.fatal:
                 self.fatal = f"implausibly fast JVM step: {command[0]} in {elapsed:.3f}s (<5s)"
         if b"OutOfMemoryError" in output:
             self.fatal = "JVM out of memory"
@@ -222,7 +233,7 @@ def worker_language(pin, root, out, deadline, question_deadline, persist=write_j
         if len(languages) != 1:
             raise ValueError(f"one pin has multiple frontend languages: {sorted(languages)}")
         language = next(iter(languages))
-        requests = pin["questions"]
+        requests = {rid: {key: _render(value) for key, value in params.items()} for rid, params in pin["questions"].items()}
         if set(requests) != {u["unit"] for u in active}:
             raise ValueError("prepared questions do not match supported units")
         record["questions"] = requests
@@ -304,6 +315,12 @@ def worker_language(pin, root, out, deadline, question_deadline, persist=write_j
     finally:
         if cpg and cpg.cleanup:
             cpg.cleanup()
+        for stage in backend.stages:
+            if stage["command"] == "joern" and stage.get("exit") and "output_tail" in stage:
+                detail = f"joern query exited {stage['exit']}: {stage['output_tail'] or 'no output'}"
+                for row in record["units"]:
+                    if row["supported"]:
+                        row["reason"] = f"{row['reason']}\n{detail}".strip()
         record["questions_asked"] = list(dict.fromkeys(backend.asked))
         record["questions_completed"] = [rid for u in record["units"] for rid in u["questions_completed"]]
         record["done"] = True

tests/test_engine_trace.py

@@ -189,6 +189,94 @@ def test_worker_one_batch_and_preserves_witnesses(tmp_path, monkeypatch):
     assert result["instrument"]["files"][0]["bytes"] > 0
 
 
+@pytest.mark.parametrize("json_roundtrip", [False, True])
+def test_worker_writes_string_requests_for_php_and_python(tmp_path, monkeypatch, json_roundtrip):
+    written = {}
+    submitted = {}
+
+    class RequestBackend(worker.MeasuredBackend):
+        def build(self, root, language):
+            graph = root / f"{language}.bin"
+            graph.write_bytes(b"x" * 2048)
+            self.stages.append({"command": "joern-parse", "seconds": 20, "exit": 0, "cpg_bytes": 2048})
+
+            def batch(query, requests):
+                submitted.update(requests)
+                return self._batch_once(graph, query, requests)
+
+            return CpgResult(graph, lambda q, p: None, run_batch_once=batch)
+
+        def _run(self, command, **kwargs):
+            request_file = Path(next(arg.split("=", 1)[1] for arg in command if arg.startswith("requestsFile=")))
+            data = request_file.read_bytes()
+            print(f"read {request_file.name}: {len(data)} bytes")
+            requests = json.loads(data)
+            written.update(requests)
+            self.asked.extend(requests)
+            self.stages.append({"command": "joern", "seconds": 20, "exit": 0})
+            answers = {**dict.fromkeys(requests, []), "__census__": [{"files": "1", "file_names": ["app.php", "app.py"]}]}
+            return subprocess.CompletedProcess(command, 0, BEGIN + "\n" + json.dumps(answers) + "\n" + END, "")
+
+    monkeypatch.setattr(worker, "MeasuredBackend", RequestBackend)
+    (tmp_path / "app.php").write_text("<?php function run() {}\n")
+    (tmp_path / "app.py").write_text("def run(): pass\n")
+    pin = {"units": [unit("php", language="php", file="app.php"), unit("python")]}
+    pin["questions"] = trace.prepare_questions(pin, tmp_path, 120)
+    assert all(isinstance(params["sources"], tuple) and params["sources"] for params in pin["questions"].values())
+    expected = {rid: ",".join(sorted(params["sources"])) for rid, params in pin["questions"].items()}
+    # Cover both direct tuple callers and arrays decoded from the host's pin.json.
+    if json_roundtrip:
+        pin = json.loads(json.dumps(pin))
+    out = tmp_path / "result.json"
+    worker.worker(pin, tmp_path, out, 900, 120)
+    result = json.loads(out.read_text())
+    assert all(row["status"] == "asked-nothing" for row in result["units"])
+    assert set(written) == set(submitted) == {"php", "python"}
+    for requests in (written, submitted, {rid: p for row in result["units"] for rid, p in row["questions"].items()}):
+        assert all(isinstance(value, str) for params in requests.values() for value in params.values())
+        assert {rid: params["sources"] for rid, params in requests.items()} == expected
+
+
+def test_failed_query_records_non_stack_stderr_tail_in_unit_reason(tmp_path, monkeypatch):
+    error = 'ujson.Value$InvalidData: Expected ujson.Str (data: ["$_COOKIE","$_GET"])'
+    joern = tmp_path / "joern"
+    joern.write_text(
+        f"#!{sys.executable}\nimport sys\n"
+        "print('read bytes:', len(open(sys.argv[-1], 'rb').read()), flush=True)\n"
+        "for i in range(25): print(f'diagnostic {i}', file=sys.stderr)\n"
+        f"print({error!r}, file=sys.stderr)\n"
+        "for i in range(30): print(f'\\tat example.Frame.method(Frame.java:{i})', file=sys.stderr)\n"
+        "print('\\t... 30 more', file=sys.stderr)\n"
+        "sys.exit(1)\n"
+    )
+    joern.chmod(0o755)
+
+    class FailedQueryBackend(worker.MeasuredBackend):
+        def build(self, root, language):
+            graph = root / "graph.bin"
+            graph.write_bytes(b"x" * 2048)
+            self.stages.append({"command": "joern-parse", "seconds": 20, "exit": 0, "cpg_bytes": 2048})
+
+            def batch(query, requests):
+                done = self._run([str(joern), "--script", str(root / "app.py")], timeout=10, cwd=root)
+                assert done.returncode == 1
+                assert "read bytes: 20" in done.stdout
+                return None
+
+            return CpgResult(graph, lambda q, p: None, run_batch_once=batch)
+
+    result = run_fake(tmp_path, monkeypatch, FailedQueryBackend)
+    stage = result["instrument"]["jvm"][-1]
+    assert stage["exit"] == 1
+    assert stage["output_tail"].splitlines() == [*[f"diagnostic {i}" for i in range(6, 25)], error]
+    for row in result["units"]:
+        assert row["status"] == "failed"
+        assert "joern query exited 1" in row["reason"]
+        assert error in row["reason"]
+        assert "Frame.java" not in row["reason"]
+        assert "implausibly fast" not in row["reason"]
+
+
 @pytest.mark.parametrize("failure", ["fast", "zero-input", "zero-census"])
 def test_invalid_instrument_is_persisted_failed(tmp_path, monkeypatch, failure):
     class BadBackend(FakeBackend):