Hashfull in Stockfish slowdown in fast games?

Discussion of anything and everything relating to chess playing software and machines.

Moderators: hgm, Rebel, chrisw

User avatar
Guenther
Posts: 4605
Joined: Wed Oct 01, 2008 6:33 am
Location: Regensburg, Germany
Full name: Guenther Simon

Hashfull in Stockfish slowdown in fast games?

Post by Guenther »

Currently I am doing some tests with various SF versions regarding the time usage / time losses in mps time controls with m >40.

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&#91;2-6&#93; &#91;2-5&#93;.&#91;0-9&#93;s
Which means 334 moves with depths 12-16 AND time 2.0-5.9 seconds.
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

&#91;Event "GS-Test_2017"&#93;
&#91;Site "RWBC&#58;&#58;CAPPUCCINO"&#93;
&#91;Date "2017.10.20"&#93;
&#91;Round "37"&#93;
&#91;White "Stockfish_17101111-64"&#93;
&#91;Black "StockfishTB_17092216-64"&#93;
&#91;Result "0-1"&#93;
&#91;FEN "rnbqkb1r/ppppp1pp/5p1n/8/1P6/8/PBPPPPPP/RN1QKBNR w KQkq - 0 1"&#93;
&#91;PlyCount "163"&#93;
&#91;SetUp "1"&#93;
&#91;Termination "adjudication"&#93;
&#91;TimeControl "60/30"&#93;

