CuteChessGUI v1.1.0: 'cancellation stall' abort.

Discussion of anything and everything relating to chess playing software and machines.

Moderators: hgm, Dann Corbit, Harvey Williamson

Forum rules
This textbox is used to restore diagrams posted with the [d] tag before the upgrade.
brinan
Posts: 87
Joined: Fri Apr 23, 2010 3:34 pm
Location: London
Full name: bri nan
Contact:

Re: CuteChessGUI v1.1.0: 'cancellation stall' abort.

Post by brinan » Sun Feb 09, 2020 6:13 pm

Did not have any game aborts during this weekend's 14-game match stream.
The only change was unchecking Thinking on opponent's time (Ponder) box in Cute Chess GUI 1.1.0.

My own situation is now clarified. However, would like to help in resolving issue.

1. Any idea on the cause should be capable of explaining why problem arises only with long time controls.
Have run thousands of 10s+1s gauntlets untroubled, with pondering enabled and using Cute Chess GUI.
Current matches have a time control of 40m + 12s / move. There have been 3 trial runs and, now, 3 matches. Trouble-free only when turned off pondering in last match.

2. It might not be a bug in lc0's coding. Perhaps it's just a need for GUI to allow for an eccentricity in the implementation of the UCI protocol.

3. Read lc0 ponder stop issue again. Decided to compare my log output from Stockfish with same-situation output from lc0. Didn't see that lc0 omitted any responses, although it is more verbose.

Code: Select all

Stockfish 11
------------
GO PONDER:
<< bestmove g8f6 ponder c1g5
>> position startpos moves e2e4 e7e6 d2d4 d7d5 b1c3 g8f6 c1g5
>> isready
<< readyok
>> go ponder wtime 2380958 btime 2187085 winc 12000 binc 12000
<< info depth 1 seldepth 1 multipv 1 score cp -13 nodes 205 nps 102500 tbhits 0 time 2 pv d5e4

STOP:
<< info depth 23 seldepth 39 multipv 1 score cp -20 nodes 4220857 […]
>> stop
<< info depth 41 seldepth 5 multipv 1 score cp 0 nodes 430693475 […]
<< bestmove f8e7 ponder e4e5
>> position startpos moves e2e4 e7e6 d2d4 d7d5 b1c3 g8f6 e4e5
>> isready
<< readyok
>> go wtime 2391685 btime 2187085 winc 12000 binc 12000
<< info depth 1 seldepth 1 multipv 1 score cp 0 nodes 221 […]
-------------------------------------------------------------

lc0
---
GO PONDER:
0209 16:05:05.147405 9732 c:\projects\lc0\src\chess\uciloop.cc:219] << bestmove b1c3 ponder g8f6
0209 16:05:05.147428 9732 c:\projects\lc0\src\mcts\search.cc:624] End a watchdog thread.
0209 16:05:05.147932 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> position startpos moves e2e4 […]
0209 16:05:05.148004 8580 c:\projects\lc0\src\mcts\search.cc:646] Aborting search, if it is still active.
0209 16:05:05.702115 8580 c:\projects\lc0\src\mcts\search.cc:660] Search destroyed.
0209 16:05:05.702195 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> isready
0209 16:05:05.702234 8580 c:\projects\lc0\src\chess\uciloop.cc:219] << readyok
0209 16:05:05.702429 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> go ponder wtime 2380958 btime […]
0209 16:05:05.702527 8580 c:\projects\lc0\src\engine.cc:259] Timer started at 0209 16:05:05.702232
0209 16:05:05.702744 6816 c:\projects\lc0\src\mcts\search.cc:593] Start a watchdog thread.
0209 16:05:05.702914 4604 c:\projects\lc0\src\mcts\search.h:195] Started search thread.
0209 16:05:05.703077 8580 c:\projects\lc0\src\mcts\search.cc:560] Search started. 0ms already passed.
0209 16:05:05.703066 8264 c:\projects\lc0\src\mcts\search.h:195] Started search thread.
0209 16:05:05.808868 6816 c:\projects\lc0\src\chess\uciloop.cc:219] << info depth 20 seldepth 55 […]

