Cute Chess on Windows: Monchester's connection stalls

[lithander]

A tournament of 500 games between Monchester and MinimalChess ended prematurely on a stalled connection. See logs & screenshot in the attached files.

log.txt
PGN.txt

The tournament used book moves and fast time controls of 10 seconds per game max.

[unserializable]

SUMMARY

First step is modify Monchester 1.0 branch to keep completely quiet at receiving ? since move should follow anyway within very short timeframe. The 2.0 will support ? anyway, the mechanisms to do that are being tested out with CECP analyze support.

That CC sent the ? is astonishing itself, as there was plenty of move time (time 1065 == 10.65 seconds). So maybe there was some crash indeed, for CC to even tickle Monchester that way -- but if there was, it did not leave any trace in the log. Log lines unfortunately are not timestamped, so it is not possible to tell how long CC waited for the move before sending ?. So there might be need for additional second step after this, if there turns out to be unseen crash. But first step first -- get rid of any CECP snippets that could be sent between ? and the engine move, to exclude the case that CC does not handle such snippets graciously.

DETAILS

The ? (move now) is optional in CECP and near insta-mover Monchester does not implement it in 1.0, because all the response needs to be is the move, that should come very soon anyway. There was some discussion about '?' and CuteChess in http://talkchess.com/forum3/viewtopic.php?f=2&t=75718&start=110#p873261 and the conclusion was that it is enough when engine sends move very soon.

BUT: Monchester 1.0 branch should be made aware of ? to remain completely silent when it receives '?', so that there will be no output between the ? and move sent, the 1.0 version sends 'Unrecognized command' together with CECP comment-escaped # board printout when ? is received:

# Monchester 1.0 ~(9508 kN/s)
command : xboard
# received xboard
protover 2
feature myname="Monchester 1.0" name=1 setboard=1 ping=1 edit=0 memory=0 usermove=0 analyze=0 colors=0 sigint=0 sigterm=0 done=1
?
Unrecognized command
#8:  R N B Q K B N R 
#7:  P P P P P P P P 
#6:  - - - - - - - - 
#5:  - - - - - - - - 
#4:  - - - - - - - - 
#3:  - - - - - - - - 
#2:  p p p p p p p p 
#1:  r n b q k b n r 
#-------------------
#    A B C D E F G H       rnbqkbnr/pppppppp/8/8/8/8/PPPPPPPP/RNBQKBNR w KQkq - 0 1

... and current 1.0-branch sends Error (unknown command): ? (which better complies with CECP, #10) + the same comment-escaped board printout:

# Monchester 1.0.1-14-g84db4ed ~(9274 kN/s)
command : xboard
# received xboard
protover 2
feature myname="Monchester 1.0.1-14-g84db4ed" name=1 setboard=1 ping=1 edit=0 memory=0 usermove=0 analyze=0 colors=0 sigint=0 sigterm=0 done=1
?
Error (unknown command): ?
#8:  R N B Q K B N R 
#7:  P P P P P P P P 
#6:  - - - - - - - - 
#5:  - - - - - - - - 
#4:  - - - - - - - - 
#3:  - - - - - - - - 
#2:  p p p p p p p p 
#1:  r n b q k b n r 
#-------------------
#    A B C D E F G H       rnbqkbnr/pppppppp/8/8/8/8/PPPPPPPP/RNBQKBNR w KQkq - 0 1

[unserializable]

Couple other noteworthy things from logs and .pgn:

1. c4 {book} Nc6 {book} 
2. Nc3 {book} Nf6 {+0.45/2 0s}
3. Nf3 {book} e5 {book}
4. e3 {book} Be7 {book}
5. a3 {book} e4 {-0.54/2 0s}
6. Ng1 {+1.00/5 0.25s} Bxa3 {+1.60/1 0s} 
7. bxa3 {+3.00/5 0.24s} Nd4 {-6.40/1 0s}
8. exd4 {+4.00/6 0.16s, Black's connection stalls} 1-0

1. The book moves are not applied all in order, on 2. move Monchester (B) can make one move choice and then moves continue from book until 5th move of black.
2. Black seems to act as its search depth has been decreased (like e.g. CECP sd would do), it searches at depth 2 on moves 2 and 5 and other its 6-7th move are at depth 1 (sic!), whereas fixed depth 4 is its usual hardcoded behaviour from which it normally deviates only when time issues are so bad that its very rudimentary time emergency mechanism kicks in.
3. From CECP time/otim and UCI wtime/btime in logs, Black is gaining a bit of time after each move, even though the timecontrol is 0:10 (inc 0) (set with >Monchester(0): level 0 0:10 0 quite at the beginning of the log),

...
>Monchester(0): level 0 0:10 0
...
>Monchester(0): time 1000
...
>Monchester(0): time 1000
...
>Monchester(0): time 1025
...
>Monchester(0): time 1049
...
>Monchester(0): time 1065

[unserializable]

Attempts to reproduce stall on Ubuntu 20.04.2 Linux so far have seen no success. Using time control 10s+0:

• 5000 games (no opening book) vs MCE 0.2.1 on XBoard 4.9.1 went flawlessly (both engines never lost games on time)
• 2000 games (no opening book) vs MCE 0.2.1 on CuteChess GUI 1.2.0 went well (Monchester did lose 82 games on time)
• 2724 games (Unbalanced Human Openings 2.0, 4-move opening book) vs MCE 0.2.1 on CuteChess GUI 1.2.0 went well (Monchester did lose 57 games on time)
• 1000 games (no opening book) vs MCE 0.2.1 on CuteChess CLI 1.2.0 went well (Monchester did lose 54 games on time)

@lithander Thanks for the detailed report, so far no success in reproducing this unfortunately. Maybe the way book moves were used can somehow prove to be a trigger. Could you give me hint on how to configure the book similar to your test setup? Namely, I am only aware of how to use .pgn books so that all book moves are sequentially forced, but in the sample you gave:

1. c4 {book} Nc6 {book} 
2. Nc3 {book} Nf6 {+0.45/2 0s}
3. Nf3 {book} e5 {book}
4. e3 {book} Be7 {book}
5. a3 {book} e4 {-0.54/2 0s}
6. Ng1 {+1.00/5 0.25s} Bxa3 {+1.60/1 0s} 
7. bxa3 {+3.00/5 0.24s} Nd4 {-6.40/1 0s}
8. exd4 {+4.00/6 0.16s, Black's connection stalls} 1-0

book moves are not all applied in forced sequence, on 2. move Monchester (B) can make one move choice and then moves continue from book until 5th move of black is again free to choose move after the book definitely ends.

[lithander]

When setting up a tournament I select a polyglot file in the "Opening book" section of the window. I leave the depth at "10 full moves". The opening book I usually use is the 'varried.bin' that was included in this software: http://scidvspc.sourceforge.net/