Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Depth 245 anomaly during TCEC #2717

Closed
mstembera opened this issue Jun 5, 2020 · 25 comments
Closed

Depth 245 anomaly during TCEC #2717

mstembera opened this issue Jun 5, 2020 · 25 comments

Comments

@mstembera
Copy link
Contributor

I was looking at this TCEC game
https://tcec-chess.com/#div=p&game=72&season=18&x=archive
and noticed that on move 67 SF reached our max depth of 245. This isn't so strange on its own except that the depth never went above 68 on any other move. The time used, nodes searched, and TB hits, all look normal. Does anyone have a plausible explanation or could this be an issue?

@joergoster
Copy link
Contributor

There was also a big difference in depth between threads reported here #2620
Probably the thread with the highest depth was chosen by the thread voting. TB scores are getting stored with max depth, and one thread probably always took the TT cutoff and made it to MAX_PLY ...

@vondele
Copy link
Member

vondele commented Jun 6, 2020

TB could indeed be a reason for this. I couldn't yet reproduce it, but so far tried without TB.

@mstembera
Copy link
Contributor Author

Maybe that's correct I'm not sure. The fact that it only happened in the position on move 67 and not any of the other similar positions just before or after seems odd regardless.

@mstembera
Copy link
Contributor Author

Ok here is a game where it happens several times
https://tcec-chess.com/#div=p&game=16&season=18&x=archive

@vondele
Copy link
Member

vondele commented Jun 9, 2020

could we get the cutechess log for that game? Might be useful to figure out what's going on.

@vondele
Copy link
Member

vondele commented Jun 9, 2020

s18p_16live.log.txt

@Alayan-stk-2
Copy link

This happened again yesterday in another game after Stockfish had found a TB win.

@joergoster
Copy link
Contributor

Are we sure the thread voting patch is working correctly for cases with very high depth differences?
https://github.com/official-stockfish/Stockfish/blob/master/src/thread.cpp#L240-L241

@vondele
Copy link
Member

vondele commented Jul 7, 2020

@joergoster not necessarily, or said differently, that thread will have a very high weight. I once tried to limit the depth difference, but those patches did not pass:
https://tests.stockfishchess.org/tests/view/5e9c2bd927460669d4042db0
https://tests.stockfishchess.org/tests/view/5e9c2bcd27460669d4042dae
https://tests.stockfishchess.org/tests/view/5e9c2bc127460669d4042dac

Some analysis why this is happening is still missing.

@joergoster
Copy link
Contributor

joergoster commented Jul 7, 2020

@vondele But that seems more like a bugfix, no?

But first, however, it must be fully understood what is going on.

Edit: In TB win positions we shouldn't accept threads with lower scores, however!

@vondele
Copy link
Member

vondele commented Jul 7, 2020

Yes, we need to fully understand before we can say something is a bug fix, or test it as a bug fix.... so testing as an Elo gainer was a quick workaround ;-)

I agree that in TB win positions we should use the score, rather than a vote (but I think we do that already).

@dav1312
Copy link
Contributor

dav1312 commented Apr 20, 2022

@ghost
Copy link

ghost commented Apr 23, 2022

depth 245 is a maximum depth of stockfish
it was happened when adjustedDepth has bug or problem in main source code

Depth adjustedDepth = std::max(1, rootDepth - failedHighCnt - searchAgainCounter);
bestValue = Stockfish::search<Root>(rootPos, ss, alpha, beta, adjustedDepth, false);

see search.cpp , line 372 & 373 from this link :

https://github.com/official-stockfish/Stockfish/blob/master/src/search.cpp#L372
https://github.com/official-stockfish/Stockfish/blob/master/src/search.cpp#L373

@vondele
Copy link
Member

vondele commented May 8, 2022

so, some more investigation of the games https://tests.stockfishchess.org/tests/view/6272a6afc8f14123163c1997 some of these high depth happen also there, so it doesn't require TB. It doesn't happen in a single threaded run (https://tests.stockfishchess.org/tests/view/626abd7e8707aa698c0093a8), so it seems purely related to threading.
(note that these are depth 245 in the middle of a game, they can happen without concern if there is a mate announcement, or stalemate, 3fold on then next move).

So somehow an interaction between threads, but at least we can take TB out of the picture.

@vondele vondele removed the tablebases label May 8, 2022
@miguel-l
Copy link
Contributor

miguel-l commented May 9, 2022

I'm not too familiar with threading code, but does the following make sense:
Is it possible that this has something to do with Threads.increaseDepth ?

