log eval time

[mayinghan]

Note

Adds precise evaluation timing to aid performance analysis.

• In pointwise mode, wrap each eval with a timer and set result.execution_metadata.eval_duration_seconds
• In groupwise mode, time the grouped eval once and assign the same duration to each row in results
• In all-mode, time the dataset-wide eval and propagate eval_duration_seconds to all returned rows

^{Written by Cursor Bugbot for commit 6bfe52e. This will update automatically on new commits. Configure here.}

[xzrderek]

looks good. it will also measure the time it takes waiting for the sema, that is intended right?

[cursor]

Eval duration includes semaphore wait time, not just execution

The start_time is captured before async with semaphore:, which means eval_duration_seconds includes time spent waiting for the semaphore, not just the actual evaluation execution time. When concurrent evaluations compete for semaphore slots, reported durations will be artificially inflated. The start_time assignment needs to be moved inside the async with semaphore: block to measure only the actual evaluation time.

Additional Locations (1)

• eval_protocol/pytest/evaluation_test.py#L516-L517

 

[cursor]

Duration set before element type validation causes AttributeError

The new loop at lines 636-637 accesses r.execution_metadata.eval_duration_seconds before the validation at lines 638-642 confirms all elements are EvaluationRow instances. If the test function returns a list containing non-EvaluationRow objects, this will raise an AttributeError instead of the helpful ValueError with guidance. This is inconsistent with the pointwise case where validation occurs before setting the duration.

 

[mayinghan]

@xzrderek yes