UCI2WB 4.0

Discussion of chess software programming and technical issues.

Moderators: hgm, Rebel, chrisw

Michel
Posts: 2272
Joined: Mon Sep 29, 2008 1:50 am

Re: UCI2WB 4.0

Post by Michel »

hgm wrote: Sun Dec 09, 2018 10:47 am I now completely redesigned the master logic of UCI2WB: instead of having threads for all engine->GUI and all GUI->engine traffic, which would now and then block waiting for each other when there is a need to synchronize, it now has one of threads always listenining to the GUI, and instantly handling any incoming command, either processing it (if that can be done during search), or queueing it for execution by the 'engine thread'. The latter listens to the engine for as long as it is searching. (UCI engines always tell you when they are done searching!) But if the engine is idle or merely pondering it first processes all queued commands, before it starts listening to any ponder output. Only when the engine is idle and the queue empty it blocks waiting for a command to appear in the queue.
This description sounds quite complicated. Polyglot simply listens to both the engine and the GUI using an event loop. In Linux this is trivial to implement using select. On windows (which does not have select) it is a bit more complicated but still possible using threads and windows events. I think this works satisfactorily (although I must confess I tested almost exclusively on Linux).
Ideas=science. Simplification=engineering.
Without ideas there is nothing to simplify.
Joerg Oster
Posts: 937
Joined: Fri Mar 10, 2006 4:29 pm
Location: Germany

Re: UCI2WB 4.0

Post by Joerg Oster »

hgm wrote: Thu Dec 20, 2018 9:52 pm I now have made a test version of UCI2WB that reports what it is doing on an independent log file. This gives me the following when starting Stockfish 10, pasting a game, and then switching on analysis mode:

Code: Select all

