Class: Raif::Evals::RunLog

Inherits:
Object
  • Object
show all
Defined in:
lib/raif/evals/run_log.rb

Overview

An append-only JSON Lines log of a run: a header line carrying the run's identity and the plan it set out to execute, then one line per eval result as that result completes.

A run's results file is only written once every eval set has finished, so without this a run killed partway through would lose every result it had already paid for. raif evals --resume reads the log back so that work is not bought twice.

The plan is what makes the log the authority on whether the run is done - see Raif::Evals::RunPlan. Without it a resume could only ask itself, and an invocation narrowed to one eval set file would answer yes while most of the run was still outstanding.

Defined Under Namespace

Classes: IncompatibleResumeError

Constant Summary collapse

PARTIAL_SUFFIX = 
".partial.jsonl"
PROVENANCE_KEYS =

Configuration keys the log records to describe the run rather than to constrain a resume. The code the run started against is one: insisting on it would strand the results of any run interrupted across a commit. Raif::Evals::Run warns when it moved instead.

["code"].freeze
DATASETS_KEY =

Compared specially - see .dataset_differences.

"datasets"

Instance Attribute Summary collapse

Class Method Summary collapse

Instance Method Summary collapse

Constructor Details

#initialize(path:, run_at:, configuration:, plan:, results: {}, recorded_keys: nil, prior_elapsed_seconds: 0) ⇒ RunLog

Returns a new instance of RunLog.



34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
 
# File 'lib/raif/evals/run_log.rb', line 34

def initialize(path:, run_at:, configuration:, plan:, results: {}, recorded_keys: nil, prior_elapsed_seconds: 0)
  @path = Pathname.new(path.to_s)
  @run_at = run_at
  @configuration = configuration
  @plan = plan
  @results = results
  @recorded_keys = recorded_keys || Set.new
  # Time spent by earlier invocations of a resumed run, so the elapsed time the results file
  # records covers the time evals were running and not the gap between a stop and a resume.
  @prior_elapsed_seconds = prior_elapsed_seconds.to_f
  @invocation_started_at = Process.clock_gettime(Process::CLOCK_MONOTONIC)
  # Concurrent evals record into one log. The append is one File.open per LLM-bound eval,
  # so serializing the whole of #record costs nothing next to what produced the result.
  @mutex = Mutex.new
end

Instance Attribute Details

#configuration ⇒ Object (readonly)

Returns the value of attribute configuration.



32
33
34
 
# File 'lib/raif/evals/run_log.rb', line 32

def configuration
  @configuration
end

#path ⇒ Object (readonly)

Returns the value of attribute path.



32
33
34
 
# File 'lib/raif/evals/run_log.rb', line 32

def path
  @path
end

#plan ⇒ Object (readonly)

Returns the value of attribute plan.



32
33
34
 
# File 'lib/raif/evals/run_log.rb', line 32

def plan
  @plan
end

#results ⇒ Object (readonly)

Returns the value of attribute results.



32
33
34
 
# File 'lib/raif/evals/run_log.rb', line 32

def results
  @results
end

#run_at ⇒ Object (readonly)

Returns the value of attribute run_at.



32
33
34
 
# File 'lib/raif/evals/run_log.rb', line 32

def run_at
  @run_at
end

Class Method Details

.json_round_trip(result) ⇒ Object

A result hash after the trip through JSON the log itself puts it through, for a caller that has to move one somewhere Marshal cannot follow: an eval's metadata can hold anything, and JSON renders what Marshal would refuse.



128
129
130
 
# File 'lib/raif/evals/run_log.rb', line 128

def json_round_trip(result)
  normalize_result(JSON.parse(JSON.generate(result), symbolize_names: true))
end

.key(eval_id:, case_id:, run_index:) ⇒ Object

The tuple that identifies one execution in the results JSON: which eval block, against which case, on which repeat. The eval id already carries the eval set it belongs to, so this key is unique across every set in the run.



