Add depth based logging

src/search/iterative_deepening.rs

@@ -1,6 +1,9 @@
+use std::io;
+
 use crate::{
     board::game::Game,
     evaluation::{MAX_SCORE, MIN_SCORE},
+    interface::uci::{write_response, Response},
     movegen::r#move::Move,
 };
 
@@ -22,6 +25,8 @@ pub fn iterative_deepening(
             return Ok(best_move);
         }
 
+        let mut total_nodes_searched = 0;
+
         let score = negamax::negamax(
             game,
             MIN_SCORE,
@@ -29,6 +34,7 @@ pub fn iterative_deepening(
             depth,
             0,
             &TimeInfo::new(time, remaining_time),
+            &mut total_nodes_searched,
         );
 
         if score.is_err() {
@@ -37,10 +43,44 @@ pub fn iterative_deepening(
 
         best_score = score?;
         best_move = game.tt.lookup(game.hash).and_then(|entry| entry.mv);
+
+        let nps = ((total_nodes_searched * 1_000_000) as u128).div_ceil(time.elapsed().as_micros())
+            as u64;
+
+        write_response(
+            &mut io::stdout(),
+            &search_info(
+                depth,
+                time.elapsed().as_millis() as u64,
+                total_nodes_searched,
+                nps,
+                best_score,
+                best_move,
+            ),
+        )?;
     }
     Ok(best_move)
 }
 
+fn search_info(
+    depth: u8,
+    time: u64,
+    total_nodes_searched: u64,
+    nps: u64,
+    best_score: i32,
+    best_move: Option<Move>,
+) -> Response {
+    Response::Info(format!(
+        "info depth {} time {} nodes {} nps {} eval {} pv {}",
+        depth,
+        time,
+        total_nodes_searched,
+        nps,
+        best_score,
+        best_move.expect("msg: No best move found")
+    ))
+}
+
 #[cfg(test)]
 mod tests {
     use crate::{

src/search/negamax.rs

@@ -19,6 +19,7 @@ pub fn negamax(
     depth: u8,
     plies: u8,
     time_info: &TimeInfo,
+    total_nodes_searched: &mut u64,
 ) -> Result<i32> {
     if hard_limit(&time_info.time, time_info.remaining_time_in_ms) {
         bail!("Time is up! In Negamax");
@@ -29,7 +30,8 @@ pub fn negamax(
     }
 
     if depth == 0 {
-        let q_score = quiescence(game, alpha, beta, time_info).map_err(|e| anyhow!("{e}"))?;
+        let q_score = quiescence(game, alpha, beta, time_info, total_nodes_searched)
+            .map_err(|e| anyhow!("{e}"))?;
         return Ok(q_score);
     }
 
@@ -49,15 +51,39 @@ pub fn negamax(
             game.unmake_move();
             continue;
         }
-
         legal_moves += 1;
+        *total_nodes_searched += 1;
 
         let score = if legal_moves == 1 {
-            -negamax(game, -beta, -alpha, depth - 1, plies + 1, time_info)?
+            -negamax(
+                game,
+                -beta,
+                -alpha,
+                depth - 1,
+                plies + 1,
+                time_info,
+                total_nodes_searched,
+            )?
         } else {
-            let mut score = -negamax(game, -alpha - 1, -alpha, depth - 1, plies + 1, time_info)?;
+            let mut score = -negamax(
+                game,
+                -alpha - 1,
+                -alpha,
+                depth - 1,
+                plies + 1,
+                time_info,
+                total_nodes_searched,
+            )?;
             if score > alpha && score < beta {
-                score = -negamax(game, -beta, -alpha, depth - 1, plies + 1, time_info)?;
+                score = -negamax(
+                    game,
+                    -beta,
+                    -alpha,
+                    depth - 1,
+                    plies + 1,
+                    time_info,
+                    total_nodes_searched,
+                )?;
             }
             score
         };
@@ -110,7 +136,7 @@ mod tests {
 
         let e3f2 = Move::new(Square::E3, Square::F2);
         let time_info = TimeInfo::new(std::time::Instant::now(), 1000);
-        negamax(&mut game, MIN_SCORE, MAX_SCORE, 2, 0, &time_info)
+        negamax(&mut game, MIN_SCORE, MAX_SCORE, 2, 0, &time_info, &mut 0)
             .expect("Expected a search result");
 
         assert_eq!(e3f2, game.tt.lookup(game.hash).unwrap().mv.unwrap());
@@ -118,7 +144,7 @@ mod tests {
         let mut game = from_fen(FEN_MATE_IN_1[1]).unwrap();
 
         let e3f2 = Move::new(Square::E3, Square::F2);
-        negamax(&mut game, MIN_SCORE, MAX_SCORE, 2, 0, &time_info)
+        negamax(&mut game, MIN_SCORE, MAX_SCORE, 2, 0, &time_info, &mut 0)
             .expect("Expected a search result");
 
         assert_eq!(e3f2, game.tt.lookup(game.hash).unwrap().mv.unwrap());

src/search/quiescence.rs

@@ -7,7 +7,13 @@ use super::{
     time::{hard_limit, TimeInfo},
 };
 
-pub fn quiescence(game: &mut Game, mut alpha: i32, beta: i32, time_info: &TimeInfo) -> Result<i32> {
+pub fn quiescence(
+    game: &mut Game,
+    mut alpha: i32,
+    beta: i32,
+    time_info: &TimeInfo,
+    total_nodes_searched: &mut u64,
+) -> Result<i32> {
     if hard_limit(&time_info.time, time_info.remaining_time_in_ms) {
         bail!("Time is up! In Quiescence");
     }
@@ -36,11 +42,11 @@ pub fn quiescence(game: &mut Game, mut alpha: i32, beta: i32, time_info: &TimeIn
             game.unmake_move();
             continue;
         }
+        *total_nodes_searched += 1;
 
-        let score = -quiescence(game, -beta, -alpha, time_info)?;
+        let score = -quiescence(game, -beta, -alpha, time_info, &mut 0)?;
         game.unmake_move();
 
-
         if score > best_score {
             best_score = score;
         }

src/search/transposition_table.rs

@@ -60,7 +60,7 @@ mod tests {
         let mut game = from_fen(FEN).unwrap();
         let time_info = TimeInfo::new(std::time::Instant::now(), 30000);
 
-        negamax(&mut game, MIN_SCORE, MAX_SCORE, 2, 0, &time_info)
+        negamax(&mut game, MIN_SCORE, MAX_SCORE, 2, 0, &time_info, &mut 0)
             .expect("Expected a search result");
 
         dbg!(time_info.time.elapsed());