1. d4 &#123;+0.22/13 0.56s&#125; e5 &#123;-0.28/13 1.0s&#125; 2. a3 &#123;+0.20/14 0.54s&#125;
exd4 &#123;-0.32/14 0.33s&#125; 3. Qxd4 &#123;+0.21/12 0.075s&#125; Nc6 &#123;-0.20/14 0.24s&#125;
4. Qe4+ &#123;+0.15/13 0.44s&#125; Be7 &#123;+0.12/15 0.87s&#125; 5. Nc3 &#123;-0.08/14 0.60s&#125;
Ne5 &#123;+0.07/14 0.42s&#125; 6. f4 &#123;+0.13/14 0.48s&#125; Ng6 &#123;+0.23/15 0.77s&#125;
7. Qf3 &#123;+0.13/14 0.64s&#125; c6 &#123;+0.23/12 0.070s&#125; 8. e4 &#123;-0.07/17 3.0s&#125;
b5 &#123;+0.27/14 0.85s&#125; 9. a4 &#123;-0.13/15 1.1s&#125; bxa4 &#123;+0.08/15 0.89s&#125;
10. Nxa4 &#123;-0.46/13 1.6s&#125; d5 &#123;+0.75/12 0.26s&#125; 11. b5 &#123;-0.20/14 1.3s&#125;
Rb8 &#123;+1.19/12 0.24s&#125; 12. bxc6 &#123;-1.31/15 2.5s&#125; dxe4 &#123;+1.50/13 0.41s&#125;
13. Qd1 &#123;-1.70/15 0.92s&#125; Qc7 &#123;+1.07/15 1.4s&#125; 14. Ne2 &#123;-1.92/15 0.61s&#125;
Qxc6 &#123;+1.33/13 0.20s&#125; 15. Nd4 &#123;-1.90/14 0.45s&#125; Qd5 &#123;+1.80/15 0.64s&#125;
16. Bc1 &#123;-1.75/14 0.21s&#125; e3 &#123;+2.28/15 0.86s&#125; 17. Bxe3 &#123;-2.72/14 0.46s&#125;
Ng4 &#123;+2.70/14 0.20s&#125; 18. Bg1 &#123;-2.60/15 1.0s&#125; Nxf4 &#123;+2.72/14 0.52s&#125;
19. Qd2 &#123;-2.74/14 0.52s&#125; Bb4 &#123;+2.25/15 0.60s&#125; 20. c3 &#123;-2.50/14 0.25s&#125;
Qe4+ &#123;+2.11/16 0.62s&#125; 21. Kd1 &#123;-2.65/14 0.11s&#125; Ne5 &#123;+1.97/16 0.57s&#125;
22. Qe3 &#123;-1.61/13 0.15s&#125; Qxe3 &#123;+1.93/16 1.0s&#125; 23. Bxe3 &#123;-2.05/15 0.45s&#125;
Nd5 &#123;+2.06/14 0.13s&#125; 24. Bd2 &#123;-1.90/13 0.054s&#125; Be7 &#123;+1.93/15 0.59s&#125;
25. Be2 &#123;-1.89/14 0.32s&#125; O-O &#123;+1.77/14 0.56s&#125; 26. Rf1 &#123;-1.75/13 0.20s&#125;
Rd8 &#123;+2.11/14 0.57s&#125; 27. Kc1 &#123;-1.55/13 0.43s&#125; Bb7 &#123;+2.24/12 0.084s&#125;
28. Nf3 &#123;-2.02/14 0.44s&#125; Bd6 &#123;+1.95/16 0.86s&#125; 29. g3 &#123;-1.87/14 0.41s&#125;
Rbc8 &#123;+1.84/16 1.1s&#125; 30. Nxe5 &#123;-1.85/11 0.069s&#125; Bxe5 &#123;+1.79/12 0.062s&#125;
31. Ra3 &#123;-1.59/13 0.17s&#125; Bd6 &#123;+1.71/16 2.5s&#125; 32. Ra1 &#123;-1.63/14 0.50s&#125;
Be5 &#123;+1.76/16 0.90s&#125; 33. Ra3 &#123;-1.67/14 0.28s&#125; Nb4 &#123;+2.00/14 0.12s&#125;
34. Nb2 &#123;-1.61/14 0.30s&#125; a5 &#123;+1.51/14 0.67s&#125; 35. Rxa5 &#123;-1.58/15 0.47s&#125;
Bxc3 &#123;+1.43/15 0.34s&#125; 36. Bc4+ &#123;-1.49/15 0.31s&#125; Bd5 &#123;+1.56/16 0.29s&#125;
37. Bxc3 &#123;-1.58/14 0.087s&#125; Bxc4 &#123;+1.55/14 0.038s&#125; 38. Nxc4 &#123;-1.57/15 0.19s&#125;
Rxc4 &#123;+1.46/16 0.37s&#125; 39. Ra3 &#123;-1.58/13 0.064s&#125; Nd3+ &#123;+1.55/15 0.19s&#125;
40. Kc2 &#123;-1.40/14 0.11s&#125; Ne5 &#123;+1.47/16 0.23s&#125; 41. Rd1 &#123;-1.53/12 0.091s&#125;
Rdc8 &#123;+1.53/15 0.076s&#125; 42. Kb2 &#123;-1.45/15 0.38s&#125; Nf7 &#123;+1.45/16 1.1s&#125;
43. Rd7 &#123;-1.47/16 0.68s&#125; Ng5 &#123;+1.57/15 0.19s&#125; 44. Bd2 &#123;-1.11/16 0.45s&#125;
Ne6 &#123;+1.24/17 0.74s&#125; 45. Rc3 &#123;-1.15/16 0.71s&#125; Nd4 &#123;+1.21/17 0.34s&#125;
46. Rb7 &#123;-1.12/17 0.34s&#125; Nf3 &#123;+1.17/18 0.51s&#125; 47. Rxf3 &#123;-1.23/17 0.085s&#125;
Rc2+ &#123;+1.38/15 0.17s&#125; 48. Kb3 &#123;-1.08/19 0.34s&#125; Rxd2 &#123;+1.28/21 1.0s&#125;
49. h3 &#123;-1.17/16 0.068s&#125; Rh2 &#123;+1.30/19 0.068s&#125; 50. g4 &#123;-1.23/20 0.60s&#125;
h6 &#123;+1.40/19 0.49s&#125; 51. Rd3 &#123;-1.22/18 0.078s&#125; Kh7 &#123;+1.42/18 0.27s&#125;
52. Ra7 &#123;-1.35/18 0.92s&#125; Kg6 &#123;+1.52/18 0.21s&#125; 53. Rb7 &#123;-1.35/19 0.63s&#125;
Rg2 &#123;+1.54/17 0.33s&#125; 54. Ra7 &#123;-1.37/19 0.73s&#125; h5 &#123;+1.89/17 0.49s&#125;
55. Rdd7 &#123;-1.39/18 0.40s&#125; Rg3+ &#123;+1.81/16 0.38s&#125; 56. Kb2 &#123;-1.47/17 0.41s&#125;
Rg8 &#123;+1.76/15 0.071s&#125; 57. gxh5+ &#123;-1.40/14 0.043s&#125; Kxh5 &#123;+1.95/15 0.25s&#125;
58. Kc2 &#123;-1.47/18 0.47s&#125; Rxh3 &#123;+1.90/13 0.052s&#125; 59. Rxg7 &#123;-0.44/15 0.091s&#125;
Rxg7 &#123;+132.77/35 0.18s&#125; 60. Rxg7 &#123;-0.32/14 0.020s&#125; Re3 &#123;+132.79/1 0.030s&#125;
61. Rf7 &#123;-2.26/29 1.0s&#125; Kg5 &#123;+132.79/18 0.41s&#125; 62. Rf8 &#123;-2.26/38 0.51s&#125;
f5 &#123;+132.79/22 0.36s&#125; 63. Rc8 &#123;-6.59/34 5.1s&#125; f4 &#123;+132.79/20 0.74s&#125;
64. Rg8+ &#123;-9.49/22 2.0s&#125; Kh4 &#123;+132.79/19 0.49s&#125; 65. Rf8 &#123;-5.76/21 0.42s&#125;
Kg3 &#123;+132.79/20 0.42s&#125; 66. Rg8+ &#123;-5.80/18 0.078s&#125; Kf2 &#123;+132.79/19 0.19s&#125;
67. Rf8 &#123;-10.35/23 2.1s&#125; f3 &#123;+132.79/21 0.45s&#125; 68. Kd2 &#123;-10.42/26 0.56s&#125;
Re5 &#123;+132.79/20 0.14s&#125; 69. Kd3 &#123;-10.42/21 0.10s&#125; Kg2 &#123;+132.79/22 1.3s&#125;
70. Kd4 &#123;-10.45/22 0.37s&#125; Re1 &#123;+132.79/16 0.16s&#125; 71. Rg8+ &#123;-10.42/16 0.061s&#125;
Kf1 &#123;+132.79/20 2.7s&#125; 72. Kd3 &#123;-10.56/18 0.78s&#125; f2 &#123;+132.79/18 0.56s&#125;
73. Rg5 &#123;-47.13/18 1.8s&#125; Re8 &#123;+132.79/18 0.47s&#125; 74. Kd2 &#123;-47.55/18 0.84s&#125;
Rd8+ &#123;+132.79/20 0.12s&#125; 75. Kc3 &#123;-47.63/21 0.83s&#125; Ke2 &#123;+132.79/23 0.47s&#125;
76. Re5+ &#123;-47.63/21 0.10s&#125; Kf3 &#123;+132.79/24 0.24s&#125; 77. Rf5+ &#123;-47.67/22 0.46s&#125;
Kg3 &#123;+132.79/25 0.44s&#125; 78. Kc2 &#123;-47.75/23 0.77s&#125; Re8 &#123;+132.79/24 0.16s&#125;
79. Kc3 &#123;-47.87/26 0.81s&#125; Re1 &#123;+132.79/24 0.36s&#125; 80. Rg5+ &#123;-M54/22 2.2s&#125;
Kf4 &#123;+M31/19 0.98s&#125; 81. Rg7 &#123;-M48/22 0.31s&#125; Re5 &#123;+M27/20 0.12s&#125;
82. Kd4 &#123;-M36/19 0.33s, Black wins by adjudication&#125; 0-1
https://rwbc-chess.de

