I understand now, it is the book move, cutechess-cli increments time from book moves, same with winboard 4.8.0.Cheney wrote: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.
Sample log from winboard 4.8.0
Sample log from cutechess-cli 0.8.2639 >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
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