As far as I can tell, this is handled only by mainThread and updated only at the end of its current iteration. My thought is if it gets stuck in resolving a fail or stuck in some search explosion while increaseDepth is false, then some other thread could be looping over the same rootDepth until they reach 245.

@ruicoelhopedro
Copy link
Contributor

ruicoelhopedro commented Jun 8, 2022

Two examples where this issue happens: depth245.zip
Logs with both regular debug log file and with per-thread search logs, reproduced locally.

For one of the cases, quick plot of the completed depth over time for each thread:
depth-time

@mstembera
Copy link
Contributor Author

I'm not sure if this is related but in the current TCEC swiss SF announced mate in 73 even though it only reported depth 39 and select depth 61. This was on move 53 of this game https://tcec-chess.com/#div=sw3&game=93&season=22

miguel-l added a commit to miguel-l/Stockfish that referenced this issue Jun 18, 2022
…cally per thread. Use same TC and threads as test 6272a6afc8f14123163c1997 where this was shown to occur. low tp. Bench: 5845802
miguel-l added a commit to miguel-l/Stockfish that referenced this issue Jun 18, 2022
… counter locally per thread helps. Use same TC and threads (but with low throughput) as test 6272a6afc8f14123163c1997 where this was known to occur. I may try to check pgns from time to time and stop the test earlier if the issue persists. Bench: 5845802
miguel-l added a commit to miguel-l/Stockfish that referenced this issue Jun 18, 2022
… counter locally per thread helps. Use same TC and threads (but with low throughput) as test 6272a6afc8f14123163c1997 where this was known to occur. I may try to check pgns from time to time and stop the test earlier if the issue persists. Bench: 5845802
@vondele
Copy link
Member

vondele commented Jun 30, 2022

looks like @miguel-l has identified the cause in the test https://tests.stockfishchess.org/tests/view/62aee644e7ee5525ef88c15a

In discord:
Disservin

Today at 9:47 AM
I just checked the first 756 pgns and the patch has no weird 245 depths other than near checkmate or draw, base has 422
422 (some of them are also checkmate and draw depths) but shouldnt be that many < 10

I can see how these changes could be related.

@vondele
Copy link
Member

vondele commented Jun 30, 2022

@ruicoelhopedro any chance you could repeat your analysis, printing out an additional number of each thread, namely the adjustedDepth in addition to the rootDepth?

@vondele
Copy link
Member

vondele commented Jun 30, 2022

So, explanation being discussed at https://discord.com/channels/435943710472011776/813919248455827515/991975708953935903
basically, while the master thread has a hard time to resolve a given depth with increaseDepth false, other threads basically search at constant depth, which gets faster and faster over time. As a result their 'apparent depth' goes to the max 245 quickly.
I still have to look carefully at how this is actually fixed.
It might not be too bad what's going on right now, but it will screw a bit the thread voting scheme.

It's also consistent with the earlier posted graph where mainthread is stuck at a given depth.

and of course that's @miguel-l explanation.

@ruicoelhopedro
Copy link
Contributor

@ruicoelhopedro any chance you could repeat your analysis, printing out an additional number of each thread, namely the adjustedDepth in addition to the rootDepth?

I've started some games with the extra field. I'll post the logs when the issue is reproduced.

@ruicoelhopedro
Copy link
Contributor

Here they go, got a bit lucky as this happened in 3 games: depth245_adjustedDepth.zip

@vondele
Copy link
Member

vondele commented Jun 30, 2022

so, the logs show that what we think is happing is actually happening. The increaseDepth is false, adjustedDepth is constant, and the rootDepth just reaches the maximum.

@miguel-l
Copy link
Contributor

miguel-l commented Jul 2, 2022

Just want to have these somewhere I can find it (and also in case others might want to use or improve upon).

For downloading sample pgns from a test
for i in {0..99}; do wget "https://tests.stockfishchess.org/api/pgn/62aee644e7ee5525ef88c15a-${i}.pgn"; done

For manual checking
cat *.pgn | grep "White\|Black\|\/245" | grep -B 2 "\/245" | less

vondele added a commit to vondele/Stockfish that referenced this issue Jul 8, 2022
If the elapsed time is close to the available time, the time management thread can signal that the next iterations should be searched at the same depth (Threads.increaseDepth = false). While the rootDepth increases, the adjustedDepth is kept constant with the searchAgainCounter.

