Missing input in ponder

[Fabio Gobbato]

I've tried my engine with cutechess-cli and ponder on and I've found a bug.
These are the commands sent by cutechess:

Code: Select all

111907 >Pedone(0): go ponder wtime 9675 btime 9833 winc 1000 binc 1000
111907 <stockfish(1): info depth 26 seldepth 30 multipv 1 score cp 0 nodes 1177874 nps 1280297 tbhits 0 time 920 pv a4h4 e3f2 h4h5 b5b6 h5g5 e2a6 b7a6 a1a6 f7b7 e1e8 g5e5 e8c8 e5e7 c8c1 g6g5 f2g3 e7e8 g3f2 e8f8 f2g3
111907 <stockfish(1): bestmove a4h4 ponder e3f2
111907 >Pedone(0): stop

When cutechess send "go ponder" and immediately after "stop" within a millisecond the engine from the its own log file receive only "go ponder" and seems that it doesn't receive "stop" so the engine keep searching when instead should stop.
How can such thing happen?

Inside the search I check if there is an input with this function:

Code: Select all

static inline int InputAvailable(void)
{
#ifdef _WIN32
   if (Ric.Pipe)
   {
      DWORD bytes_left;
      PeekNamedPipe(Ric.Handle, 0, 0, 0, &bytes_left, 0);
      return bytes_left;
   }
   else return _kbhit();
#else
   fd_set readfds;
   struct timeval timeout;
   FD_ZERO(&readfds);
   FD_SET(STDIN_FILENO, &readfds);
   timeout.tv_sec = timeout.tv_usec = 0;
   select(STDIN_FILENO + 1, &readfds, 0, 0, &timeout);
   return FD_ISSET(STDIN_FILENO, &readfds);
#endif
}

and then I read it with an fgets.

It seems that inside the search this function doesn't detect the "stop" sent immediately after "go ponder" but I can't understand why. It happens under linux and under windows.

[BeyondCritics]

You have a bug that seems to break some basic abstractions, so it smells like UB.
Do you have several threads? If so, try to use only a single thread and see if the bug still happens.

[Ferdy]

I've tried my engine with cutechess-cli and ponder on and I've found a bug.
These are the commands sent by cutechess:

Code: Select all

111907 >Pedone(0): go ponder wtime 9675 btime 9833 winc 1000 binc 1000
111907 <stockfish(1): info depth 26 seldepth 30 multipv 1 score cp 0 nodes 1177874 nps 1280297 tbhits 0 time 920 pv a4h4 e3f2 h4h5 b5b6 h5g5 e2a6 b7a6 a1a6 f7b7 e1e8 g5e5 e8c8 e5e7 c8c1 g6g5 f2g3 e7e8 g3f2 e8f8 f2g3
111907 <stockfish(1): bestmove a4h4 ponder e3f2
111907 >Pedone(0): stop

When cutechess send "go ponder" and immediately after "stop" within a millisecond the engine from the its own log file receive only "go ponder"

Looks like you need to examine what the input parser is doing. It is clear that the input is "go ponder wtime 9675 btime 9833 winc 1000 binc 1000" Why it only saw "go ponder"?

[Fabio Gobbato]

You have a bug that seems to break some basic abstractions, so it smells like UB.
Do you have several threads? If so, try to use only a single thread and see if the bug still happens.

I have tried with only 1 thread.
I have used the sanitizers to check the engine but there aren't errors.

[Ras]

Looks like you need to examine what the input parser is doing.

That's also where I'd look first. Maybe the "stop" gets already consumed in the input parser where it would just be ignored so that by the time the input scanner in search gets around to checking the pipe, the "stop" is already gone.

It is clear that the input is "go ponder wtime 9675 btime 9833 winc 1000 binc 1000" Why it only saw "go ponder"?

I'd guess it did see the full command, and Fabio just abbreviated it in the posting.

[Fabio Gobbato]

Looks like you need to examine what the input parser is doing. It is clear that the input is "go ponder wtime 9675 btime 9833 winc 1000 binc 1000" Why it only saw "go ponder"?

Sure the engine reads "go ponder wtime 9675 btime 9833 winc 1000 binc 1000" but it gives no more input after that. In the log of the engine there is no "stop" command so the engine stays in ponder while it should exit.

[BeyondCritics]

First i would take a break. The idea is, that you are overworked and maybe have a blind spot.
At the next day you could write a script that reproduces the bug as simple as possible. You could also use the reverse debugging capabilities of gdb.
Then set a breakpoint at the method, which parses the stop and take it from there.

[hgm]

That you use PeekNamedPipe suggest that you do not use a separate input thread, which is just hanging in a read call, blocked while waiting for input to arrive. But instead have the search thread poll for arrival of input, and only read it when there is something to read. This can give problems with input buffering. When you use, say, fgetc() on a stream to read from the pipe, the underlying software mightread all characters waiting in the pipe, and put them in a buffer. Your parsing code then processes the first line of it, checks the pipe to see if there is more, and doesn't se any because there is nothing in the pipe. But there can be something (like 'stop' in this case) in the stream buffer.

I am not aware of any methods to probe how much is buffered. Perhaps you can switch off buffering of the stream.

I had the same problem in my WB engine; there if a move arrives during during pondering he GUI sends time, otim and usermove commands all at once, and in CECP these are on separate lines. So my normal input parser would process the 'time' command, and then remain unaware of the arrival of the 'otime' and 'usermove' command, which got buffered. Which would then make it hang, pondering forever, while the GUI would wait for it to move. I solved it by unconditianally reading a next line after 'time' and 'otim'. But there is so such solution in the current case, where multiple commands come at once in an unpredictable way.

[Fabio Gobbato]

In the end I have solved using 2 threads, one for the input and one for the search. In this way it works. Thank you everybody!

[hgm]

On more thinking I realized that this problem could also have been solved by actually using the number of waiting input characters that PeekNamedPipe() reports. You could put that in a variable 'buffered', which you ecrement each time you read a character from the input. As long as it is non-zero, you can safely read without blocking. If it does hit zero, you have to call a new PeekNamedPipe(), to update it. If the update leaves it at zero, you know there is no input.