279
280
281
 
# File 'lib/raif/evals/run_log.rb', line 279

def self.key(eval_id:, case_id:, run_index:)
  [eval_id.to_s, case_id&.to_s, run_index]
end

.logged_configuration(path) ⇒ Object

The configuration a log was started with, read without opening it for writing. A resumed run needs one value out of it - the seed - before it can state its own configuration. Returns nil for anything that is not a readable log; #resume is what reports on that.



118
119
120
121
122
123
 
# File 'lib/raif/evals/run_log.rb', line 118

def logged_configuration(path)
  header = read(path)[:header]
  header && header[:configuration]
rescue SystemCallError
  nil
end

.resume(path:, configuration:, plan:) ⇒ Object

Reopens an interrupted run's log. The whole configuration has to match - see Run#configuration_data.

Parameters:

  • plan (Raif::Evals::RunPlan) —

    what the resuming invocation itself covers, which for a resume narrowed to one file is a fraction of the run. Reconciled against the logged plan rather than replacing it - see #extend_plan!.



75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
 
# File 'lib/raif/evals/run_log.rb', line 75

def resume(path:, configuration:, plan:)
  log = read(path)
  header = log[:header]

  if header.nil?
    raise IncompatibleResumeError, "#{path} has no run header line, so it is not a Raif eval run log."
  end

  if log[:unidentified_results].positive?
    raise IncompatibleResumeError, "Refusing to resume #{path}: #{log[:unidentified_results]} of its results were written " \
      "before evals had ids, so there is no way to tell which of this run's executions they cover. Start a new run."
  end

  logged_plan = read_plan(path, log[:plan_records])

  differences = configuration_differences(header[:configuration], configuration)
  unless differences.empty?
    raise IncompatibleResumeError, <<~MSG.strip
      Refusing to resume #{path}: this run was started with different settings.

      #{differences.join("\n")}

      Re-run with the settings the log was started with, or drop --resume to start a new run.
    MSG
  end

  run_log = new(
    path: path,
    run_at: header[:run_at],
    configuration: configuration,
    plan: logged_plan,
    results: log[:results],
    recorded_keys: log[:recorded_keys],
    prior_elapsed_seconds: log[:elapsed_seconds]
  )

  run_log.extend_plan!(plan)
  run_log
end

.start(results_dir:, basename:, run_at:, configuration:, plan:) ⇒ Object

Starts a fresh log and writes its header, so a run that dies before its first result still leaves a file that identifies what was being run and what it owes.



53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
 
# File 'lib/raif/evals/run_log.rb', line 53

def start(results_dir:, basename:, run_at:, configuration:, plan:)
  FileUtils.mkdir_p(results_dir)

  log = new(
    path: File.join(results_dir, "#{basename}#{PARTIAL_SUFFIX}"),
    run_at: run_at,
    configuration: configuration,
    plan: plan
  )

  # Truncating, unlike every write after it: a stale log left at the same path by an
  # abandoned run of the same second would otherwise gain a second header.
  log.send(:write_header, { type: "run", run_at: run_at, plan: plan.to_h, configuration: configuration })
  log
end

Instance Method Details

#complete? ⇒ Boolean

Returns:

  • (Boolean) 


311
312
313
 
# File 'lib/raif/evals/run_log.rb', line 311

def complete?
  outstanding_keys.empty?
end

#discard! ⇒ Object

Called once the final results file is written, and on a run that died before recording anything, where a header-only log is nothing to resume.



370
371
372
 
# File 'lib/raif/evals/run_log.rb', line 370

def discard!
  FileUtils.rm_f(path)
end

#display_path ⇒ Object

For console output, where the absolute path is long enough to wrap in a terminal.



375
376
377
378
379
 
# File 'lib/raif/evals/run_log.rb', line 375

def display_path
  path.relative_path_from(Rails.root).to_s
rescue StandardError
  path.to_s
end

#elapsed_seconds ⇒ Object