# queue 'protover', searching=0
# command protover
# uci
>> Stockfish 10 64 by T. Romstad, M. Costalba, J. Kiiski, G. Linscott
>> id name Stockfish 10 64
>> id author T. Romstad, M. Costalba, J. Kiiski, G. Linscott
>> 
>> option name Debug Log File type string default 
>> option name Contempt type spin default 24 min -100 max 100
>> option name Analysis Contempt type combo default Both var Off var White var Black var Both
>> option name Threads type spin default 1 min 1 max 512
>> option name Hash type spin default 16 min 1 max 131072
>> option name Clear Hash type button
>> option name Ponder type check default false
>> option name MultiPV type spin default 1 min 1 max 500
>> option name Skill Level type spin default 20 min 0 max 20
>> option name Move Overhead type spin default 30 min 0 max 5000
>> option name Minimum Thinking Time type spin default 20 min 0 max 5000
>> option name Slow Mover type spin default 84 min 10 max 1000
>> option name nodestime type spin default 0 min 0 max 10000
>> option name UCI_Chess960 type check default false
>> option name UCI_AnalyseMode type check default false
>> option name SyzygyPath type string default <empty>
>> option name SyzygyProbeDepth type spin default 1 min 1 max 100
>> option name Syzygy50MoveRule type check default true
>> option name SyzygyProbeLimit type spin default 7 min 0 max 7
>> uciok
# queue 'memory', searching=0
# command memory
# queue 'egtpath', searching=0
# command egtpath
# setoption name syzygyPath value ..\dtz50
# queue 'cores', searching=0
# command cores
# setoption name Threads value 1
# queue 'new', searching=0
# command new
# setoption name Hash value 68
# isready
# queue 'level', searching=0
# queue 'option', searching=0
# queue 'option', searching=0
# queue 'ping', searching=0
>> info string Found 0 tablebases
>> readyok
# ucinewgame
# command level
# command option
# setoption name Ponder value true
# command option
# setoption name Ponder value false
# command ping
# queue 'memory', searching=0
# command memory
# queue 'egtpath', searching=0
# command egtpath
# setoption name syzygyPath value ..\dtz50
# queue 'cores', searching=0
# command cores
# setoption name Threads value 1
# queue 'new', searching=0
# command new
# isready
>> info string Found 0 tablebases
# queue 'level', searching=0
# queue 'option', searching=0
# queue 'option', searching=0
# queue 'ping', searching=0
# queue 'force', searching=0
>> info string Found 0 tablebases
# queue 'quit', searching=0
# queue 'quit', searching=0
...
# queue 'quit', searching=0
# queue 'quit', searching=0
# queue 'quit', # queue 'protover', searching=0
# command protover
# uci
>> Stockfish 10 64 by T. Romstad, M. Costalba, J. Kiiski, G. Linscott
# queue 'memory', searching=0
>> id name Stockfish 10 64
>> id author T. Romstad, M. Costalba, J. Kiiski, G. Linscott
>> 
>> option name Debug Log File type string default 
>> option name Contempt type spin default 24 min -100 max 100
>> option name Analysis Contempt type combo default Both var Off var White var Black var Both
>> option name Threads type spin default 1 min 1 max 512
>> option name Hash type spin default 16 min 1 max 131072
>> option name Clear Hash type button
>> option name Ponder type check default false
>> option name MultiPV type spin default 1 min 1 max 500
>> option name Skill Level type spin default 20 min 0 max 20
>> option name Move Overhead type spin default 30 min 0 max 5000
>> option name Minimum Thinking Time type spin default 20 min 0 max 5000
>> option name Slow Mover type spin default 84 min 10 max 1000
>> option name nodestime type spin default 0 min 0 max 10000
>> option name UCI_Chess960 type check default false
>> option name UCI_AnalyseMode type check default false
# queue 'egtpath', searching=0
>> option name SyzygyPath type string default <empty>
>> option name SyzygyProbeDepth type spin default 1 min 1 max 100
>> option name Syzygy50MoveRule type check default true
>> option name SyzygyProbeLimit type spin default 7 min 0 max 7
>> uciok
# command memory
# command egtpath
# setoption name syzygyPath value ..\dtz50
# queue 'cores', searching=0
# command cores
# setoption name Threads value 1
# queue 'new', searching=0
# command new
# setoption name Hash value 68
# isready
# queue 'level', searching=0
# queue 'option', searching=0
# queue 'option', searching=0
# queue 'ping', searching=0
# queue 'force', searching=0
# queue 'analyze', searching=0
>> info string Found 0 tablebases
>> readyok
# ucinewgame
# command level
# command option
# setoption name Ponder value true
# command option
# setoption name Ponder value false
# command ping
# command force
# command analyze
# setoption name UCI_AnalyseMode value true
# position startpos moves d2d4 g8f6 c2c4 g7g6 b1c3 f8g7
# go infinite
>> info string Found 0 tablebases
>> info depth 1 seldepth 1 multipv 1 score cp 253 nodes 33 nps 16500 tbhits 0 time 2 pv e2e4
>> info depth 2 seldepth 2 multipv 1 score cp 275 nodes 70 nps 35000 tbhits 0 time 2 pv e2e4 a7a6
>> info depth 3 seldepth 3 multipv 1 score cp 338 nodes 114 nps 57000 tbhits 0 time 2 pv e2e4 b7b6 e4e5
>> info depth 4 seldepth 4 multipv 1 score cp 136 nodes 503 nps 251500 tbhits 0 time 2 pv c1g5 d7d6 e2e4 c7c6
>> info depth 5 seldepth 5 multipv 1 score cp 166 nodes 825 nps 275000 tbhits 0 time 3 pv e2e4 d7d6 f1e2 b8c6
...
An unintended effect that is revealed by this is that UCI2WB starts queueing zillions of 'quit' commands when WinBoard closes the pipes, so that it sees an End-Of-File on its input. I had intentionally fake it a 'quit' command in that situation to be sure everything will be handled orderly when a GUI dies without sending 'quit', but I had not realized that it would then keep doing that. (I snipped most of it out of the log.) This should not hurt, however. The sequence is interrupted somewhere in the middle, when WinBoard kills the adapter, to start a new one. The log of that new one is just appended, and starts with the "# queue 'protover', ...". So the issue is, why didn't the session before that terminate by itself?

It seems there is indeed some strange Stockfish behavior to blame for this:
The first 'new' command triggers sending of an 'isready', and Stockfish replies to this with

>> info string Found 0 tablebases
>> readyok

(The >> was prefixed by UCI2WB in the log to indicate raw engine input.) The 'level', 2x 'option' (from 'hard', 'easy') and 'ping' that were queued while waiting for 'readyok' are then released and executed. But after some more commands are processed as they should, a new 'new' command comes in, and causes sending of another 'isready'.

