search (bug): null move returned while pondering

[tissatussa]

hi, i successfully compiled your v0.1.0 code on Linux and Mess seems to run fine in CuteChess -- then this happened :

here's the CuteChess engine debug log tail :

<Mess v0.1.0(13): bestmove d7c5 ponder e7f6
>SF Fat Titz Hybrid(12): ponderhit
>Mess v0.1.0(13): position fen 8/p5pp/1pk5/5p2/P1nn4/2NN3P/5PPK/8 w - - 0 1 moves h2g3 h7h6 g3h4 g7g6 g2g4 f5f4 d3f4 g6g5 h4h5 g5f4 h5h6 c4e5 h6g7 c6d6 g7f6 e5d7 f6f7 d4f3 c3b5 d6d5 f7e7 d7c5 e7f6
>Mess v0.1.0(13): isready
<Mess v0.1.0(13): readyok
>Mess v0.1.0(13): go ponder wtime 428668 btime 368847 winc 3000 binc 3000
<SF Fat Titz Hybrid(12): info depth 30 seldepth 59 multipv 1 score cp -413 nodes 17252590 nps 895866 hashfull 735 tbhits 0 time 19258 pv e7f6 f3h4 f6g5 h4g2 h3h4 c5e4 g5f5 e4f2 b5c3 d5d4 h4h5 f4f3 h5h6 f2d3 c3d1 g2e3 f5g5 e3d1 h6h7 f3f2 h7h8q d4e3 h8f6 e3d2 f6f7 d1e3 f7a2 d2c3 a2a1 c3c2 a1a2 d3b2 a2a3 f2f1q a3e3 f1c4 e3f4 c4g8 g5f5 g8f8 f5e4 f8e8 e4f5 e8d7 f5g5 d7g7 g5h5
<SF Fat Titz Hybrid(12): bestmove e7f6 ponder f3h4
>Mess v0.1.0(13): ponderhit
>SF Fat Titz Hybrid(12): position fen 8/p5pp/1pk5/5p2/P1nn4/2NN3P/5PPK/8 w - - 0 1 moves h2g3 h7h6 g3h4 g7g6 g2g4 f5f4 d3f4 g6g5 h4h5 g5f4 h5h6 c4e5 h6g7 c6d6 g7f6 e5d7 f6f7 d4f3 c3b5 d6d5 f7e7 d7c5 e7f6 f3h4
>SF Fat Titz Hybrid(12): isready
<SF Fat Titz Hybrid(12): readyok
>SF Fat Titz Hybrid(12): go ponder wtime 431668 btime 368847 winc 3000 binc 3000
<Mess v0.1.0(13): bestmove 0000
>SF Fat Titz Hybrid(12): stop
>Mess v0.1.0(13): isready
<SF Fat Titz Hybrid(12): info string Hybrid NNUE evaluation enabled.
<SF Fat Titz Hybrid(12): info depth 1 seldepth 1 multipv 1 score cp -413 nodes 79 nps 79000 tbhits 0 time 1 pv f6g5
<SF Fat Titz Hybrid(12): info depth 2 seldepth 2 multipv 1 score cp -413 nodes 118 nps 118000 tbhits 0 time 1 pv f6g5 h4g2
<SF Fat Titz Hybrid(12): info depth 3 seldepth 3 multipv 1 score cp -421 nodes 279 nps 279000 tbhits 0 time 1 pv f6g5 h4g2 g5g6
<SF Fat Titz Hybrid(12): info depth 4 seldepth 4 multipv 1 score cp -421 nodes 420 nps 420000 tbhits 0 time 1 pv f6g5 h4g2 g5g6 c5e4
<SF Fat Titz Hybrid(12): info depth 5 seldepth 5 multipv 1 score cp -421 nodes 536 nps 268000 tbhits 0 time 2 pv f6g5 h4g2 g5g6 c5e4 g4g5
<SF Fat Titz Hybrid(12): info depth 6 seldepth 5 multipv 1 score cp -421 nodes 720 nps 360000 tbhits 0 time 2 pv f6g5 h4g2 g5g6 c5e4 g4g5
<SF Fat Titz Hybrid(12): bestmove f6g5 ponder h4g2
>SF Fat Titz Hybrid(12): isready
<Mess v0.1.0(13): readyok
<SF Fat Titz Hybrid(12): readyok

here's the game, from a certain starting position :

[Event "engine vs engine"]
[Site "Holland"]
[Date "2023.03.03"]
[Round "?"]
[White "SF Fat Titz Hybrid"]
[Black "Mess v0.1.0"]
[Result "1-0"]
[FEN "8/p5pp/1pk5/5p2/P1nn4/2NN3P/5PPK/8 w - - 0 1"]
[GameDuration "00:07:54"]
[PlyCount "23"]
[SetUp "1"]
[Termination "illegal move"]
[TimeControl "600+3"]

1. Kg3 {-4.16/28 16s} h6 {+1.21/27 30s} 2. Kh4 {-3.15/24 6.7s} g6 {+1.23/29 29s}
3. g4 {-3.43/31 18s} f4 {+2.01/32 28s} 4. Nxf4 {-2.71/25 7.9s}
g5+ {+2.11/30 26s} 5. Kh5 {-2.99/32 15s} gxf4 {+2.23/31 25s}
6. Kxh6 {-3.73/32 48s} Ne5 {24s} 7. Kg7 {-3.80/33 40s} Kd6 {+2.18/30 23s}
8. Kf6 {-4.26/30 19s} Nd7+ {22s} 9. Kf7 {-4.37/32 19s} Nf3 {+2.42/28 21s}
10. Nb5+ {-3.78/23 7.8s} Kd5 {+2.18/27 20s} 11. Ke7 {-3.73/29 11s}
Nc5 {+2.41/30 19s} 12. Kf6 {-4.13/30 0s, Black makes an illegal move: 0000} 1-0

[raklaptudirm]

Mess's pondering is probably a bit bugged right now. From the logs, it seems like Mess received the ponderhit command extremely fast after the go ponder. It probably wasn't able to start a search before the ponderhit command was received. That said, this issue needs some investigation. Thank you for the information.

[raklaptudirm]

@tissatussa Could you provide the average nps which Mess was reporting during this tournament?

[tissatussa]

it was not a tournament, it was a single game .. i showed the tail log lines, it's all i have .. mess does not output extensive info lines, like the opponent, having nps data .. however, running another game (6m3s) from normal starting position, mess DOES output such info lines and so i see an nps around 700000 upto 1 milion ..

[raklaptudirm]

With 1 Mnps, the issue of the ponderhit command arriving too fast can be discarded. The main issue which I see is that Mess was not reporting info properly for some reason, which is weird since it does print an info string for each depth it completes. This suggests that there was some misconfiguration when setting up the problematic game, though I have no idea what. Please do report if this occurs again.

[tissatussa]

Please do report if this occurs again

OK, i will do that.

btw. i do not always use Ponder -- it's a checkbox in CuteChess called "Thinking on opponent's time", but not all engines support it. I remember that game had Ponder ON. Might the Ponder option have been the cause of the problem ? Or do you have no clue ?

[raklaptudirm]

btw. i do not always use Ponder -- it's a checkbox in CuteChess called "Thinking on opponent's time", but not all engines support it. I remember that game had Ponder ON. Might the Ponder option have been the cause of the problem ? Or do you have no clue ?

As I said:

Mess's pondering is probably a bit bugged right now.

So yeah, probably.