Add rollout start time and latency display

Author: benjibc

eval_protocol/integrations/tinker_rollout_processor.py

@@ -2,6 +2,7 @@
 import logging
 import os
 import time
+from datetime import datetime, timezone
 import traceback
 from typing import Any, Dict, List, Optional, Union
 
@@ -76,6 +77,8 @@ def __call__(self, rows: List[EvaluationRow], config: RolloutProcessorConfig) ->
         """Generate rollout tasks using Tinker."""
 
         async def process_row(row: EvaluationRow) -> EvaluationRow:
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
 
             if not row.messages:

eval_protocol/mcp/execution/manager.py

@@ -11,6 +11,7 @@
 import os
 import threading
 import time
+from datetime import datetime, timezone
 from dataclasses import asdict
 from typing import TYPE_CHECKING, Any, Callable, Dict, List, Optional, Union, cast
 
@@ -97,6 +98,8 @@ def execute_rollouts(
         async def _execute_with_semaphore(idx):
             async with semaphore:
                 evaluation_row: EvaluationRow = evaluation_rows[idx]
+                if evaluation_row.execution_metadata.rollout_start_time is None:
+                    evaluation_row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
                 row_start_time = time.perf_counter()
 
                 trajectory = await self._execute_rollout(

eval_protocol/models.py

@@ -793,6 +793,11 @@ class CostMetrics(BaseModel):
 class ExecutionMetadata(BaseModel):
     """Metadata about the execution of the evaluation."""
 
+    rollout_start_time: Optional[datetime] = Field(
+        default=None,
+        description="UTC timestamp when the rollout started.",
+    )
+
     invocation_id: Optional[str] = Field(
         default_factory=generate_id,
         description="The ID of the invocation that this row belongs to.",

eval_protocol/pytest/default_agent_rollout_processor.py

@@ -3,6 +3,7 @@
 import logging
 import os
 import time
+from datetime import datetime, timezone
 from typing import Any, AsyncIterator, List, Optional, Union, Dict
 
 from mcp.types import CallToolResult, TextContent
@@ -249,6 +250,8 @@ def __call__(self, rows: List[EvaluationRow], config: RolloutProcessorConfig) ->
 
         async def process_row(row: EvaluationRow) -> EvaluationRow:
             """Process a single row with agent rollout."""
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
 
             agent = Agent(

eval_protocol/pytest/default_klavis_sandbox_rollout_processor.py

@@ -4,6 +4,7 @@
 import os
 import tempfile
 import time
+from datetime import datetime, timezone
 from typing import Any, Callable, Dict, List, Optional
 
 from pydantic import BaseModel, Field
@@ -66,7 +67,8 @@ def __call__(
 
         async def process_row(row: EvaluationRow) -> EvaluationRow:
             """Process a single row with complete sandbox lifecycle"""
-            
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
             agent: Agent | None = None
             temp_config_path: str | None = None

eval_protocol/pytest/default_pydantic_ai_rollout_processor.py

@@ -4,6 +4,7 @@
 from collections.abc import Callable
 import logging
 import time
+from datetime import datetime, timezone
 from pydantic_ai.toolsets import FunctionToolset
 from pydantic_ai.usage import UsageLimits
 from typing_extensions import override
@@ -50,6 +51,8 @@ def __call__(self, rows: list[EvaluationRow], config: RolloutProcessorConfig) ->
 
         async def process_row(row: EvaluationRow) -> EvaluationRow:
             """Process a single row with agent rollout."""
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
 
             tools = []

eval_protocol/pytest/default_single_turn_rollout_process.py

@@ -3,6 +3,7 @@
 import logging
 import os
 import time
+from datetime import datetime, timezone
 from dataclasses import asdict, is_dataclass
 from types import SimpleNamespace
 from typing import Any, List
@@ -62,6 +63,8 @@ def __call__(self, rows: List[EvaluationRow], config: RolloutProcessorConfig) ->
 
         async def process_row(row: EvaluationRow) -> EvaluationRow:
             """Process a single row asynchronously."""
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
 
             if len(row.messages) == 0:

eval_protocol/pytest/github_action_rollout_processor.py

@@ -67,6 +67,8 @@ def __call__(self, rows: List[EvaluationRow], config: RolloutProcessorConfig) ->
         max_pages = (num_rows + 99) // 100  # Round up pages
 
         async def _process_row(row: EvaluationRow) -> EvaluationRow:
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
 
             if row.execution_metadata.invocation_id is None:

eval_protocol/pytest/openenv_rollout_processor.py

@@ -15,6 +15,7 @@
 import asyncio
 import logging
 import time
+from datetime import datetime, timezone
 from itertools import count
 from typing import List, Any, Dict, Callable, Generic, TypeVar, Optional, Type
 
@@ -167,6 +168,8 @@ def __call__(self, rows: List[EvaluationRow], config: RolloutProcessorConfig) ->
 
         async def process_row(row: EvaluationRow) -> EvaluationRow:
             """Process a single row with OpenEnv rollout."""
+            if row.execution_metadata.rollout_start_time is None:
+                row.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
             start_time = time.perf_counter()
 
             logger.info("[OpenEnvRolloutProcessor] Starting rollout for row")

eval_protocol/pytest/priority_scheduler.py

@@ -3,6 +3,7 @@
 import logging
 import os
 import time
+from datetime import datetime, timezone
 from collections import defaultdict
 from dataclasses import dataclass, field
 from typing import Any, List, Dict, Optional, Union
@@ -293,6 +294,8 @@ async def _run_eval(rows_to_eval: Union[EvaluationRow, List[EvaluationRow]]):
 
         # 3. Execute the rollout
         result_row: Optional[EvaluationRow] = None
+        if row_copy.execution_metadata.rollout_start_time is None:
+            row_copy.execution_metadata.rollout_start_time = datetime.now(timezone.utc)
         start_time = time.perf_counter()
         try:
             async for result in rollout_processor_with_retry(