Cutechess-cli Time Control: Me or Bug

[Ferdy]

I see the time 1100 in both my engine's logging plus int cutechess's debugging output. Here's a sample:

cutechess-cli -each tc=0/0:03+1 -engine cmd=engine1.exe dir=C:\chess\Engines\one proto=xboard -engine cmd=engine2.exe dir=C:\chess\Engines\two proto=xboard -rounds 500 -pgnout timetest.pgn -repeat -openings file=500-openings.pgn format=pgn order=sequential -debug

35 >XboardEngine(0): xboard
... extras omitted ...
227 >engine1(0): new
228 >engine1(0): level 0 0:03 1
230 >engine1(0): post
231 >engine1(0): easy
232 >engine1(0): force
235 >engine2(1): new
236 >engine2(1): level 0 0:03 1
237 >engine2(1): post
238 >engine2(1): easy
239 >engine2(1): force
284 >engine1(0): ping 10
285 <engine1(0): Error (post): unknown command
287 <engine1(0): pong 10
288 >engine1(0): time 1100
289 >engine1(0): otim 1100
290 >engine1(0): go

The level lines are correct but time should be 300.

If I increase the increment to 5, time is 4300.

When I remove the +1 in the tc and leave it as 0/0:03, then time is 300.

cutechess-cli 0.8.5
Using Qt version 5.7.0

WinBoard 4.6.2 works fine as does the CuteChess GUI.

I understand now, it is the book move, cutechess-cli increments time from book moves, same with winboard 4.8.0.

Sample log from winboard 4.8.0

639 >first : level 0 0:03 1
639 >first : post
639 >first : hard
639 >first : ping 1
Impossible move , type = 0
702 <first : pong 1
nps: w=-1, b=-1
nps: w=-1, b=-1
2373 >first : time 300
2373 >first : otim 400
book key = 830eb9b20758d1de
book move field = 3299
book hit = d7d5
2373 >first : force
2373 >first : d2d4
2373 >first : d7d5
silence
Interrupting first
3761 >first : time 400
3761 >first : otim 361
book key = 8a470482d88334ff
book move field = 3242
book hit = c7c6
3761 >first : c2c4
3761 >first : c7c6
silence
Interrupting first
5087 >first : time 500
5087 >first : otim 328
book key = b510abdf8b1c6fe0
book move field = 4013
book hit = g8f6
5087 >first : e2e3
5087 >first : g8f6
silence
Interrupting first
6382 >first : time 598
6382 >first : otim 300
book key = 15698788e404acaf
book move field = 3372
book hit = e7e6
6398 >first : b1c3
6398 >first : e7e6
silence
Interrupting first
7646 >first : time 695
7646 >first : otim 277
book key = d20707a4eef00099
book move field = 3112
book hit = a7a6
7646 >first : d1c2
7646 >first : a7a6
silence
Interrupting first
9128 >first : time 793
9128 >first : otim 230
book key = 55fd57f530503a36
book hit = (NULL)
9128 >first : f1d3
9128 >first : go
9159 <first : # times @ 13437286
9159 <first : # 16+16 pieces, centr = (1,1) R=40
9159 <first : 1 -11 0 3 d5c4
9175 <first : 1 0 0 3 a8a7
9175 <first : 1 14 0 3 b8d7
9175 <first : 2 1 0 83 b8d7 g1f3
9175 <first : 2 5 1 1195 b7b5 c4c5
9175 <first : 3 15 1 2709 b7b5 b2b3 b8d7
9175 <first : 4 3 4 8491 b7b5 c4d5 c6d5 g1f3
9221 <first : 4 11 9 29201 c6c5 g1f3 b8c6 c4d5
9284 <first : 5 10 15 54939 c6c5 c4d5 e6d5 g1f3 b8c6
9471 <first : 5 12 34 129270 b8d7 g1f3 b7b5 b2b3 f8d6
9877 <first : 5 16 74 301624 b7b5 c4d5 c6d5 g1f3 b8d7
9877 <first : # times @ 13438035: real=749 cpu=749
9877 <first : # promo = 0 (`) GT = 0
9877 <first : move b7b5

Sample log from cutechess-cli 0.8.2

Started game 1 of 100 (Fairy-Max 4.8V vs Quazar 0.4 x64)
1498 >Fairy-Max 4.8V(0): new
1498 >Fairy-Max 4.8V(0): level 0 0:03 1
1498 >Fairy-Max 4.8V(0): post
1498 >Fairy-Max 4.8V(0): easy
1498 >Fairy-Max 4.8V(0): force
1498 >Quazar 0.4 x64(1): ucinewgame
1498 >Quazar 0.4 x64(1): setoption name Ponder value false
1498 >Quazar 0.4 x64(1): position startpos
1499 >Fairy-Max 4.8V(0): f2f4
1499 >Quazar 0.4 x64(1): position startpos moves f2f4
1499 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5
1499 >Fairy-Max 4.8V(0): d7d5
1499 >Fairy-Max 4.8V(0): g1f3
1499 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3
1499 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6
1499 >Fairy-Max 4.8V(0): g8f6
1500 >Fairy-Max 4.8V(0): b2b3
1500 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3
1500 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6
1500 >Fairy-Max 4.8V(0): g7g6
1500 >Fairy-Max 4.8V(0): c1b2
1500 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2
1500 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7
1501 >Fairy-Max 4.8V(0): f8g7
1501 >Fairy-Max 4.8V(0): e2e3
1501 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7 e2e3
1501 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7 e2e3 e8g8
1501 >Fairy-Max 4.8V(0): e8g8
1501 >Fairy-Max 4.8V(0): f1e2
1501 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7 e2e3 e8g8 f1e2
1502 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7 e2e3 e8g8 f1e2 c7c5
1502 >Fairy-Max 4.8V(0): c7c5
1502 >Fairy-Max 4.8V(0): e1g1
1502 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7 e2e3 e8g8 f1e2 c7c5 e1g1
1502 >Quazar 0.4 x64(1): position startpos moves f2f4 d7d5 g1f3 g8f6 b2b3 g7g6 c1b2 f8g7 e2e3 e8g8 f1e2 c7c5 e1g1 b8c6
1503 >Fairy-Max 4.8V(0): b8c6
1503 >Fairy-Max 4.8V(0): ping 10
1556 <Fairy-Max 4.8V(0): pong 10
1556 >Fairy-Max 4.8V(0): time 1000
otim 1000
1556 >Fairy-Max 4.8V(0): go
1557 <Fairy-Max 4.8V(0): # times @ 13184642
1557 <Fairy-Max 4.8V(0): # 16+16 pieces, centr = (1,1) R=40
1557 <Fairy-Max 4.8V(0): 1 -32 0 3 b2f6
1557 <Fairy-Max 4.8V(0): 1 -1 0 3 b2c1
1557 <Fairy-Max 4.8V(0): 1 9 0 3 b2c3
1557 <Fairy-Max 4.8V(0): 1 15 0 3 b1c3
1557 <Fairy-Max 4.8V(0): 2 0 0 63 b1c3 c8f5
1560 <Fairy-Max 4.8V(0): 3 6 0 1443 b1c3 c8f5 a2a4
1565 <Fairy-Max 4.8V(0): 4 0 0 3605 b1c3 c8f5 a2a4 h7h5
1606 <Fairy-Max 4.8V(0): 4 4 4 20665 c2c4 c8e6 b1c3 f6e4
1656 <Fairy-Max 4.8V(0): 5 6 9 42534 c2c4 c8f5 b1c3 g7h6 a1c1
2688 <Fairy-Max 4.8V(0): 6 5 112 479641 c2c4 c8f5 b1c3 d5d4 e3d4 c6d4
2761 <Fairy-Max 4.8V(0): # times @ 13185844: real=1202 cpu=1201
2761 <Fairy-Max 4.8V(0): # promo = 0 (`) GT = 0
2761 <Fairy-Max 4.8V(0): move c2c4

[Cheney]

I figured it out

I have a PGN based opening which cutechess uses and sends each move to each engine before having the engine start playing (debugging will reveal a series of "usermove" commands).

Cutechess appears to be adding the increment to the clock after each move that is played from opening pgn.

When I remove the -openings pgn, the time is OK.

[Cheney]

Great news - I just posted a similar but not as detailed response

Thank you!

[Cheney]

Sorry to touch on this old thread, but I am wondering something as I start to perform engine vs engine matches again.

I want to have engines play fast games. I am not totally versed on the definitions of blitz versus rapid versus bullet, but the idea I thought was to play a game in 3 seconds with a 0.8 or 1 second increment. My level command sent to my xboard engine looks like level 0 0:03 1. I have tested other settings, like level 0 0:01 0.8.

The problem is the games take forever. 500 games can take over 12 to 16 hours with around 40 to 45 moves per game and an average of 2 seconds per move. What I know is when I have cutechess use a pgn styled opening book and, if it plays 10 moves from that book, the game time just incremented by 10 seconds for each engine, defeating the purpose of having a 3 second game. To set this in perspective, for the very first move, my engine will calculate to use almost 4 seconds and around move 40, the engine is around 2 seconds per move.

The engine's clock works fine as time increases or decreases, but I'm trying to find a way to not have the engines get that 10 seconds because of the opening.

I have tried the set time (st) command but there are other engines on-line that seem to not play well with this and crash. These other engines seem to work best with the level command.

I have not converted the pgn opening book into fen positions but believe that will work as it will be a starting position. I have used other books that are fen based, however, but they are not as versed as the Adam Hair openings and do not account for the moves that made it to the starting position.

Is there a setting that I am missing here? Maybe the game time should be 0:00.5 (which I have not tried)?

Thank you

[syzygy]

Lower the increment?

[hgm]

Play from positions rather than opening lines?

[Cheney]

Lower the increment?

I have done that, it does decrease the time a bit. 0.8 increment increases the game (with 10 moves) to 8 additional seconds. Maybe go less than that? Like 0.3? Hmmm, that I'll try , for some reason, I always wanted to avoid going that low, maybe I did not want to expose a bug?

Play from positions rather than opening lines?

I have done that and it does indeed answer the riddle to the extra time, but it does eliminate playing out the lines, keeping that move history, and I just do not have opening books of +30k positions yet; I have been used to using the Adam Hair opening books. Also, I see no gain at this time with avoiding the starting positions versus keeping all the opening moves as I do nothing special in the engine.

I was hoping there was a setting in cutechess that would not increment the clock until all opening moves are played out.

I'm going to just go with both your ideas, test lowing the increment when using the pgn plus convert all these opening books I have to a starting position. Thank you

[Ferdy]

New version of cutechess no longer increments time on book moves.

Download Cutechess:
http://talkchess.com/forum/viewtopic.ph ... 52&t=64669

[hgm]

That seems a bug.

[Ferdy]

That seems a bug.

Care to elaborate why it seems a bug?