Closed CPagador closed 1 month ago
rwbc
commented
2 months ago A few things here Carlos,
You should add that this was played with lot of concurrency (and how much for the given games above)?
Also as it is in old WB (no native uci support), was this played via Polyglot or HGMs adapter?
Finally a debug/log file for such a time loss would be really helpful, otherwise it will be difficult. Do you also have time losses in Cutechess e.g.?
Guenther
CPagador
commented
2 months ago Hi Guenther,
Yes, concurrency is 14/15 threads out of 16 threads available. The GUI is Winboard 4.6.2 and polyglot adapter is used for UCI engines. All engines play with the same conditions, not all of them lose on time. I am talking about close to 800 engines and only 4 or 5 engines lose on time. Why do I use old Winboard? Because WB is the only GUI that let me run a Swiss tournament with many games at the same time. Why not latest WB? I did try (imagine to install 800 engines, but I did), the problem was that more engines could run under old WB than in the latest WB, so to include more engines in my tournament I use WB 4.6.2.
I only use Cute Chess for FRC testing, and almost no time losses. In the last edition of my FRC tournament, 2520 games were played and only 3 time forfeits. Considering the time control is shorter 1'+0.5", I think the games lost on time percentage is very low.
About the debug file, with many games running on parallel the debug info would be overlapped in the winboard.debug file (unless there is a way to generate an independent debug file for each game, if you know how to do it, please let me know.)
I could run a gauntlet for Crab (only one instance of WB) and wait for time losses. It would be helpful if Crab had an option to create a log for each game played and see why it loses on time.
Carlos
CPagador
commented
2 months ago Ok, I got one game where Crab lost again on time, again having a decisive advantage.
Here is the game:
[Event "Computer Chess Game"]
[Site "DESKTOP-PIO4BDF"]
[Date "2024.09.30"]
[Round "9"]
[White "Crab 4.4.0 GS"]
[Black "Lishex 1.1.1"]
[Result "0-1"]
[TimeControl "180+2"]
[Annotator "6. +0.21 6... -0.10"]
1. e4 c5 2. Nc3 d6 3. Nf3 Nf6 4. d4 cxd4 5. Nxd4 a6 6. Be3 {+0.21/22 6} e5
{-0.10/27 7} 7. Nde2 {+0.07/26 12} Ng4 {+0.09/25 7} 8. Nd5 {+0.10/26 5}
Nxe3 {+0.07/25 7} 9. Nxe3 {+0.08/25 7} g6 {+0.11/27 7} 10. Nc3 {+0.18/26 5}
Nc6 {+0.05/25 7} 11. Bc4 {+0.20/26 6} Bg7 {+0.08/26 7} 12. Ncd5
{+0.26/25 6} Be6 {+0.00/23 6} 13. O-O {+0.30/25 7} O-O {-0.01/26 6} 14. c3
{+0.27/23 4} Rc8 {+0.01/25 6} 15. a4 {+0.34/22 9} Na5 {-0.10/23 6} 16. Ba2
{+0.53/24 7} Nc6 {-0.34/19 6} 17. Nc4 {+0.97/22 7} Kh8 {-0.66/23 6} 18.
Ndb6 {+0.97/24 4} Bxc4 {-0.49/25 6} 19. Nxc4 {+1.23/26 3} Rc7 {-0.61/27 6}
20. Qxd6 {+1.37/26 5} Rd7 {-0.79/24 6} 21. Qc5 {+1.39/24 4} f5 {-1.05/24 5}
22. exf5 {+1.82/24 5} gxf5 {-1.12/26 5} 23. Bb3 {+1.81/25 4} e4
{-1.20/23 5} 24. Rad1 {+1.87/25 4} Qe7 {-1.25/26 5} 25. Qe3 {+1.86/23 4}
Rdd8 {-1.14/25 5} 26. Qe2 {+1.60/22 4} Ne5 {-1.11/22 5} 27. Nxe5
{+1.53/23 5} Bxe5 {-1.24/26 5} 28. Bd5 {+1.49/20 4} Rd7 {-0.96/24 5} 29.
Bc4 {+1.44/19 3} Rfd8 {-1.08/25 5} 30. Rxd7 {+1.43/26 19} Qxd7 {-1.09/27 5}
31. Qh5 {+1.62/23 2.9} Rf8 {-1.06/24 5} 32. Bb3 {+1.47/23 15} Qe7
{-1.12/24 4} 33. Bd5 {+1.46/22 4} b6 {-0.98/24 4} 34. Rd1 {+1.48/22 2.5} a5
{-1.00/25 4} 35. Bc4 {+1.56/21 4} Bg7 {-0.96/23 4} 36. Qe2 {+1.47/23 5} Qg5
{-1.01/21 4} 37. Bb5 {+1.60/19 2.5} Qg6 {-0.91/23 4} 38. Qd2 {+1.63/24 2.6}
Be5 {-1.22/23 4} 39. Qd5 {+1.57/22 4} Bc7 {-1.16/26 4} 40. g3
{+1.72/22 2.3} Rd8 {-1.20/30 4} 41. Bd7 {+2.32/26 4} Rf8 {-1.50/23 4} 42.
Qc4 {+1.99/22 4} Bf4 {-1.66/21 4} 43. Be6 {+2.04/25 2.6} Be5 {-1.81/26 4}
44. Rd7 {+2.24/26 2.4} Qg5 {-1.99/27 4} 45. Rd5 {+2.69/26 2.3} Bg7
{-2.24/27 4} 46. Bxf5 {+2.81/25 3} e3 {-2.33/26 4} 47. fxe3 {+2.80/23 2.9}
Qxe3+ {-2.26/25 4} 48. Kg2 {+2.65/25 2.2} Re8 {-2.29/23 4} 49. Rd6
{+2.73/22 2.1} h6 {-2.39/23 3} 50. Bd3 {+3.30/22 2.1} Qc5 {-3.41/25 3} 51.
Qxc5 {+3.28/24 2.5} bxc5 {-3.65/28 3} 52. Kf3 {+3.58/27 2.1} Ra8
{-2.99/27 3} 53. Rd5 {+3.34/25 2.6} Bf8 {-3.20/28 3} 54. Rd7 {+3.48/25 3}
Rb8 {-3.18/30 3} 55. Bb5 {+3.58/28 2.0} Ra8 {-3.54/27 3} 56. Ke4
{+3.80/26 2.0} Re8+ {-3.04/28 3} 57. Kf5 {+4.04/27 3} Re7 {-3.84/29 3} 58.
Kg6 {+4.19/34 2.1} Rxd7 {-4.18/36 3} 59. Bxd7 {+4.29/38 2.0} Bg7
{-4.36/36 3} 60. Be6 {+5.68/38 6} Bf8 {-3.81/38 3} 61. g4 {+8.69/37 26} Bd6
{-2.95/46 3} 62. Kxh6 {+13.00/35 2.7} Bxh2 {-4.60/33 3} 63. b4
{+99.73/36 26} cxb4 {-10.73/34 3}
{Black wins on time} 0-1And here is the WB debug:
Please, don't misunderstand me. I just want that Crab improves and gets stronger. It makes me feel bad when an engine lose a game because of time, illegal move or crash, when the engine could have won the game easily having a better time management.
Carlos
Beanie496
commented
1 month ago That's probably because I have a really small default move overhead (2 ms, compared to a more normal 16 ms). And yeah, older versions had a bug that caused them to go over their allocated time. Are you setting the move overhead for each engine or are you leaving it as default?
Beanie496
commented
1 month ago In any case, I've pushed a hotfix. Try 4.4.1 and see if there are still time losses.
rwbc
commented
1 month ago Hi again Jasper,
Hopefully, but may be not for old WB with high load (and surely not for Arena I guess).
There are a few things to consider. The debug showed some overhead of up to 0.15s often, before the engines started calculating, which was higher than I had expected.
Also I wonder, if it was necessary to get into severe time trouble, while trying to find a mate in a won position in the moves 61 and 63? Here it spent around 26s for each move and spoiled its rest time heavily.
I have made some sheet (out of curiosity and because of fun), which illustrates what happened in the game regarding the rest time left. (Note that most differences between the debug times and pgn just result, because the times in the pgn are rounded and have a max granularity of just one digit in this WB version)
It might also be of interest that WB adds the inc after the move, while (since some years) CuteGUI/CuteCli add the inc before the move.
BTW I could not make it use that much time (fully using 2.00 s in the 64th move) from fen at least, while I tried to give as much precise move/time informations as possible. (may be it works with full game history and tt entries though)
Anyhow, I think if Carlos uses a move overhead of 200ms in Crabs uci options he should be safe.
uci
id name Crab 4.4.0
id author Jasper Shovelton
option name Move Overhead type spin default 2 min 0 max 1000
option name Threads type spin default 1 min 1 max 256
option name Hash type spin default 32 min 1 max 268435456
option name Clear Hash type button
uciok
isready
readyok
ucinewgame
setoption name Hash value 256
position fen 7k/8/4B2K/p7/Pp4P1/2P5/7b/8 w - - 0 64
go wtime 2000 btime 36590 winc 2000 binc 2000
info depth 1 seldepth 2 score cp 189 hashfull 0 nodes 22 time 0 nps 211538 pv c3b4
info depth 2 seldepth 4 score cp 158 hashfull 0 nodes 72 time 0 nps 404494 pv c3b4 h2f4
info depth 3 seldepth 4 score cp 158 hashfull 0 nodes 124 time 0 nps 228782 pv c3b4 h2f4 h6g6 a5b4
info depth 4 seldepth 6 score cp 166 hashfull 0 nodes 319 time 0 nps 364988 pv c3b4 a5b4 e6d5 h2g3
info depth 5 seldepth 7 score cp 194 hashfull 0 nodes 520 time 1 nps 434782 pv c3b4 a5b4 e6d5 h2g3 h6g6
info depth 6 seldepth 8 score cp 221 hashfull 0 nodes 1155 time 1 nps 724592 pv c3b4 a5b4 a4a5 h2g3 a5a6 g3e5
info depth 7 seldepth 9 score cp 239 hashfull 0 nodes 1635 time 1 nps 823677 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c1 a5a6 c1f4
info depth 8 seldepth 10 score cp 244 hashfull 0 nodes 2423 time 2 nps 1028438 pv c3b4 a5b4 a4a5 h2c7 a5a6 c7b6 h6g6 b6d4
info depth 9 seldepth 11 score cp 271 hashfull 0 nodes 3674 time 2 nps 1353222 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 e6d5 b6d4
info depth 10 seldepth 12 score cp 281 hashfull 0 nodes 4834 time 2 nps 1611870 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 e6d5 b6d4 g4g5
info depth 11 seldepth 13 score cp 281 hashfull 0 nodes 6158 time 3 nps 1862110 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 e6d5 b6f2 g4g5 f2d4
info depth 12 seldepth 14 score cp 283 hashfull 0 nodes 8024 time 3 nps 2198356 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 e6d5 b6f2 g4g5 f2d4 g6f5
info depth 13 seldepth 16 score cp 280 hashfull 1 nodes 11277 time 4 nps 2724571 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 e6d5 b6f2 g4g5 f2c5 d5c4 c5d4
info depth 14 seldepth 16 score cp 280 hashfull 1 nodes 14997 time 4 nps 3283774 pv c3b4 a5b4 a4a5 h2e5 a5a6 e5d4 h6g6 d4c5 e6d5 c5d4 g4g5 d4c5 d5c4 c5d4
info depth 15 seldepth 16 score cp 282 hashfull 1 nodes 18076 time 5 nps 3607264 pv c3b4 a5b4 a4a5 h2e5 a5a6 e5d4 h6g6 d4c5 e6d5 c5d4 g4g5 d4c5 d5c4 c5d4 g6f5
info depth 16 seldepth 19 score cp 321 hashfull 1 nodes 25050 time 5 nps 4324184 pv c3b4 a5b4 a4a5 h2e5 a5a6 e5d4 h6g6 d4c5 g4g5 c5d4 g6f7 d4c5 g5g6 c5d4 e6d5 d4c5
info depth 17 seldepth 20 score cp 375 hashfull 1 nodes 39350 time 7 nps 5259991 pv c3b4
info depth 17 seldepth 22 score cp 400 hashfull 2 nodes 80631 time 12 nps 6668679 pv c3b4 h2f4 h6g6 f4c7 b4a5 c7a5 g6f7 a5c3 e6f5 c3d2 f5e4 d2a5 g4g5 a5c3 g5g6 c3d4 a4a5 d4c5
info depth 18 seldepth 22 score cp 454 hashfull 2 nodes 95572 time 14 nps 6677286 pv c3b4 h2f4 h6g6 f4c7 b4a5 c7a5 g6f7 a5c3 e6f5 c3d2 f5e4 d2a5 g4g5 a5c3 g5g6 c3b2 a4a5 b2d4 a5a6
info depth 19 seldepth 24 score cp 458 hashfull 2 nodes 114392 time 16 nps 7057313 pv c3b4 h2f4 h6g6 f4c7 b4a5 c7a5 g6f7 a5c3 g4g5 c3d2 g5g6 d2c3 a4a5 c3d4 e6d5 d4g7 a5a6 g7d4 d5c4 d4c5
info depth 20 seldepth 25 score cp 531 hashfull 2 nodes 167850 time 21 nps 7669286 pv c3b4 h2c7 b4a5 c7a5 g4g5 a5d2 h6g6 d2e3 a4a5 e3d4 a5a6 d4c5 e6b3 c5d4 g6f7 h8h7 b3d5 d4c5 g5g6 h7h6 g6g7
info depth 21 seldepth 25 score cp 417 hashfull 2 nodes 203171 time 25 nps 7947543 pv c3b4 h2c7 b4a5 c7a5 g4g5 a5d2 h6g6 d2e3 a4a5 e3d4 a5a6 d4c5 e6b3 c5d4 g6f7 h8h7 b3d5 d4c5 g5g6 h7h6 g6g7
info depth 21 seldepth 26 score cp 534 hashfull 2 nodes 220702 time 27 nps 8002248 pv c3b4
info depth 21 seldepth 27 score cp 883 hashfull 2 nodes 276061 time 34 nps 8000376 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 g4g5 b6d4 g6f7 h8h7 g5g6 h7h6 a6a7 d4a7 g6g7 h6g5 g7g8q g5f4 g8f8 a7d4 f8b4 f4e4
info depth 22 seldepth 30 score cp 912 hashfull 2 nodes 306795 time 37 nps 8109833 pv c3b4 h2c7 b4a5 c7a5 h6g6 a5c3 g4g5 c3d2 e6d5 d2c3 g6f7 h8h7 a4a5 c3d4 g5g6 h7h6 a5a6 h6g5 g6g7 d4g7 a6a7 g7d4 a7a8q
info depth 23 seldepth 31 score cp 911 hashfull 2 nodes 330183 time 40 nps 8176692 pv c3b4 h2c7 b4a5 c7a5 h6g6 a5c3 g4g5 c3d2 e6d5 d2c3 g6f7 h8h7 a4a5 c3d4 g5g6 h7h6 a5a6 h6g5 a6a7 d4a7 g6g7 g5f4 f7g6 a7d4
info depth 24 seldepth 32 score cp 942 hashfull 2 nodes 368174 time 44 nps 8288846 pv c3b4 h2c7 b4a5 c7a5 h6g6 a5c3 g4g5 c3d2 e6d5 d2c3 g6f7 h8h7 a4a5 c3d4 g5g6 h7h6 a5a6 h6g5 a6a7 d4a7 g6g7 a7d4 g7g8q g5f4 g8g6 d4c3
info depth 25 seldepth 35 score cp 605 hashfull 4 nodes 453568 time 54 nps 8291161 pv c3b4 h2c7 b4a5 c7a5 h6g6 a5c3 g4g5 c3d2 e6d5 d2c3 g6f7 h8h7 a4a5 c3d4 g5g6 h7h6 a5a6 h6g5 a6a7 d4a7 g6g7 a7d4 g7g8q g5f4 g8g6 d4c3
info depth 25 seldepth 35 score cp 942 hashfull 4 nodes 468189 time 56 nps 8306672 pv c3b4
info depth 25 seldepth 36 score cp 945 hashfull 9 nodes 668915 time 78 nps 8492756 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 g4g5 b6d4 g6f7 h8h7 g5g6 h7h6 a6a7 d4a7 g6g7 h6g5 g7g8q g5f4 g8f8 a7d4 f8b4 f4e4 b4d6 d4e5 e6d5 e4f4 d6g6
info depth 26 seldepth 36 score cp 952 hashfull 9 nodes 706760 time 83 nps 8491241 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 g4g5 b6d4 g6f7 h8h7 g5g6 h7h6 a6a7 d4a7 g6g7 h6g5 g7g8q g5f4 g8f8 b4b3 e6b3 a7d4 f7g6 f4e4 f8f5 e4e3 b3d5 e3d2 f5f7
info depth 27 seldepth 40 score cp 952 hashfull 11 nodes 777346 time 91 nps 8470589 pv c3b4 a5b4 a4a5 h2f4 h6g6 f4c7 a5a6 c7b6 g4g5 b6d4 g6f7 h8h7 g5g6 h7h6 a6a7 d4a7 g6g7 h6g5 g7g8q g5f4 g8f8 a7d4 f8b4 f4e4 b4d6 d4c3 e6d5 e4e3 d6g6 e3d2 g6d6
info depth 28 seldepth 42 score cp 1253 hashfull 14 nodes 1238020 time 146 nps 8441256 pv c3b4 h2c7 b4a5 c7a5 h6g6 a5d8 g4g5 d8g5 g6g5 h8g7 a4a5 g7f8 e6d5 f8e7 a5a6 e7d6 d5e4 d6e5 e4f5 e5d4 a6a7 d4e3 a7a8q e3f2 a8e8 f2f3 g5f6 f3g3
info depth 29 seldepth 34 score cp 1268 hashfull 14 nodes 1299835 time 153 nps 8448002 pv c3b4 h2c7 b4a5 c7a5 h6g6 a5d8 g4g5 d8c7 e6c4 c7d8 c4d5 d8g5 g6g5 h8g7 a4a5 g7f8 a5a6 f8e7 a6a7 e7d6 a7a8q d6c5 a8g8 c5d4 g8e6 d4d3 g5f6 d3d2 e6e8
info depth 30 seldepth 38 score cp 1268 hashfull 14 nodes 1359935 time 160 nps 8457096 pv c3b4 h2f4 h6g6 f4c7 b4a5 c7a5 e6d5 a5d2 g4g5 d2g5 g6g5 h8g7 a4a5 g7f8 a5a6 f8e7 a6a7 e7d6 a7a8q d6c5 a8g8 c5d4 g8e6 d4d3 g5f6 d3d2 e6e8 d2d1 f6f7 d1d2 f7f6
info depth 31 seldepth 35 score cp 1272 hashfull 14 nodes 1395690 time 165 nps 8449305 pv c3b4 h2f4 h6g6 f4c7 b4a5 c7a5 e6d5 a5d2 g4g5 d2g5 g6g5 h8g7 a4a5 g7f8 a5a6 f8e7 a6a7 e7d6 a7a8q d6c5 a8g8 c5d4 g8e6 d4d3 g5f6 d3d2 e6e8 d2d1 e8e5 d1d2 d5c4 d2c2
info depth 32 seldepth 48 score cp 1279 hashfull 29 nodes 3229597 time 376 nps 8571777 pv c3b4 h2f4 h6g6 a5b4 g4g5 b4b3 e6b3 f4e3 b3d5 e3g5 g6g5 h8g7 a4a5 g7f8 a5a6 f8e7 a6a7 e7d6 a7a8q d6c5 a8g8 c5d4 g8e6 d4d3 g5f6 d3d2 e6e8 d2c2 e8e5 c2c1 e5d4 c1c2 d4e5
info depth 33 seldepth 47 score cp 1844 hashfull 47 nodes 5178355 time 608 nps 8512620 pv c3b4
info depth 33 seldepth 49 score cp 1314 hashfull 103 nodes 10604578 time 1284 nps 8252840 pv c3b4 a5b4 h6g6 h2f4 e6d5 f4c7 g4g5 c7d8 d5e6 d8g5 g6g5 h8g7 a4a5 g7f8 g5f6 f8e8 a5a6 e8d8 a6a7 d8c7 a7a8q c7b6 a8e4 b4b3 e6b3 b6c5 b3d5 c5b5 e4d4 b5a5 d5c6 a5a6 c6d5
bestmove c3b4Guenther (RWBC)
P.S. Do you plan to create your own compilations in the future for the releases? CCRL e.g. neglected my compilations so far despite I announced Crab in the XB/UCI chronology months ago. https://docs.google.com/spreadsheets/d/1GXoy3lGhdKPJbatdw2_2dhWT3TkpthPcNtHs51MQydM/edit?gid=175552346#gid=175552346
Beanie496
commented
1 month ago Thanks for making the sheet - the detail is amazing. I suspect the 0.15 s comes from WB itself, because I'm seeing exactly the same delay from the other engine and it takes much less time than that to start the search. (I'm also only seeing a ~0.5 ms delay when I use fast-chess, which is about what I expect.)
Spending a lot of time when there's already a mate is the same as spending a lot of time in any other position - it's just trying to find a faster mate, whether or not that is wise. The time management is really rudimentary - it continues another iterative deepening loop if it's not used more than about 40% of its allocated time (which is in turn only a fraction of the remaining time), but it won't stop the search partway through until it's about to use all of its remaining time. This means that it, if an iteration of the iterative deepening loop takes way longer than expected, it could very easily burn a lot of time. (I did try to make it check allocated time instead of total time but it lost elo. I might retry but with total time / 2 instead, or something similar.) And yeah, I think you're right about being unable to replicate the large amount of time usage - how much time it spends depends on whatever random TT and history entries it already has, so it's very difficult to reproduce it from a single FEN. (Although you could sort of see it with the example you gave, where the re-search at the end took more time than all the other root searches put together.)
Lastly, about the compilations - probably, assuming I can set up a github action or something to do it automatically.
CPagador
commented
1 month ago In any case, I've pushed a hotfix. Try 4.4.1 and see if there are still time losses.
Can you or Guenther build a binary, so I can test it? I am using the 4.4.0 version built by Guenther in the Promotion League 5 of my tournament, I hope Crab passes, so I can test the fixed version in the next PL.
Beanie496
commented
1 month ago Here's a linux and windows build for reasonably modern CPUs. Setting up some workflow with github actions will take a while, but this will do for now. crab_binaries.tar.gz
rwbc
commented
1 month ago Note that you still should set a higher overhead in its uci options, because of the GUI overhead with high concurrency. I guess most people use cli tools instead of GUIs for this. IIRC there is even a way to start WB w/o UI for this, but I forgot how (probably via batch file with some extra flag?) BTW out of curiosity I checked some of my old WB debug backups [still newer versions than your one ;)] and here the overhead was mostly 10-20 ms, but those were w/o concurrency.
CPagador
commented
1 month ago Hi guys,
Crab 4.4.1 participated in PL4 and qualified to PL3, no time losses this time. I didn't change the default settings (Move overhead=16ms).
Carlos
Beanie496
commented
1 month ago That's great to hear, thanks! Looks like I can probably close this then.
Hi,
I run tournaments at 3'+2", ponder off and single thread. Older versions of Crab like 3.12.0 and 3.28.0 (compiled by Guenther Simon) lost many times on time (>30% of the games). I am using version 4.4.0 for my current tournament and it is still losing on time, although less.
https://talkchess.com/forum3/viewtopic.php?t=84301
These are from PL11:
Regards, Carlos