trollwatch:
Chessqueen + chessica + AlexChess + Eduard + Sylwy
MonteCarlo
Posts: 188
Joined: Sun Dec 25, 2016 4:59 pm

Re: Hashfull in Stockfish slowdown in fast games?

Post by MonteCarlo »

Just something to be aware of, there's probably some selection bias here, since SF only outputs hashfull after 1 second of searching.

This means that you'll only see hashfull on lower depths when it's perhaps failed high/low or otherwise had to spend a bunch of time for other reasons; it may well have nothing to do with hash.

Cheers!
User avatar
Guenther
Posts: 4605
Joined: Wed Oct 01, 2008 6:33 am
Location: Regensburg, Germany
Full name: Guenther Simon

Re: Hashfull in Stockfish slowdown in fast games?

Post by Guenther »

MonteCarlo wrote:Just something to be aware of, there's probably some selection bias here, since SF only outputs hashfull after 1 second of searching.

This means that you'll only see hashfull on lower depths when it's perhaps failed high/low or otherwise had to spend a bunch of time for other reasons; it may well have nothing to do with hash.

Cheers!
You may be right about fail high/lows, because the nps seems not to drop
much actually, which means lot of nodes were still burnt to the final pv.
I wonder though why it seems I cannot get those relatively high times
in analysis mode under the same conditions?
(of course games were single core)
Anyhow I will check the pvs in the debug for fail high/lows from previous depths before this happens.

