1use std::fmt::Debug;
4use std::marker::PhantomData;
5use std::time::Instant;
6
7use rand::RngExt;
8use solverforge_core::domain::PlanningSolution;
9use solverforge_core::score::Score;
10use solverforge_scoring::Director;
11use tracing::{debug, info, trace};
12
13use crate::heuristic::r#move::Move;
14use crate::heuristic::selector::move_selector::{MoveCandidateRef, MoveCursor, MoveStreamContext};
15use crate::heuristic::selector::MoveSelector;
16use crate::phase::control::{
17 settle_search_interrupt, should_interrupt_after_step, should_interrupt_before_candidate,
18 should_interrupt_before_evaluation, StepInterrupt,
19};
20use crate::phase::localsearch::evaluation::{
21 evaluate_candidate, record_evaluated_move, CandidateEvaluation,
22};
23use crate::phase::localsearch::{Acceptor, LocalSearchForager};
24use crate::phase::Phase;
25use crate::scope::{PendingControl, ProgressCallback};
26use crate::scope::{PhaseScope, SolverScope, StepScope};
27use crate::stats::{format_duration, whole_units_per_second, AppliedMoveTelemetry};
28
29const STEP_ACCEPTED_LABEL_LIMIT: usize = 32;
30
31#[derive(Clone, Copy)]
32struct StepMoveLabelCount {
33 label: &'static str,
34 count: u64,
35}
36
37struct StepMoveLabelCounts {
38 entries: [StepMoveLabelCount; STEP_ACCEPTED_LABEL_LIMIT],
39 overflow: u64,
40}
41
42impl StepMoveLabelCounts {
43 const EMPTY_ENTRY: StepMoveLabelCount = StepMoveLabelCount {
44 label: "",
45 count: 0,
46 };
47
48 fn new() -> Self {
49 Self {
50 entries: [Self::EMPTY_ENTRY; STEP_ACCEPTED_LABEL_LIMIT],
51 overflow: 0,
52 }
53 }
54
55 fn record(&mut self, label: &'static str) {
56 for entry in &mut self.entries {
57 if entry.count > 0 && entry.label == label {
58 entry.count += 1;
59 return;
60 }
61 }
62 for entry in &mut self.entries {
63 if entry.count == 0 {
64 entry.label = label;
65 entry.count = 1;
66 return;
67 }
68 }
69 self.overflow += 1;
70 }
71
72 fn for_each_ignored_except_selected(
73 &self,
74 selected_label: Option<&'static str>,
75 mut visitor: impl FnMut(&'static str, u64),
76 ) {
77 let mut selected_remaining = selected_label;
78 for entry in &self.entries {
79 if entry.count == 0 {
80 continue;
81 }
82 let ignored = if selected_remaining == Some(entry.label) {
83 selected_remaining = None;
84 entry.count.saturating_sub(1)
85 } else {
86 entry.count
87 };
88 if ignored > 0 {
89 visitor(entry.label, ignored);
90 }
91 }
92 if self.overflow > 0 {
93 visitor("move", self.overflow);
94 }
95 }
96}
97
98pub struct LocalSearchPhase<S, M, MS, A, Fo>
119where
120 S: PlanningSolution,
121 M: Move<S>,
122 MS: MoveSelector<S, M>,
123 A: Acceptor<S>,
124 Fo: LocalSearchForager<S, M>,
125{
126 move_selector: MS,
127 acceptor: A,
128 forager: Fo,
129 step_limit: Option<u64>,
130 _phantom: PhantomData<fn() -> (S, M)>,
131}
132
133fn candidate_selector_label<S, M>(mov: &MoveCandidateRef<'_, S, M>) -> String
134where
135 S: PlanningSolution,
136 M: Move<S>,
137{
138 let move_label = mov.telemetry_label();
139 if mov.variable_name() == "compound_scalar" || mov.variable_name() == "conflict_repair" {
140 return format!("{}:{move_label}", mov.variable_name());
141 }
142 let mut label = None;
143 mov.for_each_affected_entity(&mut |affected| {
144 if label.is_none() {
145 label = Some(affected.variable_name.to_string());
146 }
147 });
148 label
149 .map(|variable| format!("{variable}:{move_label}"))
150 .unwrap_or_else(|| format!("move:{move_label}"))
151}
152
153impl<S, M, MS, A, Fo> LocalSearchPhase<S, M, MS, A, Fo>
154where
155 S: PlanningSolution,
156 M: Move<S> + 'static,
157 MS: MoveSelector<S, M>,
158 A: Acceptor<S>,
159 Fo: LocalSearchForager<S, M>,
160{
161 pub fn new(move_selector: MS, acceptor: A, forager: Fo, step_limit: Option<u64>) -> Self {
162 Self {
163 move_selector,
164 acceptor,
165 forager,
166 step_limit,
167 _phantom: PhantomData,
168 }
169 }
170}
171
172impl<S, M, MS, A, Fo> Debug for LocalSearchPhase<S, M, MS, A, Fo>
173where
174 S: PlanningSolution,
175 M: Move<S>,
176 MS: MoveSelector<S, M> + Debug,
177 A: Acceptor<S> + Debug,
178 Fo: LocalSearchForager<S, M> + Debug,
179{
180 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
181 f.debug_struct("LocalSearchPhase")
182 .field("move_selector", &self.move_selector)
183 .field("acceptor", &self.acceptor)
184 .field("forager", &self.forager)
185 .field("step_limit", &self.step_limit)
186 .finish()
187 }
188}
189
190impl<S, D, BestCb, M, MS, A, Fo> Phase<S, D, BestCb> for LocalSearchPhase<S, M, MS, A, Fo>
191where
192 S: PlanningSolution,
193 D: Director<S>,
194 BestCb: ProgressCallback<S>,
195 M: Move<S>,
196 MS: MoveSelector<S, M>,
197 A: Acceptor<S>,
198 Fo: LocalSearchForager<S, M>,
199{
200 fn solve(&mut self, solver_scope: &mut SolverScope<S, D, BestCb>) {
201 let mut phase_scope = PhaseScope::new(solver_scope, 0);
202 let phase_index = phase_scope.phase_index();
203
204 let mut last_step_score = phase_scope.calculate_score();
206
207 info!(
208 event = "phase_start",
209 phase = "Local Search",
210 phase_index = phase_index,
211 score = %last_step_score,
212 );
213
214 self.acceptor.phase_started(&last_step_score);
216
217 let start_time = Instant::now();
218 let mut local_moves_generated: u64 = 0;
219 let mut local_moves_evaluated: u64 = 0;
220 let mut last_progress_time = Instant::now();
221 let mut last_progress_moves: u64 = 0;
222 loop {
223 if phase_scope.solver_scope_mut().should_terminate() {
225 break;
226 }
227
228 if let Some(limit) = self.step_limit {
230 if phase_scope.step_count() >= limit {
231 break;
232 }
233 }
234
235 let mut step_scope = StepScope::new(&mut phase_scope);
236
237 let best_score = step_scope
242 .phase_scope()
243 .solver_scope()
244 .best_score()
245 .copied()
246 .unwrap_or(last_step_score);
247 self.forager.step_started(best_score, last_step_score);
248 self.acceptor.step_started();
249 let requires_move_signatures = self.acceptor.requires_move_signatures();
250
251 let mut interrupted_step = false;
252 let mut accepted_moves_this_step = 0u64;
253 let mut moves_generated_this_step = 0u64;
254 let mut moves_evaluated_this_step = 0u64;
255 let mut accepted_move_labels_this_step = StepMoveLabelCounts::new();
256 if should_interrupt_before_candidate(&step_scope) {
257 interrupted_step = true;
258 }
259 let generation_started = Instant::now();
260 let step_index = step_scope.step_index();
261 let stream_context = MoveStreamContext::new(
262 step_index,
263 step_scope
264 .phase_scope_mut()
265 .solver_scope_mut()
266 .rng()
267 .random::<u64>(),
268 self.forager.accepted_count_limit(),
269 );
270 let mut cursor = self
271 .move_selector
272 .open_cursor_with_context(step_scope.score_director(), stream_context);
273 step_scope
274 .phase_scope_mut()
275 .record_generation_time(generation_started.elapsed());
276
277 while !self.forager.is_quit_early() {
278 if interrupted_step || should_interrupt_before_candidate(&step_scope) {
279 interrupted_step = true;
280 break;
281 }
282 if step_scope
283 .phase_scope_mut()
284 .solver_scope_mut()
285 .should_terminate()
286 {
287 interrupted_step = true;
288 break;
289 }
290
291 let generation_started = Instant::now();
292 let Some(candidate_id) = cursor.next_candidate() else {
293 break;
294 };
295 let selector_index = cursor.selector_index(candidate_id);
296 let mov = cursor
297 .candidate(candidate_id)
298 .expect("discovered candidate id must remain borrowable");
299 let move_label = mov.telemetry_label();
300 let selector_label = selector_index.map(|_| candidate_selector_label(&mov));
301 let generation_elapsed = generation_started.elapsed();
302 local_moves_generated += 1;
303 moves_generated_this_step += 1;
304 step_scope
305 .phase_scope_mut()
306 .record_move_kind_generated(move_label);
307 if let Some(selector_index) = selector_index {
308 step_scope
309 .phase_scope_mut()
310 .record_selector_generated_move_with_label(
311 selector_index,
312 selector_label.as_deref().unwrap_or("selector"),
313 generation_elapsed,
314 );
315 } else {
316 step_scope
317 .phase_scope_mut()
318 .record_generated_move(generation_elapsed);
319 }
320
321 if should_interrupt_before_evaluation(&step_scope) {
322 interrupted_step = true;
323 break;
324 }
325 if step_scope
326 .phase_scope_mut()
327 .solver_scope_mut()
328 .should_terminate()
329 {
330 interrupted_step = true;
331 break;
332 }
333 local_moves_evaluated += 1;
334 moves_evaluated_this_step += 1;
335
336 if local_moves_evaluated & 0x1FFF == 0 {
337 let now = Instant::now();
338 if now.duration_since(last_progress_time).as_secs() >= 1 {
339 let current_speed = whole_units_per_second(
340 local_moves_evaluated - last_progress_moves,
341 now.duration_since(last_progress_time),
342 );
343 debug!(
344 event = "progress",
345 steps = step_scope.step_index(),
346 moves_generated = local_moves_generated,
347 moves_evaluated = local_moves_evaluated,
348 moves_accepted = step_scope.phase_scope().solver_scope().stats().moves_accepted,
349 score_calculations = step_scope.phase_scope().solver_scope().stats().score_calculations,
350 speed = current_speed,
351 acceptance_rate = format!(
352 "{:.1}%",
353 step_scope.phase_scope().solver_scope().stats().acceptance_rate() * 100.0
354 ),
355 current_score = %last_step_score,
356 best_score = %best_score,
357 );
358 step_scope.phase_scope().solver_scope().report_progress();
359 last_progress_time = now;
360 last_progress_moves = local_moves_evaluated;
361 }
362 }
363
364 let evaluation_started = Instant::now();
365 let move_score = match evaluate_candidate(
366 &mov,
367 &mut step_scope,
368 last_step_score,
369 selector_index,
370 evaluation_started,
371 ) {
372 CandidateEvaluation::Scored(score) => {
373 step_scope.phase_scope_mut().record_move_kind_evaluated(
374 move_label,
375 score.compare(&last_step_score),
376 );
377 score
378 }
379 CandidateEvaluation::NotDoable
380 | CandidateEvaluation::RejectedByHardImprovement(_)
381 | CandidateEvaluation::RejectedByScoreImprovement(_) => continue,
382 };
383 let move_signature = if requires_move_signatures {
384 Some(mov.tabu_signature(step_scope.score_director()))
385 } else {
386 None
387 };
388
389 let accepted = self.acceptor.is_accepted(
390 &last_step_score,
391 &move_score,
392 move_signature.as_ref(),
393 );
394
395 record_evaluated_move(&mut step_scope, selector_index, evaluation_started);
396 if accepted {
397 step_scope
398 .phase_scope_mut()
399 .record_move_kind_accepted(move_label);
400 accepted_move_labels_this_step.record(move_label);
401 if let Some(selector_index) = selector_index {
402 step_scope
403 .phase_scope_mut()
404 .record_selector_move_accepted(selector_index);
405 } else {
406 step_scope.phase_scope_mut().record_move_accepted();
407 }
408 accepted_moves_this_step += 1;
409 } else if let Some(selector_index) = selector_index {
410 step_scope
411 .phase_scope_mut()
412 .record_selector_move_acceptor_rejected(selector_index);
413 step_scope
414 .phase_scope_mut()
415 .record_move_kind_acceptor_rejected(
416 move_label,
417 move_score.compare(&last_step_score),
418 );
419 } else {
420 step_scope.phase_scope_mut().record_move_acceptor_rejected();
421 step_scope
422 .phase_scope_mut()
423 .record_move_kind_acceptor_rejected(
424 move_label,
425 move_score.compare(&last_step_score),
426 );
427 }
428
429 trace!(
430 event = "step",
431 step = step_scope.step_index(),
432 move_index = candidate_id.index(),
433 score = %move_score,
434 accepted = accepted,
435 );
436
437 if accepted {
438 self.forager.add_move_index(candidate_id, move_score);
439 }
440 }
441
442 if !interrupted_step && should_interrupt_after_step(&step_scope) {
443 interrupted_step = true;
444 }
445
446 let commit_interrupted_config_step = interrupted_step
447 && accepted_moves_this_step > 0
448 && matches!(
449 step_scope.pending_control(),
450 PendingControl::ConfigTerminationRequested
451 );
452 if interrupted_step && !commit_interrupted_config_step {
453 match settle_search_interrupt(&mut step_scope) {
454 StepInterrupt::Restart => continue,
455 StepInterrupt::TerminatePhase => break,
456 }
457 }
458
459 let mut accepted_move_signature = None;
461 if let Some((selected_index, selected_score)) = self.forager.pick_move_index() {
462 let selector_index = cursor.selector_index(selected_index);
463 let selected_move = cursor
464 .candidate(selected_index)
465 .expect("selected candidate id must remain borrowable until commit");
466 let selected_move_label = selected_move.telemetry_label();
467 if requires_move_signatures {
468 accepted_move_signature =
469 Some(selected_move.tabu_signature(step_scope.score_director()));
470 }
471 let previous_score = last_step_score;
472 step_scope.apply_committed_move(&selected_move);
473 if let Some(selector_index) = selector_index {
474 step_scope
475 .phase_scope_mut()
476 .record_selector_move_applied(selector_index);
477 } else {
478 step_scope.phase_scope_mut().record_move_applied();
479 }
480 step_scope.set_step_score(selected_score);
481 let score_improvement =
482 if previous_score.is_feasible() && selected_score > previous_score {
483 selected_score.to_scalar() - previous_score.to_scalar()
484 } else {
485 0.0
486 };
487 step_scope
488 .phase_scope_mut()
489 .record_move_kind_applied(selected_move_label, score_improvement);
490 if step_scope.phase_scope().can_record_applied_move_trace() {
491 let score_before = previous_score.to_scalar();
492 let score_after = selected_score.to_scalar();
493 step_scope
494 .phase_scope_mut()
495 .record_applied_move_trace(AppliedMoveTelemetry {
496 step_index,
497 move_label: selected_move_label,
498 selected_candidate_index: selected_index.index(),
499 moves_generated_this_step,
500 moves_evaluated_this_step,
501 moves_accepted_this_step: accepted_moves_this_step,
502 moves_forager_ignored_this_step: accepted_moves_this_step
503 .saturating_sub(1),
504 score_before,
505 score_after,
506 score_delta: score_after - score_before,
507 hard_feasible_before: previous_score.is_feasible(),
508 hard_feasible_after: selected_score.is_feasible(),
509 });
510 }
511
512 last_step_score = selected_score;
514
515 step_scope.phase_scope_mut().update_best_solution();
517 if accepted_moves_this_step > 1 {
518 step_scope
519 .phase_scope_mut()
520 .record_moves_forager_ignored(accepted_moves_this_step - 1);
521 accepted_move_labels_this_step.for_each_ignored_except_selected(
522 Some(selected_move_label),
523 |label, count| {
524 step_scope
525 .phase_scope_mut()
526 .record_move_kind_forager_ignored(label, count);
527 },
528 );
529 }
530 } else if accepted_moves_this_step > 0 {
531 step_scope
532 .phase_scope_mut()
533 .record_moves_forager_ignored(accepted_moves_this_step);
534 accepted_move_labels_this_step.for_each_ignored_except_selected(
535 None,
536 |label, count| {
537 step_scope
538 .phase_scope_mut()
539 .record_move_kind_forager_ignored(label, count);
540 },
541 );
542 }
543 self.acceptor
554 .step_ended(&last_step_score, accepted_move_signature.as_ref());
555
556 step_scope.complete();
557 }
558
559 self.acceptor.phase_ended();
561
562 let duration = start_time.elapsed();
563 let steps = phase_scope.step_count();
564 let stats = phase_scope.stats();
565 let speed = whole_units_per_second(stats.moves_evaluated, duration);
566 let acceptance_rate = stats.acceptance_rate() * 100.0;
567 let calc_speed = whole_units_per_second(stats.score_calculations, duration);
568
569 let best_score_str = phase_scope
570 .solver_scope()
571 .best_score()
572 .map(|s| format!("{}", s))
573 .unwrap_or_else(|| "none".to_string());
574
575 info!(
576 event = "phase_end",
577 phase = "Local Search",
578 phase_index = phase_index,
579 duration = %format_duration(duration),
580 steps = steps,
581 moves_generated = stats.moves_generated,
582 moves_evaluated = stats.moves_evaluated,
583 moves_accepted = stats.moves_accepted,
584 score_calculations = stats.score_calculations,
585 generation_time = %format_duration(stats.generation_time()),
586 evaluation_time = %format_duration(stats.evaluation_time()),
587 moves_speed = speed,
588 calc_speed = calc_speed,
589 acceptance_rate = format!("{:.1}%", acceptance_rate),
590 score = best_score_str,
591 );
592 }
593
594 fn phase_type_name(&self) -> &'static str {
595 "LocalSearch"
596 }
597}
598
599#[cfg(test)]
600mod tests;