Bad communication between xboard (polyglot?) and engines

[velocidrom]

I've noticed a few times (and even reported it here), with Stockfish (UCI engine) and now Sunsetter (winboard engine) that when they play with a book and they have to make their first move out of the book, they don't know they have to move. And so they lose on time. I could not reproduce the bug at will, it seems rare but still quite bothering.

I have a log file of the communication between Sunsetter and xboard and it seems that Sunsetter never got the move played by its opponent from xboard.
Here's the communication:

Code: Select all

< new
< random
< post
< hard
< variant crazyhouse
> tellics kibitz Hello from Sunsetter 7g
< level 0 1 0
< name excellion
< rating 2462 1930
< black
< time 6000
< otim 6000
< white
< go
< holding [] []
> move e2e4
> 5 0 0 82 pondering e7e5(hashfill % 0.00)
> 6 0 0 104 pondering e7e5(hashfill % 0.00)
> 7 28 0 724 pondering d7d5(hashfill % 0.01)
> 8 3 0 3503 pondering e7e5(hashfill % 0.06)
> 9 20 1 13758 pondering e7e5(hashfill % 0.25)
> 10 23 8 57026 pondering e7e5(hashfill % 1.04)
< holding [] []
> 11 20 38 275814 pondering e7e6(hashfill % 5.09)
> 12 20 153 1112124 pondering e7e5(hashfill %19.16)
< time 6000
< otim 6000
< b8c6
< holding [] []
>
>  11      25      0       0  d2d4 <already searched>
> 12 35 24 151587 d2d4 e7e6 d4d5 c6e5 c1f4 d7d6 f1b5 c8d7 b1c3  ..
>

> tellics whisper :-| 13: d2d4 e7e6 d4d5 c6e5 c1f4 d7d6 f1b5 c8d7 b1c3  ..(M: +0 D: +15 C: +20 KW: +0 KB: +0 )
>
> Found move: d2d4 +35 fply: 12  searches: 480351 quiesces: 70620
            T-hits: 109271 T-full: 16 (percent)
> Time      : Time Alloc: 750 Clock Ticks Used (in Thousands): 761
>

> move d2d4
> 5 28 0 93 pondering e7e5(hashfill % 0.00)
> 6 28 0 120 pondering e7e5(hashfill % 0.00)
> 7 33 0 867 pondering e7e6(hashfill % 0.01)
> 8 33 0 3637 pondering e7e6(hashfill % 0.04)
> 9 33 2 12603 pondering e7e6(hashfill % 0.17)
> 10 33 12 76458 pondering e7e6(hashfill % 1.30)
> 11 33 49 324263 pondering e7e6(hashfill % 5.68)
> 12 33 222 1525650 pondering e7e6(hashfill %24.82)
> 13 33 902 6265136 pondering e7e6(hashfill %69.75)
> 14 19 5255 39161223 pondering d7d5(hashfill %98.29)
< holding [] []
< hard
< result 0-1 {Sunsetter forfeits on time}
< force

< sign indicates a message from xboard to Sunsetter and > sign indicates a message from Sunsetter to xboard.
The game was played on FICS. The game was 1.e4 Nc6 0-1, white (Sunsetter) lost on time. The book was 1 move deep (1.e4 only). And it seems like Sunsetter never got informed that black had played Nc6.
A similar/same bug happens with Stockfish with a much deeper book, sometimes.

[H.G.Muller]

I don't get it. I do see b8c6 in the log you posted, and even a reply d2d4 to it. So it seems to me the engine was already out of book, and playing. That makes it unlikely the book has anything to do with it.

I cannot see the communication between XBoard and the ICS in these logs, so it is hard to guess what might have gone wrong.

[velocidrom]

I don't get it. I do see b8c6 in the log you posted, and even a reply d2d4 to it. So it seems to me the engine was already out of book, and playing. That makes it unlikely the book has anything to do with it.

I cannot see the communication between XBoard and the ICS in these logs, so it is hard to guess what might have gone wrong.

Sorry I did not see it.
Then it looks like xboard never got informed about d2d4 despite that Sunsetter "sent" this information to xboard.
The game can be found in fics archives: http://ficsgames.org/cgi-bin/show.cgi?ID=357668222 and white never played d2d4.

[H.G.Muller]

Indeed, strange. But without a winboard.debug file it will not be possible to figure out what went wrong.

[velocidrom]

Indeed, strange. But without a winboard.debug file it will not be possible to figure out what went wrong.

I see, thank you HGM.
Since I know this bug will occur again, I would like to enable winboard.debug. I would appreciate if you pointed me out how to do it. I do not find it in the Options...

[H.G.Muller]

xboard -debug

will do it.