Skip to content

Commit 91b6eae

Browse files
ITHwangclaude
andauthored
feat(env): inter-turn idle instrumentation for LocalREPL (BR002-WO002) (#5)
Ports PyWasmEnv's idle-timing schema to the native env so latency-on idle structure compares directly across envs: execute wall/active accumulation, inter-turn idle windows backdated to the last execute end (initial root wait uncounted), per-request reset via warm_reset, and runtime_timing() fractions. Mid-execute park is deliberately NOT instrumented (BR002-CL005) — active is an upper bound. Additive only; stock behavior unchanged. 5 new tests. Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
1 parent dbd9343 commit 91b6eae

3 files changed

Lines changed: 157 additions & 1 deletion

File tree

‎rlm/environments/local_repl.py‎

Lines changed: 84 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -177,6 +177,15 @@ def __init__(
177177
self.original_cwd = os.getcwd()
178178
self.temp_dir = tempfile.mkdtemp(prefix=f"repl_env_{uuid.uuid4()}_")
179179
self._lock = threading.Lock()
180+
# Inter-turn idle instrumentation (RLM Lab, BR002-WO002): mirrors
181+
# PyWasmEnv's timing fields so native and wasm idle structure compare
182+
# directly. Mid-execute park is deliberately NOT instrumented here
183+
# (BR002-CL005) — active_seconds therefore includes nested llm_query
184+
# waits and is an upper bound on true active time.
185+
self._timing_lock = threading.Lock()
186+
self._timing = self._new_idle_timing()
187+
self._last_execute_ended_at: float | None = None
188+
self._inter_turn_idle_started_at: float | None = None
180189
self._context_count: int = 0
181190
self._history_count: int = 0
182191
self.compaction = compaction
@@ -597,15 +606,89 @@ def execute_code(self, code: str) -> REPLResult:
597606
final_answer = self._last_final_answer
598607
self._last_final_answer = None
599608

609+
end_time = time.perf_counter()
610+
with self._timing_lock:
611+
wall = max(0.0, end_time - start_time)
612+
self._timing["execute_wall_seconds"] += wall
613+
self._timing["active_seconds"] += wall
614+
self._timing["execute_count"] += 1
615+
self._last_execute_ended_at = end_time
616+
600617
return REPLResult(
601618
stdout=stdout,
602619
stderr=stderr,
603620
locals=self.locals.copy(),
604-
execution_time=time.perf_counter() - start_time,
621+
execution_time=end_time - start_time,
605622
rlm_calls=self._pending_llm_calls.copy(),
606623
final_answer=final_answer,
607624
)
608625

626+
# -- Inter-turn idle instrumentation (RLM Lab, BR002-WO002) ------------- #
627+
628+
@staticmethod
629+
def _new_idle_timing() -> dict[str, float | int]:
630+
return {
631+
"execute_wall_seconds": 0.0,
632+
"active_seconds": 0.0,
633+
"mid_execute_park_seconds": 0.0, # not instrumented (BR002-CL005)
634+
"inter_turn_idle_seconds": 0.0,
635+
"execute_count": 0,
636+
"mid_execute_park_count": 0,
637+
"inter_turn_idle_count": 0,
638+
}
639+
640+
def reset_idle_timing(self) -> None:
641+
with self._timing_lock:
642+
self._timing = self._new_idle_timing()
643+
self._last_execute_ended_at = None
644+
self._inter_turn_idle_started_at = None
645+
646+
def begin_inter_turn_idle(self) -> None:
647+
"""Mark that the session is awaiting the next root-model response.
648+
649+
Idle is backdated to the last execute's end so the interval matches
650+
PyWasmEnv's boundary (execute-return -> next code execution). The
651+
initial root wait (no prior REPL state) is deliberately not counted.
652+
"""
653+
with self._timing_lock:
654+
if (
655+
self._last_execute_ended_at is not None
656+
and self._inter_turn_idle_started_at is None
657+
):
658+
self._inter_turn_idle_started_at = self._last_execute_ended_at
659+
660+
def end_inter_turn_idle(self) -> None:
661+
with self._timing_lock:
662+
if self._inter_turn_idle_started_at is None:
663+
return
664+
now = time.perf_counter()
665+
self._timing["inter_turn_idle_seconds"] += max(
666+
0.0, now - self._inter_turn_idle_started_at
667+
)
668+
self._timing["inter_turn_idle_count"] += 1
669+
self._inter_turn_idle_started_at = None
670+
self._last_execute_ended_at = None
671+
672+
def runtime_timing(self) -> dict[str, Any]:
673+
with self._timing_lock:
674+
timing = dict(self._timing)
675+
if self._inter_turn_idle_started_at is not None:
676+
timing["inter_turn_idle_seconds"] += max(
677+
0.0, time.perf_counter() - self._inter_turn_idle_started_at
678+
)
679+
active = float(timing["active_seconds"])
680+
inter_turn = float(timing["inter_turn_idle_seconds"])
681+
mid_execute = float(timing["mid_execute_park_seconds"])
682+
observed = active + inter_turn + mid_execute
683+
timing["observed_seconds"] = observed
684+
timing["active_fraction"] = active / observed if observed else 0.0
685+
timing["inter_turn_idle_fraction"] = inter_turn / observed if observed else 0.0
686+
timing["mid_execute_park_fraction"] = (
687+
mid_execute / observed if observed else 0.0
688+
)
689+
timing["mid_execute_park_instrumented"] = False
690+
return timing
691+
609692
def __enter__(self):
610693
return self
611694

‎rlm/environments/warm_reset.py‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -53,3 +53,9 @@ def reset_for_request(env: "LocalREPL") -> None:
5353
if env.compaction:
5454
env._compaction_history = []
5555
env.locals["history"] = env._compaction_history
56+
57+
# Reset per-request idle timing (RLM Lab, BR002-WO002) so a reused warm env
58+
# reports each task's idle structure like a fresh environment.
59+
reset_timing = getattr(env, "reset_idle_timing", None)
60+
if callable(reset_timing):
61+
reset_timing()

‎tests/test_local_repl.py‎

Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -291,3 +291,70 @@ def test_simulated_rlm_completions_functions_not_preserved(self):
291291
assert "NameError" in result.stderr
292292
assert "my_helper" in result.stderr
293293
completion_2_env.cleanup()
294+
295+
296+
class TestLocalREPLIdleTiming:
297+
"""Inter-turn idle instrumentation (RLM Lab, BR002-WO002) — mirrors the
298+
PyWasmEnv timing contract on the native env."""
299+
300+
def test_execute_accumulates_active_time(self):
301+
repl = LocalREPL()
302+
try:
303+
repl.execute_code("x = 1")
304+
timing = repl.runtime_timing()
305+
assert timing["execute_count"] == 1
306+
assert timing["active_seconds"] > 0.0
307+
assert timing["execute_wall_seconds"] == timing["active_seconds"]
308+
assert timing["mid_execute_park_instrumented"] is False
309+
finally:
310+
repl.cleanup()
311+
312+
def test_inter_turn_idle_backdates_to_last_execute_end(self):
313+
import time as _time
314+
315+
repl = LocalREPL()
316+
try:
317+
repl.execute_code("x = 1")
318+
_time.sleep(0.05)
319+
repl.begin_inter_turn_idle() # backdates to the execute end
320+
repl.end_inter_turn_idle()
321+
timing = repl.runtime_timing()
322+
assert timing["inter_turn_idle_count"] == 1
323+
assert timing["inter_turn_idle_seconds"] >= 0.04
324+
finally:
325+
repl.cleanup()
326+
327+
def test_initial_root_wait_is_uncounted(self):
328+
repl = LocalREPL()
329+
try:
330+
repl.begin_inter_turn_idle() # no execute yet -> not an idle window
331+
repl.end_inter_turn_idle()
332+
assert repl.runtime_timing()["inter_turn_idle_count"] == 0
333+
finally:
334+
repl.cleanup()
335+
336+
def test_open_idle_window_included_in_runtime_timing(self):
337+
repl = LocalREPL()
338+
try:
339+
repl.execute_code("x = 1")
340+
repl.begin_inter_turn_idle()
341+
timing = repl.runtime_timing() # window still open
342+
assert timing["inter_turn_idle_seconds"] >= 0.0
343+
assert timing["active_fraction"] <= 1.0
344+
finally:
345+
repl.cleanup()
346+
347+
def test_reset_idle_timing_clears_all_counters(self):
348+
repl = LocalREPL()
349+
try:
350+
repl.execute_code("x = 1")
351+
repl.begin_inter_turn_idle()
352+
repl.end_inter_turn_idle()
353+
repl.reset_idle_timing()
354+
timing = repl.runtime_timing()
355+
assert timing["execute_count"] == 0
356+
assert timing["active_seconds"] == 0.0
357+
assert timing["inter_turn_idle_count"] == 0
358+
assert timing["inter_turn_idle_seconds"] == 0.0
359+
finally:
360+
repl.cleanup()

0 commit comments

Comments
 (0)