TC 40/15 with low depth moves

[vondele]

as observed at CCRL and mentioned in discord, at a TC of N move in M seconds, without increment, the last move before the N moves are over can be played at small time, and particular very low depth (1). This leads to losses at this TC that are not necessary.

Some data:
https://discord.com/channels/435943710472011776/813919248455827515/969974503595712562
https://discord.com/channels/435943710472011776/724661489381670923/968608582960562288

[ghost]

I observed this at 40/4 repeating time control at chess960 as well. It is a legacy time control for sure, I don't think anyone would choose it starting afresh today. But it should still be looked at.

[vondele]

the problem is that with low time left (comparable to moveoverhead), and just one move we will essentially not search, so go wtime 32 btime 32 movestogo 1 sets optimal and maximum search time to <=1ms . I think this is due to reserving too many times the moveOverhead, in addition to an internal margin (3 time moveOverhead and 10ms internal overhead).

I've scheduled a test that would fix this: https://tests.stockfishchess.org/tests/view/6274e951e713302ff8f709c7

[Matthies]

Maybe you find this useful...
As an exercise for learning Python I wrote a script that parses pgn files and searches for "fast" moves and ran it against the latest Stockfish versions pgns from CCRL40/15: SF15, SF14.1, SF14 and SF13 each of them 1CPU and 4CPU.
"Fast moves" are moves with a depth < 10 that are not book moves, "only-moves" or moves with a mate score.
Fast moves: {40: 6, 77: 2, ... means that there were 6 games found with a fast 40th move, 2 games with a fast 77th move and so on.
You will notice that there is almost no problem in SF13 and SF14 while it gets a little serious in SF14.1 and even more serious in SF15.
But this could also be a side effect by Graham switching to a faster hardware and scaling speed to this hardware using less time. Visible in the smaller average move time.

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_15_64-bit.commented.[1283].pgn ...
======================================================
Player: Stockfish 15 64-bit
Games: 1283
Moves: 65074
Average move time: 19.694578479884438
Std deviation: 0.05376319870785041
Avg depth: 40.751605864093186
Fast moves: {40: 6, 77: 2, 78: 5, 79: 13, 80: 26, 118: 3, 119: 3, 120: 6, 159: 1, 160: 1}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_15_64-bit_4CPU.commented.[1016].pgn ...
======================================================
Player: Stockfish 15 64-bit 4CPU
Games: 1016
Moves: 58237
Average move time: 20.109361642941725
Std deviation: 0.06486724968667493
Avg depth: 47.5341277881759
Fast moves: {40: 4, 65: 2, 77: 2, 78: 4, 79: 10, 80: 18, 103: 1, 106: 1, 107: 1, 108: 1, 109: 1, 110: 1, 111: 1, 112: 1, 113: 1, 114: 1, 118: 2, 119: 4, 120: 5, 155: 1, 156: 1, 157: 2, 158: 1, 159: 1, 160: 3, 198: 1, 199: 2, 200: 2, 240: 1}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_14_1_64-bit.commented.[1829].pgn ...
======================================================
Player: Stockfish 14.1 64-bit
Games: 1829
Moves: 93819
Average move time: 19.82373322034983
Std deviation: 0.04486405308764372
Avg depth: 43.25229431138682
Fast moves: {40: 1, 79: 2, 80: 6, 119: 2, 120: 4}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_14_1_64-bit_4CPU.commented.[1054].pgn ...
======================================================
Player: Stockfish 14.1 64-bit 4CPU
Games: 1054
Moves: 54048
Average move time: 18.806708851391356
Std deviation: 0.05897459900770405
Avg depth: 51.840808170515096
Fast moves: {40: 3, 77: 1, 78: 1, 79: 2, 80: 7, 117: 1, 118: 2, 119: 2, 120: 4, 155: 1, 160: 3, 196: 1, 197: 1, 198: 1, 199: 2, 200: 2}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_14_64-bit.commented.[1167].pgn ...
======================================================
Player: Stockfish 14 64-bit
Games: 1167
Moves: 60300
Average move time: 25.20791560530679
Std deviation: 0.07305190162418505
Avg depth: 39.26422885572139
Fast moves: {120: 1, 157: 1, 158: 1, 159: 1, 160: 1}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_14_64-bit_4CPU.commented.[874].pgn ...
======================================================
Player: Stockfish 14 64-bit 4CPU
Games: 874
Moves: 45399
Average move time: 32.34723952069434
Std deviation: 0.13504531552667534
Avg depth: 43.415669948677284
Fast moves: {80: 1, 120: 1}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_13_64-bit.commented.[929].pgn ...
======================================================
Player: Stockfish 13 64-bit
Games: 929
Moves: 52558
Average move time: 25.528977834011975
Std deviation: 0.08778718645580771
Avg depth: 38.50173142052589
Fast moves: {79: 1, 80: 2}
======================================================

Reading C:\Entwicklung\PGNTools/PGN/Stockfish_13_64-bit_4CPU.commented.[1192].pgn ...
======================================================
Player: Stockfish 13 64-bit 4CPU
Games: 1192
Moves: 71418
Average move time: 24.45838920160174
Std deviation: 0.07950081532010225
Avg depth: 43.48295947800275
Fast moves: {}
======================================================

[vondele]

between SF 14 an SF14.1 there is
5b47b4e (Increase optimumTime by 10%)
which could lead to being out of time more often at the time control point

[GrahamCCRL]

Attached is a debug file that might help.
Dbg00036_Viridithas100064-bit_Stockfish15164-bit.txt

[GrahamCCRL]

RubiChess debug file for comparison.
Dbg00019_RubiChess2023041064-bit_Uralochka339d64-bit.txt

[Matthies]

I discussed the game Viri vs. SF in Graham's chat and asked him for the logs of some Rubi games cause Rubi measures the lag between the engine and the GUI by comparing the move time from the engines pov (time difference t2-t1 from getting "go" at internal time t1 to sending "bestmove" at internal t2) and what the GUI thinks about the time of this move (t3 - t4 with "go wtime t3" for this move and "go wtime t4" for the next move). Main result is probably that you could blame the GUI:
Eng01 (RubiChess 20230410 64-bit) <- info string Measured GUI overhead is 1526ms and time forfeits are very likely. Please increase Move_Overhead option!
But on the other side: You also could measure the expected GUI delay like I described and modify the aggressiveness of your time management respecting this measured/expected GUI delay.
With cutechess-cli being very exact regarding this measured GUI delay (usually < 6ms on my Ryzen 3700x even with full concurrency) you won't discover these problems at fishtest.

[vondele]

ugh.. 1.5s GUI overhead. Yeah, sure in that case one needs to set

Move Overhead type spin default 10 min 0 max 5000
Assume a time delay of x ms due to network and GUI overheads. This is useful to avoid losses on time in those cases.

it assumes the overhead is 10ms.

[GrahamCCRL]

I set the overhead in ChessGUI to 5000ms.

…

On Fri, Jun 30, 2023 at 10:13 PM Joost VandeVondele < ***@***.***> wrote: ugh.. 1.5s GUI overhead. Yeah, sure in that case one needs to set Move Overhead type spin default 10 min 0 max 5000 Assume a time delay of x ms due to network and GUI overheads. This is useful to avoid losses on time in those cases. it assumes the overhead is 10ms. — Reply to this email directly, view it on GitHub <#4000 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AVOIVUQZHKERWWGQEVKUV7DXN2RFBANCNFSM5UYQI4RA> . You are receiving this because you commented.Message ID: ***@***.***>

[Matthies]

@GrahamCCRL: As I told you in chat: The engine doesn't know about the GUIs 5000ms grace overhead and will do depth 1 moves. SF (black) gets 123ms here:

SendToEng2Time 0000000247074937 : Eng02 (Stockfish 15.1 64-bit) -> go movestogo 3 wtime 48903 btime 123
...
System time lag per move = 549 milliseconds
Eng02 (Stockfish 15.1 64-bit) thought for 672 milliseconds, time left = -549 milliseconds
Stockfish 15.1 64-bit saved by Time Overstep Margin of 5000 milliseconds.

And next move:

SendToEng2Time 0000000247109046 : Eng02 (Stockfish 15.1 64-bit) -> go movestogo 2 wtime 35497 btime -549

Engine gets negative time and needs to move immediately.

[vondele]

The right thing here is to setoption name Move Overhead value 1500, i.e. the option is exactly there to inform about expected (worst case?) GUI delays.

Receiving negative (even including zero) btime could lead to all kind of weird stuff. This is really a GUI bug.

[ghost]

GUI overhead of 1.5 seconds is horrendous. Potentially other engines are having the same issues in that environment but go unnoticed.

[jhonnold]

The binary for Berserk 11.1 given to Graham has a different default MoveOverhead value because of this exact same issue.

[ghost]

Why a special exe ? He can just change it.

[bftjoe]

The UCI protocol does not indicate how much additional time will be given after the last move of a movestogo tc. Using this type of time control at all is probably not a good idea.