Seconds the run has spent running evals, across every invocation. Time after an invocation's last result is lost if it is killed outright, but that time recorded nothing.



317
318
319
 
# File 'lib/raif/evals/run_log.rb', line 317

def elapsed_seconds
  @prior_elapsed_seconds + (Process.clock_gettime(Process::CLOCK_MONOTONIC) - @invocation_started_at)
end

#extend_plan!(other) ⇒ Object

Adds executions the run did not originally plan and appends them to the log, so a later resume owes them too. An eval block added to a file while the run was interrupted is the case: Raif::Evals::Run warns about the code moving rather than refusing, so the new eval runs, and the run is not complete until it has.

Returns the keys that were new.



293
294
295
296
297
298
299
300
301
302
303
 
# File 'lib/raif/evals/run_log.rb', line 293

def extend_plan!(other)
  added = plan.additions(other)
  return [] if added.empty?

  @mutex.synchronize do
    append({ type: "plan", plan: RunPlan.new(keys: added).to_h })
    @plan = plan.plus(added)
  end

  added
end

#outstanding_keys ⇒ Object

The planned executions no result has been recorded for. Empty is what makes the run finishable: see Raif::Evals::Run#export_results.



307
308
309
 
# File 'lib/raif/evals/run_log.rb', line 307

def outstanding_keys
  @mutex.synchronize { plan.outstanding(@recorded_keys) }
end

#record(eval_set:, result:) ⇒ Object

Appends one result and returns the hash that was written.



322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
 
# File 'lib/raif/evals/run_log.rb', line 322

def record(eval_set:, result:)
  payload = result.to_h

  @mutex.synchronize do
    append({ type: "result", eval_set: eval_set, elapsed_seconds: elapsed_seconds.round(3), result: payload })

    (@results[eval_set] ||= []) << payload
    @recorded_keys << self.class.key(
      eval_id: payload[:eval_id],
      case_id: payload[:case_id],
      run_index: payload[:run_index]
    )
  end

  payload
end

#recorded?(eval_id:, case_id: nil, run_index: nil) ⇒ Boolean

Returns:

  • (Boolean) 


283
284
285
 
# File 'lib/raif/evals/run_log.rb', line 283

def recorded?(eval_id:, case_id: nil, run_index: nil)
  @recorded_keys.include?(self.class.key(eval_id: eval_id, case_id: case_id, run_index: run_index))
end

#results_count ⇒ Object 



364
365
366
 
# File 'lib/raif/evals/run_log.rb', line 364

def results_count
  @results.values.sum(&:count)
end

#results_for(eval_set) ⇒ Object

A copy, so a caller counting results cannot be walking the array a concurrent #record is pushing onto.



341
342
343
 
# File 'lib/raif/evals/run_log.rb', line 341

def results_for(eval_set)
  @mutex.synchronize { (@results[eval_set] || []).dup }
end

#results_path ⇒ Object

Derived from the log's own path so a resumed run completes the file its first attempt was headed for, rather than opening a second one describing the same run.



359
360
361
362
 
# File 'lib/raif/evals/run_log.rb', line 359

def results_path
  name = path.to_s
  name.end_with?(PARTIAL_SUFFIX) ? Pathname.new(name.delete_suffix(PARTIAL_SUFFIX) + ".json") : Pathname.new("#{name}.json")
end

#snapshot ⇒ Object

Everything a reader on another thread needs, copied under one lock so the counts agree with each other: a result cannot land between reading the results and reading what is outstanding. Only the copies are taken under the lock, since #record waits on it. What is outstanding is worked out from them afterwards.



349
350
351
352
353
354
355
 
# File 'lib/raif/evals/run_log.rb', line 349

def snapshot
  results, recorded_keys, current_plan = @mutex.synchronize do
    [@results.transform_values(&:dup), @recorded_keys.dup, plan]
  end

  { results: results, plan: current_plan, outstanding: current_plan.outstanding(recorded_keys) }
end