Thanks for the input.
Guenther
https://rwbc-chess.de

trollwatch:
Chessqueen + chessica + AlexChess + Eduard + Sylwy
User avatar
Guenther
Posts: 4605
Joined: Wed Oct 01, 2008 6:33 am
Location: Regensburg, Germany
Full name: Guenther Simon

Re: Hashfull in Stockfish slowdown in fast games?

Post by Guenther »

An other example which seems to prove that you are right Jacob.
Looks like a fail high at depth 14.
Therefore around 3 seconds needed to finish d15 here.
(could verify this even in analysis mode this time after some attempts)

So my impression was really just a bias due to the fact that hashfull
is only written after >1s thinking time.

Code: Select all

9675563 >Stockfish_17092216-64&#40;455&#41;&#58; position fen r1bqkbnr/ppppppp1/2n4p/1B6/4P3/8/PPPP1PPP/RNBQK1NR w KQkq - 0 1 moves g1f3 a7a6 b5c6 d7c6 d2d3 g7g5 c1d2 f8g7 d2c3 g7c3 b2c3 g8f6 b1d2 g5g4 f3e5 d8d6 e5c4 d6f4 a1b1 h6h5 d1e2 h5h4 d3d4 h8h5 e1g1 b7b6 c4b2 f4h6 b2d3 h5a5 b1b2 g4g3 h2h3 f6h5 c3c4 a5a3 d4d5 c8d7 d2b3 e8c8 c4c5
9675564 >Stockfish_17092216-64&#40;455&#41;&#58; isready
9675564 <Stockfish_17092216-64&#40;455&#41;&#58; readyok
9675565 >Stockfish_17092216-64&#40;455&#41;&#58; go wtime 14642 btime 18804 movestogo 40
9675565 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 1 seldepth 1 multipv 1 score cp -18 nodes 71 nps 71000 tbhits 0 time 1 pv g3f2 e2f2
9675566 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 2 seldepth 3 multipv 1 score cp -18 nodes 125 nps 125000 tbhits 0 time 1 pv g3f2 e2f2 c6d5
9675566 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 3 seldepth 4 multipv 1 score cp -18 nodes 183 nps 183000 tbhits 0 time 1 pv g3f2 e2f2 c6d5 c5b6
9675567 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 4 seldepth 5 multipv 1 score cp -18 nodes 252 nps 252000 tbhits 0 time 1 pv g3f2 e2f2 c6d5 c5b6 h6b6
9675568 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 5 seldepth 6 multipv 1 score cp -18 nodes 330 nps 330000 tbhits 0 time 1 pv g3f2 e2f2 c6d5 c5b6 h6b6 b3d4
9675568 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 6 seldepth 7 multipv 1 score cp -18 nodes 429 nps 214500 tbhits 0 time 2 pv g3f2 e2f2 c6d5 c5b6 h6b6 b3d4 d7b5
9675569 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 7 seldepth 8 multipv 1 score cp -18 nodes 547 nps 273500 tbhits 0 time 2 pv g3f2 e2f2 c6d5 c5b6 h6b6 b3d4 d7b5 d4b5
9675570 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 8 seldepth 10 multipv 1 score cp -18 nodes 759 nps 379500 tbhits 0 time 2 pv g3f2 e2f2 c6d5 c5b6 h6b6 b3d4 d7b5 d4b5 b6f2 f1f2
9675570 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 9 seldepth 12 multipv 1 score cp -18 nodes 1206 nps 603000 tbhits 0 time 2 pv g3f2 e2f2 c6d5 c5b6 h6b6 b3d4 d7b5 d4b5 b6f2 f1f2 a6b5 e4d5
9675575 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 10 seldepth 16 multipv 1 score cp -4 nodes 10773 nps 769500 tbhits 0 time 14 pv g3f2 e2f2 c6d5 c5b6 h6b6 b3d4 d7b5 d4b5 b6f2 f1f2 a6b5 e4d5 f7f6 b2b5
9675727 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 11 seldepth 18 multipv 1 score cp -60 nodes 133503 nps 809109 tbhits 0 time 165 pv g3f2 e2f2 d8g8 f2f7 h6g5 f7f3 a3a4 f1e1 h5g3 e4e5 d7f5 d5d6 e7d6 e5d6
...
9676091 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 12 seldepth 20 multipv 1 score cp -80 nodes 423637 nps 799315 tbhits 0 time 530 pv g3f2 e2f2 d8g8 f2f7 h6g5 f1f2 d7h3 c2c3 c6d5 f7d5 c8b8 d5g5 g8g5 f2f3
...
9676670 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 13 seldepth 21 multipv 1 score cp -58 nodes 872569 nps 786807 hashfull 105 tbhits 0 time 1109 pv b6b5 e2f3 h6g5 f3f7 g3f2 f1f2 h5g3 f7f3 c8b8 c2c4 d8g8 e4e5 d7f5 c4b5 c6d5
...
9676983 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 14 seldepth 20 multipv 1 score cp -61 nodes 1113329 nps 782931 hashfull 132 tbhits 0 time 1422 pv b6b5 c2c3 g3f2 e2f2 h5g3 f1e1 f7f5 e4f5 c6d5 d3b4 g3e4 f2f3 h6g5 b4d5 d7f5 d5b4
...
9678664 <Stockfish_17092216-64&#40;455&#41;&#58; info depth 15 seldepth 23 multipv 1 score cp -34 nodes 2412512 nps 777477 hashfull 299 tbhits 0 time 3103 pv b6b5
9678665 <Stockfish_17092216-64&#40;455&#41;&#58; bestmove b6b5 ponder b3d4

Code: Select all

&#91;Site "RWBC&#58;&#58;CAPPUCCINO"&#93;
&#91;Date "2017.10.20"&#93;
&#91;Round "65"&#93;
&#91;White "StockfishTB_17092216-64"&#93;
&#91;Black "Stockfish_17092216-64"&#93;
&#91;Result "*"&#93;
&#91;FEN "r1bqkbnr/ppppppp1/2n4p/1B6/4P3/8/PPPP1PPP/RNBQK1NR w KQkq - 0 1"&#93;
&#91;PlyCount "139"&#93;
&#91;SetUp "1"&#93;
&#91;Termination "adjudication"&#93;
&#91;TimeControl "60/30"&#93;

1. Nf3 &#123;+0.55/16 1.1s&#125; a6 &#123;-0.60/16 1.5s&#125; 2. Bxc6 &#123;+0.60/16 0.46s&#125;
dxc6 &#123;-0.71/17 0.73s&#125; 3. d3 &#123;+0.51/17 0.58s&#125; g5 &#123;-0.51/14 0.20s&#125;
4. Bd2 &#123;+0.83/14 0.18s&#125; Bg7 &#123;-0.66/15 0.55s&#125; 5. Bc3 &#123;+0.69/17 0.88s&#125;
Bxc3+ &#123;-0.55/15 0.50s&#125; 6. bxc3 &#123;+0.66/17 0.88s&#125; Nf6 &#123;-0.60/15 0.65s&#125;
7. Nbd2 &#123;+0.55/16 0.58s&#125; g4 &#123;-0.48/15 0.24s&#125; 8. Ne5 &#123;+0.73/16 0.44s&#125;
Qd6 &#123;-0.52/15 0.32s&#125; 9. Nec4 &#123;+0.57/16 0.86s&#125; Qf4 &#123;-0.60/16 0.56s&#125;
10. Rb1 &#123;+0.72/17 1.2s&#125; h5 &#123;-0.68/16 0.78s&#125; 11. Qe2 &#123;+0.74/17 0.34s&#125;
h4 &#123;-0.67/16 0.64s&#125; 12. d4 &#123;+0.81/15 0.36s&#125; Rh5 &#123;-0.68/15 0.34s&#125;
13. O-O &#123;+0.59/16 0.54s&#125; b6 &#123;-0.60/13 0.11s&#125; 14. Nb2 &#123;+0.68/14 0.47s&#125;
Qh6 &#123;-0.80/15 0.69s&#125; 15. Nd3 &#123;+0.43/16 2.9s&#125; Ra5 &#123;-0.65/13 0.069s&#125;
16. Rb2 &#123;+0.54/15 0.53s&#125; g3 &#123;-0.82/14 1.0s&#125; 17. h3 &#123;+0.82/13 0.17s&#125;
Nh5 &#123;-0.74/13 0.29s&#125; 18. c4 &#123;+0.66/14 1.2s&#125; Ra3 &#123;-0.88/14 0.74s&#125;
19. d5 &#123;+0.89/12 0.29s&#125; Bd7 &#123;-0.82/12 0.61s&#125; 20. Nb3 &#123;+0.38/13 0.99s&#125;
O-O-O &#123;-0.18/12 0.65s&#125; 21. c5 &#123;+0.42/12 0.45s&#125; b5 &#123;-0.34/15 3.1s&#125;
*
(Analysis mode same conditions, as in the game and stepping through in analysis mode in similar speed attempting to create similar hash entries finally succeeded after some tries)