STOP:
0209 16:25:52.933474 8864 c:\projects\lc0\src\chess\uciloop.cc:219] << info depth 30 seldepth 60 […]
0209 16:25:57.802444 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> stop
0209 16:25:57.802510 8580 c:\projects\lc0\src\mcts\search.cc:636] Stopping search due to `stop` uci command.
0209 16:25:57.802888 8864 c:\projects\lc0\src\chess\uciloop.cc:219] << info depth 30 seldepth 60 […]
0209 16:25:57.803551 8864 c:\projects\lc0\src\chess\uciloop.cc:219] << info string e7h4  (327 ) N: 1370245 […]
0209 16:25:57.803640 8864 c:\projects\lc0\src\mcts\search.cc:296] --- Opponent moves after: e7h4
0209 16:25:57.803836 8864 c:\projects\lc0\src\mcts\search.cc:301] e1e2  (106 ) N:    6582 […]
[…]
0209 16:25:57.804165 8864 c:\projects\lc0\src\chess\uciloop.cc:219] << bestmove e7h4 ponder d2f2
0209 16:25:57.804207 8864 c:\projects\lc0\src\mcts\search.cc:624] End a watchdog thread.
0209 16:25:57.804295 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> position startpos moves e2e4 […]
0209 16:25:57.804390 8580 c:\projects\lc0\src\mcts\search.cc:646] Aborting search, if it is still active.
0209 16:25:58.319534 8580 c:\projects\lc0\src\mcts\search.cc:660] Search destroyed.
0209 16:25:58.319626 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> isready
0209 16:25:58.319668 8580 c:\projects\lc0\src\chess\uciloop.cc:219] << readyok
0209 16:25:58.319927 8580 c:\projects\lc0\src\chess\uciloop.cc:132] >> go wtime 2170501 btime […]
0209 […]320011 8580 […]\mcts\stoppers\factory.cc:281] Budgeted time for the move: 60233.6ms(+397649ms to squander). Remaining time 2170501ms(-200ms overhead)
0209 16:25:58.320051 8580 c:\projects\lc0\src\engine.cc:259] Timer started at 0209 16:25:58.319666
0209 16:25:58.320328 1716 c:\projects\lc0\src\mcts\search.cc:593] Start a watchdog thread.
0209 16:25:58.320477 784 c:\projects\lc0\src\mcts\search.h:195] Started search thread.
0209 16:25:58.320645 8580 c:\projects\lc0\src\mcts\search.cc:560] Search started. 0ms already passed.
0209 16:25:58.320635 3104 c:\projects\lc0\src\mcts\search.h:195] Started search thread.
0209 16:25:58.433411 1716 c:\projects\lc0\src\chess\uciloop.cc:219] << info depth 23 seldepth 27 […]
Click on www button for all event details and games.
News can be received automatically by subscribing to my RSS feed (click on icon near top).

Modern Times
Posts: 2765
Joined: Thu Jun 07, 2012 9:02 pm

Re: CuteChessGUI v1.1.0: 'cancellation stall' abort.

Post by Modern Times » Sun Feb 09, 2020 6:38 pm

brinan wrote:
Sun Feb 09, 2020 6:13 pm

2. It might not be a bug in lc0's coding. Perhaps it's just a need for GUI to allow for an eccentricity in the implementation of the UCI protocol.
From memory the cutechess developers were very clear that they would not do that. The engine strictly follows protocol, or it doesn't run.
.

Opinions expressed here are my own, and not necessarily those of the CCRL Group.

User avatar
hgm
Posts: 26111
Joined: Fri Mar 10, 2006 9:06 am
Location: Amsterdam
Full name: H G Muller
Contact:

Re: CuteChessGUI v1.1.0: 'cancellation stall' abort.

Post by hgm » Sun Feb 09, 2020 7:12 pm

And that is as it should be!

brinan
Posts: 87
Joined: Fri Apr 23, 2010 3:34 pm
Location: London
Full name: bri nan
Contact:

Re: CuteChessGUI v1.1.0: '…connection stalls' abort.

Post by brinan » Sun Feb 09, 2020 8:08 pm

In terms of what to do about the issue, have no problem with last two views.

