search

dje-dev / Ceres

Ceres - an MCTS chess engine for research and recreation
GNU General Public License v3.0
153 stars 23 forks source link

Occasional early match termination in cutechess #11

Closed dje-dev closed 3 years ago

dje-dev commented 3 years ago

Tinker reports Ceres "getting time losses" on about 1 out of 10 games at 30 seconds + 1 second using cutechess. He kindly provided a sample log.

Initial investigation of the cutechess log does not explain this. Actually although Ceres was indeed on move when it stopped, cutechess does not claim that Ceres lost, it does not adjudicate it in favor of the opponent (as it usually would) with if there were a crash, i.e. we do not see any see entries such as:

Aug 10 08:35:01  io.elementary.cerbere.desktop[2026]: Engine Lc0(0) failed to respond to ping
Aug 10 08:35:01  io.elementary.cerbere.desktop[2026]: Terminating process of engine Lc0(0)

Instead we just see that it asked Ceres to stop thinking after 1.1seconds following a go command in which Ceres was informed it had 11.799 seconds left on its clock (before increment). Cutechess then marks it as "unterminated."

So the reason for cutechess ending the game/tournament is unknown. It may well be a Ceres bug, but there does not seem to be evidence of that (yet).

2210312 >ceres(20): isready
2210312 <ceres(20): readyok
2210312 >ceres(20): go wtime 11799 btime 14471 winc 1000 binc 1000
2210414 <ceres(20): info depth 0 seldepth 17 time 102 nodes 26244 score cp -5 tbhits 0 nps 10713 pv c3c4 e5c5 b5d6 e7d6 d1d6 c5c4 a4b5 c4c3 f3d5 c3c2 a5a6 c8a6 d6a6 g6g5 a6a7 c2f2 b5c4  string M= 115
2210931 <ceres(20): info depth 2 seldepth 17 time 619 nodes 35448 score cp -6 tbhits 2 nps 16636 pv c3c4 e5c5 b5d6 e7d6 d1d6 c5c4 a4b5 c4c3 f3d5 c3c2 a5a6 c8a6 d6a6 g6g5 a6a7 c2f2 b5c4  string M= 103
2211431 <ceres(20): info depth 3 seldepth 6 time 1119 nodes 46040 score cp -5 tbhits 2 nps 18658 pv c3c4 e7c5 b5d6 c8d7 d6b5 d7c8  string M= 92
2211478 >ceres(20): stop
dje-dev commented 3 years ago

CORRECTION. Tinker pointed out the timeout was in an earlier game in the log file. It seems to be a timing issue, initial testing of Ceres was on high end hardware and also used a timemargin setting in cutechess testing. So the Ceres internal time buffer will be increased to correct this problem.

dje-dev commented 3 years ago

This is believed fixed. Ceres had previously made the incorrect assumption that the time increment is awarded at the beginning of a move, but actually should be awarded only after. This is fixed in commit 969e7ac6b89b04e353e6bdccca8e699b6b3915b3.