This second 'isready' is never acknowledged with a 'readyok' by stockfish; instead it tells again how many tablebases it has loaded. (Not sure what triggers that in the first place. "setoption Threads, perhaps?). After some time it even tells that for a third time. But never a 'readyok' appears, and UCI2WB would wait for that until doomsday.

It seems to me this is a clear UCI violation by Stockfish 10.
Hmm, just trying to follow which is not that easy.

I see one 'isready' command which is answered by Stockfish with 'readyok'.
I don't see a second 'isready' command.

Reporting of how many tablebases found is either caused by setting the TB Path,
after which a 'isready' command is also recommended because this may take some while,
or after a 'ucinewgame' command, which will trigger a re-initialization of the TBs, too.
(This was added lately.)
Jörg Oster
User avatar
hgm
Posts: 27788
Joined: Fri Mar 10, 2006 10:06 am
Location: Amsterdam
Full name: H G Muller

Re: UCI2WB 4.0

Post by hgm »

Well, as you say, the problem is on Windows. In the initial design I used separate threads for listening to the GUI and the engine. But the problem was that the GUI thread is not always able to immediately relay (translated) commands to the engine, as in UCI it is for instance not allowed to set options while the engine is thinking, and you first have to stop it and wait for 'bestmove' even if you decide to stop it immediately. So there had to be some synchronization of the two threads, blocking the GUI thread while the engine thread was waiting for 'bestmove', 'readyok' or 'uciok'. But when the GUI thread is blocked it cannot notice arrival of commands that should be excuted instantly, such as 'quit'. Which caused problems with impatient GUIs that kill the adapter before it could quit the engine. On Windows such orphaned engine processes can then survive, even fully consuming CPU. (On Linux EOF or SIGPIPE usually kills them as soon as they attempt I/O, although even there improper handling of EOF can result in a 100% CPU-consuming loop.)

So the thread listening to the GUI must never be blocked for other reasons than waiting for GUI input, even if a command comes in that cannot be immediately relayed to the engine. I did not see any solution that would not need queueing of these commands internally, and the queued commands must be executed when the engine is ready for them, even if no new commands arrive from the GUI.

The design I use now basically does have the 'engine thread' handle everything in a select-like loop, because it can sort of predict whether the next 'event' will be engine input or processing of commands from the GUI: as long as an engine has not yet said 'bestmove', 'isready' or 'uciok' the engine is going to say something more (because arrival of GUI commands will make the other thread stop the search when needed, and the other two will always arrive spontaneously). After that it can simply peek the command queue; this is just a memory buffer, and if there is nothing in it, it would not block automatically, and can switch back to the engine for pondering. Or block voluntarily waiting for GUI commands when the engine is really idle.

This fails, however, with engines that behave non-compliantly. Such as when they fail to respond to 'isready'. But I suppose the current design doesn't make it impossible to also handle these situations though emergency measures (like killing the engine process if it fails to respond to 'quit' rapidly enough). It is just that I don't have those implemented yet.
User avatar
hgm
Posts: 27788
Joined: Fri Mar 10, 2006 10:06 am
Location: Amsterdam
Full name: H G Muller

Re: UCI2WB 4.0

Post by hgm »

Joerg Oster wrote: Sat Dec 22, 2018 1:10 pmI see one 'isready' command which is answered by Stockfish with 'readyok'.
I don't see a second 'isready' command.
I admit that the logging by UCI2WB is a bit messy, as both commands sent to the engine as remarks about the adapter's internal state appear prefixed by just the same '#' symbol. But the seconf 'isready' was sent just before Stockfish reports the number of tablebase for the second time:
# command new
# isready
>> info string Found 0 tablebases
# queue 'level', searching=0
# queue 'option', searching=0
# queue 'option', searching=0
# queue 'ping', searching=0
# queue 'force', searching=0
>> info string Found 0 tablebases
# queue 'quit', searching=0
Michel
Posts: 2272
Joined: Mon Sep 29, 2008 1:50 am

Re: UCI2WB 4.0

Post by Michel »

hgm wrote: Sat Dec 22, 2018 1:31 pm Well, as you say, the problem is on Windows. In the initial design I used separate threads for listening to the GUI and the engine. But the problem was that the GUI thread is not always able to immediately relay (translated) commands to the engine, as in UCI it is for instance not allowed to set options while the engine is thinking, and you first have to stop it and wait for 'bestmove' even if you decide to stop it immediately. So there had to be some synchronization of the two threads, blocking the GUI thread while the engine thread was waiting for 'bestmove', 'readyok' or 'uciok'. But when the GUI thread is blocked it cannot notice arrival of commands that should be excuted instantly, such as 'quit'. Which caused problems with impatient GUIs that kill the adapter before it could quit the engine.
Ok I understand. I think polyglot would have an issue there. But this seems like a really convoluted situation.

I.e. the GUI launches a search, then an option command and immediately after that a quit command and then it is so impatient that it kills the adapter after too short a timeout.
Ideas=science. Simplification=engineering.
Without ideas there is nothing to simplify.
Joerg Oster
Posts: 937
Joined: Fri Mar 10, 2006 4:29 pm
Location: Germany

Re: UCI2WB 4.0

Post by Joerg Oster »

hgm wrote: Sat Dec 22, 2018 1:35 pm
Joerg Oster wrote: Sat Dec 22, 2018 1:10 pmI see one 'isready' command which is answered by Stockfish with 'readyok'.
I don't see a second 'isready' command.
I admit that the logging by UCI2WB is a bit messy, as both commands sent to the engine as remarks about the adapter's internal state appear prefixed by just the same '#' symbol. But the seconf 'isready' was sent just before Stockfish reports the number of tablebase for the second time:
# command new
# isready
>> info string Found 0 tablebases
# queue 'level', searching=0
# queue 'option', searching=0
# queue 'option', searching=0
# queue 'ping', searching=0
# queue 'force', searching=0
>> info string Found 0 tablebases
# queue 'quit', searching=0

Well, all I can add is that after setting the TB Path, the GUI should also send a 'isready' and wait for the answer,
especially with 7-man TBs now available and being more and more in use.
I would also recommend to do this after changing several UCI options via 'setoption' because you never know in advance
how long the engine might need to execute all changes.
Sending 'isready' after a 'ucinewgame' command and waiting for the answer is mandatory, of course!

But I'm sure you know this, please take this just as a general recommendation.
Jörg Oster
Fulvio
Posts: 395
Joined: Fri Aug 12, 2016 8:43 pm

Re: UCI2WB 4.0

Post by Fulvio »

hgm wrote: Sat Dec 22, 2018 1:31 pm But the problem was that the GUI thread is not always able to immediately relay (translated) commands to the engine, as in UCI it is for instance not allowed to set options while the engine is thinking, and you first have to stop it and wait for 'bestmove' even if you decide to stop it immediately.
I don't think this is correct.
You can send the "stop" and the "setoption" immediately, without waiting for the bestmove.
The commands will be queued in the stdin of the engine, which will process them sequentially.

Let's say the user is analyzing a position and wants to change some options, maybe the number of threads.
It is my understanding that you need to wait only once, before restarting the search:

Code: Select all

stop
setoption ...
setoption ...
isready

*** wait for readyok ***

position ...
go ...
User avatar
hgm
Posts: 27788
Joined: Fri Mar 10, 2006 10:06 am
Location: Amsterdam
Full name: H G Muller

Re: UCI2WB 4.0

Post by hgm »

Michel wrote: Sat Dec 22, 2018 2:27 pmI.e. the GUI launches a search, then an option command and immediately after that a quit command and then it is so impatient that it kills the adapter after too short a timeout.
Well, I guess the problem is that, although the CECP specs explicitly allow you to make any command abort engine thinking, I consider this a very poor implementation. I only want arrival of 'force', 'quit' or '?' (= move now) to abort thinking, and delay execution of other commands until after the engine stops thinking on its own accord. There is the possibility that the user would try to alter the setting of an engine-defined option while the engine is thinking (WinBoard does not forbid this, because for some options it could make sense, like those which control the format or frequency of Thinking Output), which could mask a following 'quit' (e.g. because of an opponent resign) if you just have the GUI thread block waiting for the engine in order to execute the 'setoption'. Perhaps it is just paranoia on my part to worry about this.
Ras
Posts: 2487
Joined: Tue Aug 30, 2016 8:19 pm
Full name: Rasmus Althoff

Re: UCI2WB 4.0

Post by Ras »

Fulvio wrote: Sat Dec 22, 2018 4:03 pmYou can send the "stop" and the "setoption" immediately, without waiting for the bestmove.
The commands will be queued in the stdin of the engine, which will process them sequentially.
That will not be robust because it's implementation defined what then happens because the UCI protocol does not demand option settings to be buffered:
UCI: One string will be sent for each parameter and this will only be sent when the engine is waiting.
And then also:
UCI: if the engine receives a command which is not supposed to come, for example "stop" when the engine is not calculating, it should also just ignore it.
As a result, the engine is free to discard setoptions that arrive during search. Relying on setoption to be buffered will result in spotty UCI engine support of the adaptor, which is not desirable.
Rasmus Althoff
https://www.ct800.net
Fulvio
Posts: 395
Joined: Fri Aug 12, 2016 8:43 pm

Re: UCI2WB 4.0

Post by Fulvio »

Ras wrote: Sat Dec 22, 2018 8:55 pm That will not be robust because it's implementation defined what then happens because the UCI protocol does not demand option settings to be buffered:
The UCI protocol says that "all communication is done via standard input and output". UCI2WB use the standard c library and it is buffered (however the current UCI2WB code is not good because it doesn't check the result of fprintf).
Ras wrote: Sat Dec 22, 2018 8:55 pm
UCI: One string will be sent for each parameter and this will only be sent when the engine is waiting.
What "is waiting" means? If stockfish takes a long time to initialize the tablebase it is illegal to send other setoption commands because it is not waiting?
Ras wrote: Sat Dec 22, 2018 8:55 pm And then also:
UCI: if the engine receives a command which is not supposed to come, for example "stop" when the engine is not calculating, it should also just ignore it.
As a result, the engine is free to discard setoptions that arrive during search.
This is about the order of the commands and it is not relevant to the discussion.

After a stop command the engine should "stop calculating as soon as possible".
"as soon as possible" is not a very precise statement, however I think it is reasonable to expect that other commands will not be processed before interrupting the search.
Do you know any engine which will not handle the sequence of commands I posted?