Code: Select all

dep	score	nodes	time
 17	 -0.24 	4.96M  	0&#58;06.34	b6b5 c2c3 g3f2 e2f2 h5g3 f1e1 f7f5 e4f5 d7f5 d3b4 c6d5 c5c6 c8b8 e1e7 h6d6 f2c5 d6c5 b3c5 a3c3 b4a6 b8a7 e7c7 a7a8 c7b7 c3c1 g1f2 c1f1 f2e3 d5d4 e3d2
 17	 -0.37 	4.87M  	0&#58;06.23	b6b5
 17	 -0.54 	4.82M  	0&#58;06.19	b6b5 c2c3
 17	 -0.31 	4.35M  	0&#58;05.60	b6b5
 17	 -0.39 	4.27M  	0&#58;05.51	b6b5
 16	 -0.46 	4.14M  	0&#58;05.34	b6b5 c2c3 g3f2 e2f2 h5g3 f1e1 f7f5 e4f5 c6d5 d3e5 g3e4 f2d4 d7e8 c5c6 h6f6 b3c5 e8c6 c5e4 d5e4 d4c5 c6b7 c5a3
 16	 -0.52 	4.06M  	0&#58;05.24	b6b5
 16	 -0.65 	3.92M  	0&#58;05.06	b6b5 c2c3
 16	 -0.49 	3.41M  	0&#58;04.40	b6b5 c2c3
 16	 -0.37 	3.05M  	0&#58;03.93	b6b5 c2c3
 16	 -0.30 	3.00M  	0&#58;03.87	b6b5 c2c3
 15	 -0.22 	2.32M  	0&#58;02.98	b6b5 b3d4 c6d5 e4d5 h6g5 e2e5 g5e5 d3e5 g3f2 g1f2 h5f4 e5c6 d7c6 d4c6 d8d7 f2g1 a3a4 f1f2 f4d5
 14	 -0.36 	1.74M  	0&#58;02.22	b6b5 b3d4 c6d5 e4d5 g3f2 e2f2 d8g8 f2f3 c8b8 b2b3 a3b3 d4b3 g8g3 f3e4 d7h3
 13	 -0.80 	629426	0&#58;00.79	c6d5 e4d5 h6g5 e2f3 c8b8 c5b6 c7b6 b3d4 b6b5 f3f7 a3d3 c2d3 h5f4
 12	 -0.63 	265242	0&#58;00.34	a3a4 e2f3 g3f2 f1f2 h5g3 c2c4 f7f6 e4e5 d7f5 c5b6 f5d3 b6b7 c8b8 f3d3 f6e5
 11	 -0.75 	72384  	0&#58;00.09	g3f2 e2f2 c6d5 e4d5 d8g8 f2f7 h6g5 f1f2 d7h3 c2c4 c8b8 c5b6 c7b6
 10	 -0.13 	43524  	0&#58;00.06	g3f2 e2f2 d8g8 f2f7 h6g5 f7f3 h5g3 f1f2 a3a4 b3d2 b6b5 d3f4 c6d5 e4d5
  9	 -0.17 	11475  	0&#58;00.01	g3f2 f1f2 h5g3 e2e1 h6h5 c2c4 a6a5 c5b6 c7b6 c4c5
  8	 -0.69 	1525    	0&#58;00.00	g3f2 e2f2 d8g8 c5b6 c6d5 b6b7 c8b8 b3c5 d7h3
  7	 -0.70 	845      	0&#58;00.00	g3f2 e2f2 d8g8 c5b6 c6d5 b6b7 c8b8 e4d5
  6	 -0.73 	657      	0&#58;00.00	g3f2 e2f2 d8g8 c5b6 c6d5 b6b7 c8b8
  5	 -0.73 	515      	0&#58;00.00	g3f2 e2f2 d8g8 c5b6 c6d5 b6b7 c8b8
  4	 -0.84 	271      	0&#58;00.00	c6d5 e4d5 h6g5 e2f3
  3	 -0.84 	195      	0&#58;00.00	c6d5 e4d5 h6g5
  2	 -0.84 	138      	0&#58;00.00	c6d5 e4d5
  1	 -0.66 	60        	0&#58;00.00	g3f2 e2f2
https://rwbc-chess.de

trollwatch:
Chessqueen + chessica + AlexChess + Eduard + Sylwy
User avatar
cdani
Posts: 2204
Joined: Sat Jan 18, 2014 10:24 am
Location: Andorra

Re: Hashfull in Stockfish slowdown in fast games?

Post by cdani »

Hashfull calls this function

Code: Select all

int TranspositionTable&#58;&#58;hashfull&#40;) const &#123;

  int cnt = 0;
  for &#40;int i = 0; i < 1000 / ClusterSize; i++)
  &#123;
      const TTEntry* tte = &table&#91;i&#93;.entry&#91;0&#93;;
      for &#40;int j = 0; j < ClusterSize; j++)
          if (&#40;tte&#91;j&#93;.genBound8 & 0xFC&#41; == generation8&#41;
              cnt++;
  &#125;
  return cnt;
&#125;
that sure it costs some more time than desirable as it needs to bring back some slow main memory many times.

It does not happen often that is executed, but can be wrapped in an uci parameter that I would put as disabled by default, as 99.9% of times nobody is there to see its result.

Or for example once it arrives to 999 set some flag somewhere to not call again the function.