Closed lucasart closed 5 years ago
Minimal repro so far. Played games in 4+0.04, hash=4. Here's an example among many:
[White "./Engines/fruit_051103"]
[Black "./Demolito/master"]
[Result "0-1"]
[FEN "rnbqk1nr/ppppppbp/6p1/8/2B1P3/8/PPPP1PPP/RNBQK1NR b KQkq - 0 1"]
[TimeControl "4+0.04"]
1... e6 {+0.08/10 0.27s} 2. Nc3 {+0.19/8 0.086s} Ne7 {-0.04/11 0.18s}
3. Nf3 {+0.19/8 0.14s} d5 {-0.02/11 0.18s} 4. Bb3 {+0.18/8 0.12s}
Nbc6 {-0.02/9 0.24s} 5. O-O {+0.24/9 0.19s} O-O {-0.12/10 0.23s}
6. d3 {+0.19/9 0.15s} h6 {-0.09/10 0.22s} 7. Bd2 {+0.48/7 0.17s}
g5 {-0.05/10 0.21s} 8. Re1 {+0.56/7 0.12s} a6 {-0.03/10 0.20s}
9. Rb1 {+0.64/6 0.11s} Qd6 {+0.30/10 0.20s} 10. Qc1 {+0.36/7 0.23s}
Bd7 {+0.22/9 0.19s} 11. exd5 {+0.18/8 0.25s} exd5 {-0.14/11 0.17s}
12. h4 {+0.50/8 0.080s} g4 {-0.19/11 0.13s} 13. Bf4 {+0.49/8 0.069s}
Qc5 {-0.23/10 0.16s} 14. Ne5 {+0.54/7 0.068s} Nxe5 {-0.44/11 0.12s}
15. Bxe5 {+0.69/7 0.091s} Bxe5 {-0.59/11 0.11s} 16. Rxe5 {+1.09/6 0.042s}
Qd6 {-0.68/11 0.11s} 17. d4 {+0.82/7 0.083s} c6 {-0.09/11 0.15s}
18. h5 {+0.71/7 0.073s} Qf6 {-0.09/10 0.14s} 19. Na4 {+0.77/7 0.072s}
Rae8 {-0.21/10 0.14s} 20. Nc5 {+1.02/8 0.078s} Bc8 {-0.35/11 0.11s}
21. Qe1 {+1.10/8 0.10s} b6 {-0.47/10 0.13s} 22. Na4 {+1.13/9 0.088s}
b5 {-0.39/12 0.10s} 23. Nc5 {+1.20/8 0.057s} Qd6 {-0.32/12 0.086s}
24. Qe2 {+1.37/8 0.079s} f6 {-0.28/11 0.086s} 25. Re3 {+1.27/8 0.10s}
Rf7 {-0.31/11 0.088s} 26. a4 {+1.02/7 0.10s} Qf4 {0.00/9 0.11s}
27. c3 {+0.88/7 0.088s} Qg5 {-0.47/10 0.11s} 28. axb5 {+1.36/7 0.046s}
axb5 {-0.40/11 0.096s} 29. Ra1 {+1.38/8 0.060s} f5 {-0.19/10 0.10s}
30. Ra7 {+1.49/8 0.084s} f4 {-0.73/10 0.096s} 31. Re5 {+1.32/8 0.092s}
Qh4 {-0.05/10 0.096s} 32. Bc2 {+0.31/6 0.12s} g3 {+3.17/10 0.090s}
33. Bh7+ {-3.71/7 0.42s} Rxh7 {+5.28/9 0.087s} 34. Qd3 {-7.59/8 0.51s}
Qh2+ {+8.47/11 0.060s} 35. Kf1 {-5.07/4 0.009s} Qh1+ {+10.59/13 0.062s}
36. Ke2 {-5.07/4 0.002s} Bg4+ {+10.59/12 0.060s} 37. f3 {-8.20/8 0.053s}
Qxg2+ {+10.81/12 0.060s} 38. Kd1 {-10.27/9 0.16s} Bxf3+ {+10.95/12 0.060s}
39. Kc1 {-10.19/9 0.037s} Qh1+ {+11.05/11 0.057s} 40. Kc2 {-10.61/7 0.029s}
g2 {+11.24/12 0.060s} 41. Qxf3 {-10.87/7 0.049s} g1=Q {+11.36/11 0.057s}
42. Qxh1 {-11.01/6 0.023s} Qxh1 {+11.36/12 0.056s} 43. Ne6 {-11.15/6 0.048s}
f3 {+15.73/11 0.063s} 44. Nc7 {-15.31/6 0.055s} f2 {+17.67/12 0.056s}
45. Nxe8 {-18.40/7 0.043s} f1=Q {+18.35/12 0.055s} 46. Kb3 {-20.14/6 0.034s}
Qc4+ {+21.04/12 0.055s} 47. Kc2 {-20.14/6 0.043s} Rf7 {+25.47/11 0.050s}
48. Nf6+ {-26.18/6 0.038s} Rxf6 {+30.82/11 0.052s} 49. Ra8+ {-M12/7 0.019s}
Kf7 {+M11/11 0.055s} 50. Rxe7+ {-M10/34 0.034s} Kxe7 {+M9/13 0.053s}
51. Ra7+ {-M8/32 0.030s} Kd6 {+M7/13 0.050s} 52. Rd7+ {-M6/31 0.027s}
Kxd7 {+M5/11 0.050s} 53. Kd2 {-M4/31 0.033s} Rf2+ {+M3/11 0.065s}
54. Ke3 {-M2/4 0s} Qe4+ {+M1/11 0.050s} 55. Kxf2 {-M4/4 0s}
Qce2+ {+M3/11 0.060s} 56. Kg1 {-M2/30 0.032s} Q2g2# {+M1/10 0.065s, Black mates}
0-1
At move 54, Demolito played Qe4+, missing Qe1# (or Qf3#).
The above cannot be reproduced by simply feeding the position at move 54, and searching with an empty hash table. So it's most likely a hash table bug.
fixed by 48e9b933ce65fb4f9d970c30f6845e814a059ee1
After pulling from master, demolito has still trouble finding the mate in this position. It needs more than 40s to complete d13 and eventually loses track of the mate in 1.
(echo uci; echo ucinewgame; echo position fen 8/7k/P3Q3/8/1p6/1B2Q3/3K4/8 b - - 32 184 moves h7h8; echo isready; echo go depth 13) | ./demolito id name Demolito 2017-10-09 id author lucasart option name UCI_Chess960 type check default false option name Hash type spin default 1 min 1 max 1048576 option name Threads type spin default 1 min 1 max 63 option name Contempt type spin default 10 min -100 max 100 option name Time Buffer type spin default 60 min 0 max 1000 uciok readyok info depth 1 score mate 1 time 0 nodes 73 pv e6h6 info depth 2 score mate 1 time 0 nodes 113 pv e6h6 info depth 3 score mate 1 time 0 nodes 158 pv e6h6 info depth 4 score mate 1 time 0 nodes 237 pv e6h6 info depth 5 score mate 1 time 0 nodes 344 pv e6h6 info depth 6 score mate 1 time 0 nodes 446 pv e6h6 info depth 7 score mate 1 time 0 nodes 699 pv e6h6 info depth 8 score mate 1 time 0 nodes 1299 pv e6h6 info depth 9 score mate 1 time 14 nodes 33194 pv e6h6 info depth 10 score mate 1 time 18 nodes 45015 pv e6h6 info depth 11 score mate 1 time 543 nodes 1608430 pv e6h6 info depth 12 score mate 1 time 2680 nodes 7857571 pv e6h6 info depth 13 score mate -1 time 44760 nodes 131184958 pv e6e5 h8h7 b3c2 h7g8 e3g5 g8f7 g5f6 f7g8 f6h8 g8f7 h8h7 f7f8 h7f5 f8g8 e5e8 g8g7 e8h8 g7h8 f5f6 h8g8 a6a7 b4b3 bestmove e6e5 ponder h8h7
Thanks. I'll have a look.
I've been playing quite a few games, disabling resign adjudication, and everything seems in order.
I don't know if everything is alright. Same position as above and using a debug build gives:
./demolito_popcnt
uci
id name Demolito 2018-12-03
id author lucasart
option name UCI_Chess960 type check default false
option name Hash type spin default 1 min 1 max 1048576
option name Threads type spin default 1 min 1 max 63
option name Contempt type spin default 10 min -100 max 100
option name Time Buffer type spin default 60 min 0 max 1000
uciok
isready
readyok
ucinewgame
position fen 8/7k/P3Q3/8/1p6/1B2Q3/3K4/8 b - - 32 184 moves h7h8
isready
readyok
go depth 23
info depth 1 score mate 1 time 0 nodes 73 pv e6h6
demolito_popcnt: ./src/search.c:229: int search(Worker , const Position , int, int, int, int, move_t *, move_t): Assertion `-MATE <= alpha && alpha < beta && beta <= MATE' failed.
[1] 5247 abort (core dumped) ./demolito_popcnt
When using a normal build it keeps the winning move, but it takes more than 2 minutes to complete depth 17
Thanks. I can reproduce:
$ make OUT=debug CF=-std=gnu11\ -O1
clang -march=native -DPEXT -std=gnu11 -O1 -DVERSION=\"2018-12-03\" ./src/*.c -o debug -s -lm -lpthread
$ ./debug
ucinewgame
position fen 8/7k/P3Q3/8/1p6/1B2Q3/3K4/8 b - - 32 184 moves h7h8
go depth 5
info depth 1 score mate 1 time 0 nodes 73 pv e6h6
debug: ./src/search.c:229: int search(Worker *, const Position *, int, int, int, int, move_t *, move_t): Assertion `-MATE <= alpha && alpha < beta && beta <= MATE' failed.
Aborted (core dumped)
Found the problem:
That means we start depth 2 with alpha=31999-15, beta=31999+15=32014 => illegal bound!
I'm not sure this bug has any practical consequence (other than firing an assert in debug compiles). But, for good measure, let's fix it.
Sorry to disturb again. A debug compile crashes on this very same position on depth 9.
id name Demolito 2018-12-04 id author lucasart option name UCI_Chess960 type check default false option name Hash type spin default 1 min 1 max 1048576 option name Threads type spin default 1 min 1 max 63 option name Contempt type spin default 10 min -100 max 100 option name Time Buffer type spin default 60 min 0 max 1000 uciok readyok info depth 1 score mate 1 time 0 nodes 73 pv e6h6 info depth 2 score mate 1 time 0 nodes 111 pv e6h6 info depth 3 score mate 1 time 0 nodes 155 pv e6h6 info depth 4 score mate 1 time 0 nodes 221 pv e6h6 info depth 5 score mate 1 time 0 nodes 316 pv e6h6 info depth 6 score mate 1 time 0 nodes 420 pv e6h6 info depth 7 score mate 1 time 0 nodes 656 pv e6h6 info depth 8 score mate 1 time 1 nodes 1184 pv e6h6 info depth 9 score mate 1 time 1 nodes 3186 pv e6h6 demolito_popcnt: ./src/htable.c:26: int score_to_hash(int, int): Assertion `abs(score) < MATE' failed. [1] 2561 done ( echo uci; echo ucinewgame; echo position fen 8/7k/P3Q3/8/1p6/1B2Q3/3K4/8 b ) | 2562 abort (core dumped) ./demolito_popcnt
And a release build loses the mate at depth 15
id name Demolito 2018-12-04 id author lucasart option name UCI_Chess960 type check default false option name Hash type spin default 1 min 1 max 1048576 option name Threads type spin default 1 min 1 max 63 option name Contempt type spin default 10 min -100 max 100 option name Time Buffer type spin default 60 min 0 max 1000 uciok readyok info depth 1 score mate 1 time 0 nodes 73 pv e6h6 info depth 2 score mate 1 time 0 nodes 111 pv e6h6 info depth 3 score mate 1 time 0 nodes 155 pv e6h6 info depth 4 score mate 1 time 0 nodes 221 pv e6h6 info depth 5 score mate 1 time 0 nodes 316 pv e6h6 info depth 6 score mate 1 time 0 nodes 420 pv e6h6 info depth 7 score mate 1 time 0 nodes 656 pv e6h6 info depth 8 score mate 1 time 1 nodes 1184 pv e6h6 info depth 9 score mate 1 time 1 nodes 3186 pv e6h6 info depth 10 score mate 1 time 3 nodes 11862 pv e6h6 info depth 11 score mate 1 time 6 nodes 19991 pv e6h6 info depth 12 score mate 1 time 10 nodes 35603 pv e6h6 info depth 13 score mate 1 time 25 nodes 97363 pv e6h6 info depth 14 score mate 1 time 52 nodes 199093 pv e6h6 info depth 15 score mate 1 time 5728 nodes 23973757 pv a6a7 h8h7 e3f3 h7h8 d2d3 h8g7 b3d5 g7h8 f3f6 h8h7 f6g6 h7h8 d5e4 b4b3 d3c3 b3b2
Not at all disturbance. These are the best bug reports one can get. Very useful.
I can reproduce
$ make OUT=debug CF=-std=gnu11\ -O1
clang -march=native -DPEXT -std=gnu11 -O1 -DVERSION=\"2018-12-04\" ./src/*.c -o debug -s -lm -lpthread
$ ./debug
ucinewgame
position fen 8/7k/P3Q3/8/1p6/1B2Q3/3K4/8 b - - 0 1
go depth 16
info depth 1 score cp -2817 time 1 nodes 3 pv h7h8
info depth 2 score mate -1 time 1 nodes 178 pv h7h8 e6h6
info depth 3 score mate -1 time 1 nodes 225 pv h7h8 e6h6
info depth 4 score mate -1 time 1 nodes 273 pv h7h8 e6h6
info depth 5 score mate -1 time 1 nodes 333 pv h7h8 e6h6
info depth 6 score mate -1 time 1 nodes 425 pv h7h8 e6h6
info depth 7 score mate -1 time 1 nodes 531 pv h7h8 e6h6
info depth 8 score mate -1 time 2 nodes 1117 pv h7h8 e6h6
info depth 9 score mate -1 time 2 nodes 1259 pv h7h8 e6h6
info depth 10 score mate -1 time 5 nodes 4027 pv h7h8 e6h6
debug: ./src/htable.c:34: int score_from_hash(int, int): Assertion `abs(hashScore) < MATE' failed.
Aborted (core dumped)
Even better reproduction
$ make CF=-std=gnu11\ -O1
clang -march=native -DPEXT -std=gnu11 -O1 -DVERSION=\"2018-12-04\" ./src/*.c -o demolito -s -lm -lpthread
$ ./demolito
ucinewgame
position fen 8/7k/P3Q3/8/1p6/1B2Q3/3K4/8 b - - 0 1 moves h7h8
go depth 20
info depth 1 score mate 1 time 0 nodes 73 pv e6h6
info depth 2 score mate 1 time 0 nodes 111 pv e6h6
info depth 3 score mate 1 time 1 nodes 155 pv e6h6
info depth 4 score mate 1 time 1 nodes 221 pv e6h6
info depth 5 score mate 1 time 1 nodes 316 pv e6h6
info depth 6 score mate 1 time 1 nodes 420 pv e6h6
info depth 7 score mate 1 time 2 nodes 656 pv e6h6
info depth 8 score mate 1 time 3 nodes 1184 pv e6h6
info depth 9 score mate 1 time 6 nodes 3186 pv e6h6
demolito: ./src/htable.c:26: int score_to_hash(int, int): Assertion `abs(score) < MATE' failed.
Aborted (core dumped)
Now it's clear that we are storing an out of bounds score in the hash table, and that cannot come from the mate/ply adjustment.
Problem happens here
// Reduced depth, zero window
score = nextDepth - reduction <= 0
? -qsearch(worker, &nextPos, ply + 1, nextDepth - reduction, -(alpha + 1), -alpha, false, childPv)
: -search(worker, &nextPos, ply + 1, nextDepth - reduction, -(alpha + 1), -alpha, childPv, 0);
with
node=2046, depth=6, ply=2, alpha=31999, score=32000
. . . . . . . .
. . . . . . . k
P . . . Q . . .
. . . . Q . . .
. p . . . . . .
. B . . . . . .
. . . K . . . .
. . . . . . . .
8/7k/P3Q3/4Q3/1p6/1B6/3K4/8 w - - 3
@erbsenzaehler: I just fixed yet another bug. I'm not sure it's the last one, though. Let me know if you see anything suspicious.
Works fine on my machine, too. As a side effect it reaches higher depths in this position much faster.
engines somehow hovers around, keepking the mate in sight, but never reduces DTM until forced to do so, or accidently.
The bug is present since, at least, f21b0e782580f6f51ff4e54e66b80a6ec5fbe53c.