During this tests I noticed now that despite an older thread of 2015, that 'hashfull' really seems to cost quite some time (even by a huge factor in very fast games!).
I could verify with the debug option in Cutechess-cli that practically all unusual high time usage comes from 'hashfull'.
Conditions 60/30 hash 64 (first tests were with 16 like the fishtests, but after I checked all games for all kind of stats depth/time etc. likewise,
I noticed unexplicable time usages sometimes for relatively normal depths with the pattern of high hashfull numbers and I wanted to see the influence of higher hash then)
concurrency 2 on a quadcore
Example:
5319241 >Stockfish_17101111-64(252): position fen rnbqkb1r/ppppp1pp/5p1n/8/1P6/8/PBPPPPPP/RN1QKBNR w KQkq - 0 1 moves d2d4 e7e5 a2a3 e5d4 d1d4 b8c6 d4e4 f8e7 b1c3 c6e5 f2f4 e5g6 e4f3 c7c6
5319242 >Stockfish_17101111-64(252): isready
5319242 <Stockfish_17101111-64(252): readyok
5319242 >Stockfish_17101111-64(252): go wtime 26663 btime 26263 movestogo 53
5319242 <Stockfish_17101111-64(252): info depth 1 seldepth 1 multipv 1 score cp 35 nodes 38 nps 38000 tbhits 0 time 1 pv e2e4
5319243 <Stockfish_17101111-64(252): info depth 2 seldepth 2 multipv 1 score cp 35 nodes 77 nps 77000 tbhits 0 time 1 pv e2e4 a7a5
5319244 <Stockfish_17101111-64(252): info depth 3 seldepth 3 multipv 1 score cp 35 nodes 123 nps 123000 tbhits 0 time 1 pv e2e4 a7a5 b4b5
5319244 <Stockfish_17101111-64(252): info depth 4 seldepth 4 multipv 1 score cp 35 nodes 176 nps 176000 tbhits 0 time 1 pv e2e4 a7a5 b4b5 d7d5
5319245 <Stockfish_17101111-64(252): info depth 5 seldepth 5 multipv 1 score cp 35 nodes 241 nps 241000 tbhits 0 time 1 pv e2e4 a7a5 b4b5 d7d5 e4d5
5319245 <Stockfish_17101111-64(252): info depth 6 seldepth 6 multipv 1 score cp 35 nodes 334 nps 167000 tbhits 0 time 2 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4
5319246 <Stockfish_17101111-64(252): info depth 7 seldepth 7 multipv 1 score cp 35 nodes 460 nps 230000 tbhits 0 time 2 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4
5319247 <Stockfish_17101111-64(252): info depth 8 seldepth 8 multipv 1 score cp 35 nodes 629 nps 314500 tbhits 0 time 2 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5
5319247 <Stockfish_17101111-64(252): info depth 9 seldepth 14 multipv 1 score cp 35 nodes 1166 nps 583000 tbhits 0 time 2 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4c4 c6b5 c4b5 d8d7 b5d7 f5d7
5319248 <Stockfish_17101111-64(252): info depth 10 seldepth 18 multipv 1 score cp 35 nodes 2566 nps 641500 tbhits 0 time 4 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4c4 c6b5 c4b5 d8d7 b5d7 f5d7 g1f3 g6f4 g2g3 f4g6
5319282 <Stockfish_17101111-64(252): info depth 11 seldepth 22 multipv 1 score cp 22 nodes 29111 nps 677000 tbhits 0 time 43 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4c4 c6c5 e1c1 d8d6 c1b1 d6f4 g2g3
5319313 <Stockfish_17101111-64(252): info depth 12 seldepth 20 multipv 1 score cp 0 nodes 51596 nps 697243 tbhits 0 time 74 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4f3 f5g4
5319332 <Stockfish_17101111-64(252): info depth 13 seldepth 18 multipv 1 score cp 0 nodes 65230 nps 701397 tbhits 0 time 93 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4f3 f5g4
5319425 <Stockfish_17101111-64(252): info depth 14 seldepth 21 multipv 1 score cp 0 nodes 129167 nps 694446 tbhits 0 time 186 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4f3 f5g4
5319450 <Stockfish_17101111-64(252): info depth 15 seldepth 11 multipv 1 score cp 0 nodes 146884 nps 696132 tbhits 0 time 211 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4f3 f5g4
5319608 <Stockfish_17101111-64(252): info depth 16 seldepth 20 multipv 1 score cp 0 nodes 255150 nps 691463 tbhits 0 time 369 pv e2e4 a7a5 b4b5 d7d5 e4d5 c8g4 f3e4 g4f5 e4f3 f5g4
...(cut off other entities of other games here)
5322223 <Stockfish_17101111-64(252): info depth 17 seldepth 26 multipv 1 score cp -7 nodes 2048973 nps 686653 hashfull 270 tbhits 0 time 2984 pv e2e4 e8g8
A regex search in the pgn (1200 games) e.g. reveals 334 moves
with the condition:
Code: Select all
/1[2-6] [2-5].[0-9]s
I bet all of those contain a hashfull >200 (there is also a pattern that values
over 200 always have a time >2000ms)
If I have more time tomorrow I can show more examples, it's a bit tedious to dig them out of the huge cute debug file and because of concurrency the different processes are cluttered through.
Code: Select all
[Event "GS-Test_2017"]
[Site "RWBC::CAPPUCCINO"]
[Date "2017.10.20"]
[Round "37"]
[White "Stockfish_17101111-64"]
[Black "StockfishTB_17092216-64"]
[Result "0-1"]
[FEN "rnbqkb1r/ppppp1pp/5p1n/8/1P6/8/PBPPPPPP/RN1QKBNR w KQkq - 0 1"]
[PlyCount "163"]
[SetUp "1"]
[Termination "adjudication"]
[TimeControl "60/30"]
1. d4 {+0.22/13 0.56s} e5 {-0.28/13 1.0s} 2. a3 {+0.20/14 0.54s}
exd4 {-0.32/14 0.33s} 3. Qxd4 {+0.21/12 0.075s} Nc6 {-0.20/14 0.24s}
4. Qe4+ {+0.15/13 0.44s} Be7 {+0.12/15 0.87s} 5. Nc3 {-0.08/14 0.60s}
Ne5 {+0.07/14 0.42s} 6. f4 {+0.13/14 0.48s} Ng6 {+0.23/15 0.77s}
7. Qf3 {+0.13/14 0.64s} c6 {+0.23/12 0.070s} 8. e4 {-0.07/17 3.0s}
b5 {+0.27/14 0.85s} 9. a4 {-0.13/15 1.1s} bxa4 {+0.08/15 0.89s}
10. Nxa4 {-0.46/13 1.6s} d5 {+0.75/12 0.26s} 11. b5 {-0.20/14 1.3s}
Rb8 {+1.19/12 0.24s} 12. bxc6 {-1.31/15 2.5s} dxe4 {+1.50/13 0.41s}
13. Qd1 {-1.70/15 0.92s} Qc7 {+1.07/15 1.4s} 14. Ne2 {-1.92/15 0.61s}
Qxc6 {+1.33/13 0.20s} 15. Nd4 {-1.90/14 0.45s} Qd5 {+1.80/15 0.64s}
16. Bc1 {-1.75/14 0.21s} e3 {+2.28/15 0.86s} 17. Bxe3 {-2.72/14 0.46s}
Ng4 {+2.70/14 0.20s} 18. Bg1 {-2.60/15 1.0s} Nxf4 {+2.72/14 0.52s}
19. Qd2 {-2.74/14 0.52s} Bb4 {+2.25/15 0.60s} 20. c3 {-2.50/14 0.25s}
Qe4+ {+2.11/16 0.62s} 21. Kd1 {-2.65/14 0.11s} Ne5 {+1.97/16 0.57s}
22. Qe3 {-1.61/13 0.15s} Qxe3 {+1.93/16 1.0s} 23. Bxe3 {-2.05/15 0.45s}
Nd5 {+2.06/14 0.13s} 24. Bd2 {-1.90/13 0.054s} Be7 {+1.93/15 0.59s}
25. Be2 {-1.89/14 0.32s} O-O {+1.77/14 0.56s} 26. Rf1 {-1.75/13 0.20s}
Rd8 {+2.11/14 0.57s} 27. Kc1 {-1.55/13 0.43s} Bb7 {+2.24/12 0.084s}
28. Nf3 {-2.02/14 0.44s} Bd6 {+1.95/16 0.86s} 29. g3 {-1.87/14 0.41s}
Rbc8 {+1.84/16 1.1s} 30. Nxe5 {-1.85/11 0.069s} Bxe5 {+1.79/12 0.062s}
31. Ra3 {-1.59/13 0.17s} Bd6 {+1.71/16 2.5s} 32. Ra1 {-1.63/14 0.50s}
Be5 {+1.76/16 0.90s} 33. Ra3 {-1.67/14 0.28s} Nb4 {+2.00/14 0.12s}
34. Nb2 {-1.61/14 0.30s} a5 {+1.51/14 0.67s} 35. Rxa5 {-1.58/15 0.47s}
Bxc3 {+1.43/15 0.34s} 36. Bc4+ {-1.49/15 0.31s} Bd5 {+1.56/16 0.29s}
37. Bxc3 {-1.58/14 0.087s} Bxc4 {+1.55/14 0.038s} 38. Nxc4 {-1.57/15 0.19s}
Rxc4 {+1.46/16 0.37s} 39. Ra3 {-1.58/13 0.064s} Nd3+ {+1.55/15 0.19s}
40. Kc2 {-1.40/14 0.11s} Ne5 {+1.47/16 0.23s} 41. Rd1 {-1.53/12 0.091s}
Rdc8 {+1.53/15 0.076s} 42. Kb2 {-1.45/15 0.38s} Nf7 {+1.45/16 1.1s}
43. Rd7 {-1.47/16 0.68s} Ng5 {+1.57/15 0.19s} 44. Bd2 {-1.11/16 0.45s}
Ne6 {+1.24/17 0.74s} 45. Rc3 {-1.15/16 0.71s} Nd4 {+1.21/17 0.34s}
46. Rb7 {-1.12/17 0.34s} Nf3 {+1.17/18 0.51s} 47. Rxf3 {-1.23/17 0.085s}
Rc2+ {+1.38/15 0.17s} 48. Kb3 {-1.08/19 0.34s} Rxd2 {+1.28/21 1.0s}
49. h3 {-1.17/16 0.068s} Rh2 {+1.30/19 0.068s} 50. g4 {-1.23/20 0.60s}
h6 {+1.40/19 0.49s} 51. Rd3 {-1.22/18 0.078s} Kh7 {+1.42/18 0.27s}
52. Ra7 {-1.35/18 0.92s} Kg6 {+1.52/18 0.21s} 53. Rb7 {-1.35/19 0.63s}
Rg2 {+1.54/17 0.33s} 54. Ra7 {-1.37/19 0.73s} h5 {+1.89/17 0.49s}
55. Rdd7 {-1.39/18 0.40s} Rg3+ {+1.81/16 0.38s} 56. Kb2 {-1.47/17 0.41s}
Rg8 {+1.76/15 0.071s} 57. gxh5+ {-1.40/14 0.043s} Kxh5 {+1.95/15 0.25s}
58. Kc2 {-1.47/18 0.47s} Rxh3 {+1.90/13 0.052s} 59. Rxg7 {-0.44/15 0.091s}
Rxg7 {+132.77/35 0.18s} 60. Rxg7 {-0.32/14 0.020s} Re3 {+132.79/1 0.030s}
61. Rf7 {-2.26/29 1.0s} Kg5 {+132.79/18 0.41s} 62. Rf8 {-2.26/38 0.51s}
f5 {+132.79/22 0.36s} 63. Rc8 {-6.59/34 5.1s} f4 {+132.79/20 0.74s}
64. Rg8+ {-9.49/22 2.0s} Kh4 {+132.79/19 0.49s} 65. Rf8 {-5.76/21 0.42s}
Kg3 {+132.79/20 0.42s} 66. Rg8+ {-5.80/18 0.078s} Kf2 {+132.79/19 0.19s}
67. Rf8 {-10.35/23 2.1s} f3 {+132.79/21 0.45s} 68. Kd2 {-10.42/26 0.56s}
Re5 {+132.79/20 0.14s} 69. Kd3 {-10.42/21 0.10s} Kg2 {+132.79/22 1.3s}
70. Kd4 {-10.45/22 0.37s} Re1 {+132.79/16 0.16s} 71. Rg8+ {-10.42/16 0.061s}
Kf1 {+132.79/20 2.7s} 72. Kd3 {-10.56/18 0.78s} f2 {+132.79/18 0.56s}
73. Rg5 {-47.13/18 1.8s} Re8 {+132.79/18 0.47s} 74. Kd2 {-47.55/18 0.84s}
Rd8+ {+132.79/20 0.12s} 75. Kc3 {-47.63/21 0.83s} Ke2 {+132.79/23 0.47s}
76. Re5+ {-47.63/21 0.10s} Kf3 {+132.79/24 0.24s} 77. Rf5+ {-47.67/22 0.46s}
Kg3 {+132.79/25 0.44s} 78. Kc2 {-47.75/23 0.77s} Re8 {+132.79/24 0.16s}
79. Kc3 {-47.87/26 0.81s} Re1 {+132.79/24 0.36s} 80. Rg5+ {-M54/22 2.2s}
Kf4 {+M31/19 0.98s} 81. Rg7 {-M48/22 0.31s} Re5 {+M27/20 0.12s}
82. Kd4 {-M36/19 0.33s, Black wins by adjudication} 0-1