By the way, don't know where cancellation stall came from :oops:
Cute Chess GUI's error message in the pgn file is: White's (or Black's) connection stalls.
Click on www button for all event details and games.
News can be received automatically by subscribing to my RSS feed (click on icon near top).

Modern Times
Posts: 2765
Joined: Thu Jun 07, 2012 9:02 pm

Re: CuteChessGUI v1.1.0: '…connection stalls' abort.

Post by Modern Times » Sun Feb 09, 2020 8:25 pm

brinan wrote:
Sun Feb 09, 2020 8:08 pm

By the way, don't know where cancellation stall came from :oops:
Cute Chess GUI's error message in the pgn file is: White's (or Black's) connection stalls.
CCRL testers who use cutechess (with ponder off) have had this as well occasionally, depending on the engine. Including A/B engines.

I had it myself with the Zeta engine running on GPU.
.

Opinions expressed here are my own, and not necessarily those of the CCRL Group.

crem
Posts: 169
Joined: Wed May 23, 2018 7:29 pm

Re: CuteChessGUI v1.1.0: 'cancellation stall' abort.

Post by crem » Sun Feb 09, 2020 11:30 pm

I don't see anything wrong in Lc0 logs. The engine receives ucinewgame, and doesn't respond to it because it must not. After that (from Lc0 point of view) nothing happens and the engine is killed. It's suspicious though that it always happens 15 seconds after previous response of Lc0, which may be that that response somehow doesn't reach the GUI.

Could you also post CuteChess logs with more context? It would be interesting how the same situation is seen from the other side.

brinan
Posts: 87
Joined: Fri Apr 23, 2010 3:34 pm
Location: London
Full name: bri nan
Contact:

Re: CuteChessGUI v1.1.0: '...connection stalls' abort.

Post by brinan » Mon Feb 10, 2020 12:07 pm

crem
It's suspicious though that it always happens 15 seconds after previous response of Lc0, which may be that that response somehow doesn't reach the GUI.

Note, the wait between games in my more recent matches is 15 seconds.


Could you also post CuteChess logs with more context? It would be interesting how the same situation is seen from the other side.

Caught only one aborted game from Cute Chess. Note Stockfish is White for aborted game. Error message in pgn file refers to Black.
The GUI has a window for log entries. Window cleared every game. Can save window output to file. Has to be done manually.

Code: Select all

ABORTED GAME 14 (MATCH 2)
=========================

From Cute Chess GUI game logs
-----------------------------

End of previous game 13:
>lc0.net.62164(3): isready
>Stockfish 11(1): isready
<Stockfish 11(1): readyok
<lc0.net.62164(3): readyok

Log for aborted game 14:
>Stockfish 11(1): ucinewgame
>Stockfish 11(1): setoption name Ponder value true
<Stockfish 11(1): info string Found 510 tablebases
>Stockfish 11(1): isready
<Stockfish 11(1): readyok
>Stockfish 11(1): quit
Let me know if there is anything else I can do.
Click on www button for all event details and games.
News can be received automatically by subscribing to my RSS feed (click on icon near top).

crem
Posts: 169
Joined: Wed May 23, 2018 7:29 pm

Re: CuteChessGUI v1.1.0: '...connection stalls' abort.

Post by crem » Mon Feb 10, 2020 12:32 pm

brinan wrote:
Mon Feb 10, 2020 12:07 pm
crem
It's suspicious though that it always happens 15 seconds after previous response of Lc0, which may be that that response somehow doesn't reach the GUI.

Note, the wait between games in my more recent matches is 15 seconds.


Could you also post CuteChess logs with more context? It would be interesting how the same situation is seen from the other side.

Caught only one aborted game from Cute Chess. Note Stockfish is White for aborted game. Error message in pgn file refers to Black.
The GUI has a window for log entries. Window cleared every game. Can save window output to file. Has to be done manually.

Code: Select all

ABORTED GAME 14 (MATCH 2)
=========================

From Cute Chess GUI game logs
-----------------------------

End of previous game 13:
>lc0.net.62164(3): isready
>Stockfish 11(1): isready
<Stockfish 11(1): readyok
<lc0.net.62164(3): readyok

Log for aborted game 14:
>Stockfish 11(1): ucinewgame
>Stockfish 11(1): setoption name Ponder value true
<Stockfish 11(1): info string Found 510 tablebases
>Stockfish 11(1): isready
<Stockfish 11(1): readyok
>Stockfish 11(1): quit
Let me know if there is anything else I can do.
So, cutechess doesn't send anything to lc0 for game 14?

brinan
Posts: 87
Joined: Fri Apr 23, 2010 3:34 pm
Location: London
Full name: bri nan
Contact:

Re: CuteChessGUI v1.1.0: '...connection stalls' abort.

Post by brinan » Mon Feb 10, 2020 4:10 pm

crem
So, cutechess doesn't send anything to lc0 for game 14?


No.

Debug window does not clear till new game starts. Game 14 was the last game.
Did not edit a thing.
Click on www button for all event details and games.
News can be received automatically by subscribing to my RSS feed (click on icon near top).

Post Reply