In exceptional cases, when threading is used and the master thread, which controls the time management, signals to not increaseDepth, but by itself takes a long time to finish the iteration, the helper threads can search repeatedly a the same depth. This search finishes more and more quickly, leading to helper threads that report a rootDepth of MAX_DEPTH (245). The latter is not optimal as it is confusing for the user, stops search on these threads, and leads to an incorrect bias in the thread voting scheme. Probably with only a small impact on strength.

This behavior was observed almost two years ago,
see official-stockfish#2717

This patch fixes official-stockfish#2717 by ensuring the effective depth increases at once every four iterations,
even in increaseDepth is false.

Depth 245 searches (for non-trivial positions) were indeed absent with this patch,
but frequent with master in the tests below:
https://discord.com/channels/435943710472011776/813919248455827515/994872720800088095
Total pgns: 2173
Base: 2867
Patch: 0

it passed non-regression testing in various setups:

SMP STC:
https://tests.stockfishchess.org/tests/view/62bfecc96178ffe6394ba036
LLR: 2.94 (-2.94,2.94) <-2.25,0.25>
Total: 37288 W: 10171 L: 10029 D: 17088
Ptnml(0-2): 75, 3777, 10793, 3929, 70

SMP LTC:
https://tests.stockfishchess.org/tests/view/62c08f6f49b62510394be066
LLR: 2.94 (-2.94,2.94) <-2.25,0.25>
Total: 190568 W: 52125 L: 52186 D: 86257
Ptnml(0-2): 70, 17854, 59504, 17779, 77

LTC:
https://tests.stockfishchess.org/tests/view/62c08b6049b62510394bdfb6
LLR: 2.96 (-2.94,2.94) <-2.25,0.25>
Total: 48120 W: 13204 L: 13083 D: 21833
Ptnml(0-2): 54, 4458, 14919, 4571, 58

Special thanks to miguel-I,  Disservin, ruicoelhopedro and others for analysing the problem,
the data, and coming up with the key insight, needed to fix this longstanding issue.

Bench: 5182295
@vondele vondele closed this as completed in 2e02dd7 Jul 9, 2022
PikaCat-OuO pushed a commit to official-pikafish/Pikafish that referenced this issue Oct 7, 2022
If the elapsed time is close to the available time, the time management thread can signal that the next iterations should be searched at the same depth (Threads.increaseDepth = false). While the rootDepth increases, the adjustedDepth is kept constant with the searchAgainCounter.

In exceptional cases, when threading is used and the master thread, which controls the time management, signals to not increaseDepth, but by itself takes a long time to finish the iteration, the helper threads can search repeatedly at the same depth. This search finishes more and more quickly, leading to helper threads that report a rootDepth of MAX_DEPTH (245). The latter is not optimal as it is confusing for the user, stops search on these threads, and leads to an incorrect bias in the thread voting scheme. Probably with only a small impact on strength.

This behavior was observed almost two years ago,
see official-stockfish/Stockfish#2717

This patch fixes #2717 by ensuring the effective depth increases at once every four iterations,
even in increaseDepth is false.

Depth 245 searches (for non-trivial positions) were indeed absent with this patch,
but frequent with master in the tests below:
https://discord.com/channels/435943710472011776/813919248455827515/994872720800088095
Total pgns: 2173
Base: 2867
Patch: 0

it passed non-regression testing in various setups:

SMP STC:
https://tests.stockfishchess.org/tests/view/62bfecc96178ffe6394ba036
LLR: 2.94 (-2.94,2.94) <-2.25,0.25>
Total: 37288 W: 10171 L: 10029 D: 17088
Ptnml(0-2): 75, 3777, 10793, 3929, 70

SMP LTC:
https://tests.stockfishchess.org/tests/view/62c08f6f49b62510394be066
LLR: 2.94 (-2.94,2.94) <-2.25,0.25>
Total: 190568 W: 52125 L: 52186 D: 86257
Ptnml(0-2): 70, 17854, 59504, 17779, 77

LTC:
https://tests.stockfishchess.org/tests/view/62c08b6049b62510394bdfb6
LLR: 2.96 (-2.94,2.94) <-2.25,0.25>
Total: 48120 W: 13204 L: 13083 D: 21833
Ptnml(0-2): 54, 4458, 14919, 4571, 58

Special thanks to miguel-I,  Disservin, ruicoelhopedro and others for analysing the problem,
the data, and coming up with the key insight, needed to fix this longstanding issue.

closes official-stockfish/Stockfish#4104

Bench: 5182295
(cherry picked from commit 2e02dd7)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants