Engines playing Musketeer Chess, good price

Discussion of chess software programming and technical issues.

Moderators: bob, hgm, Harvey Williamson

Forum rules
This textbox is used to restore diagrams posted with the [d] tag before the upgrade.
Ferdy
Posts: 4271
Joined: Sun Aug 10, 2008 1:15 pm
Location: Philippines

Re: Engines playing Musketeer Chess, good price

Post by Ferdy » Thu Jul 02, 2020 10:09 am

It seems like the rule to not gate when king is in check and the king cannot capture the attacker is not yet implemented in winboard and KingSlayer-Aramis 0.8.

Image

***h***f/r1bqkbnr/1ppp1ppp/p1n5/4p3/4PPP1/3P4/PPP4P/RNBQKBNR/**H*F*** b KQkq f3 0 4

When I played d8h4h, attacking black's king, it played:
30688 <first : move e1d2f
(Should have been e1d2 only.)

Winboard accepted it and sent this to me.
177917 >first : usermove 177917 >first : e1d2f

Resulting in this position.

Image

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

Re: Engines playing Musketeer Chess, good price

Post by hgm » Thu Jul 02, 2020 11:04 am

That is corrrect. I don't think it would ever allow this situation to occur in a game, so implementing it would bring zero Elo.

Ferdy
Posts: 4271
Joined: Sun Aug 10, 2008 1:15 pm
Location: Philippines

Re: Engines playing Musketeer Chess, good price

Post by Ferdy » Thu Jul 02, 2020 4:27 pm

Been experiencing some time forfeits in Winboard 4.9.20200531. This is at TC 30s+100ms. In the example below, white still has 16cs or 160ms. It thinks around 16ms and got forfeited.

One thing I notice here is that the silence consumes time, around 86747-86591 or 156. Is this really charged to the engine thinking time?

I did the test between Deuterium and Crafty. Tried it in cutechess on same TC and no time forfeit. In winboard, both have loses on time.

86591 >first : time 16
86591 >first : otim 23
book hit = (NULL)
86591 >first : usermove 86591 >first : f5h3
silence
86747 <first : # command e
86747 <first : # start search
86747 <first : # position startpos moves e2e4 e7e5 g1f3 ...
86747 <first : # go btime 230 wtime 160
86747 <first : # engine said: info depth 1 seldepth 2 multipv 1 score cp -255 time 1 nodes 19 nps 19000 pv b6d4
86747 <first : 1 -255 0 19 b6d4
86747 <first : # engine said: info depth 1 seldepth 2 multipv 2 score cp -262 time 1 nodes 34 nps 34000 pv b6c5
86747 <first : 1 -262 0 34 b6c5
86747 <first : # engine said: info depth 2 seldepth 4 multipv 1 score cp -271 time 1 nodes 72 nps 72000 pv b6d4 h3g4
86747 <first : 2 -271 0 72 b6d4 h3g4
86747 <first : # engine said: info depth 3 seldepth 4 multipv 1 score cp -254 time 1 nodes 201 nps 201000 pv b6e3 h3c8 e3b6
86747 <first : 3 -254 0 201 b6e3 h3c8 e3b6
86747 <first : # engine said: info depth 4 seldepth 5 multipv 1 score cp -267 time 1 nodes 368 nps 368000 pv b6d4 h3g4 d4c5 g4f3
86747 <first : 4 -267 0 368 b6d4 h3g4 d4c5 g4f3
86747 <first : # engine said: info depth 5 seldepth 8 multipv 1 score cp -273 time 1 nodes 1024 nps 1024000 pv b6d4 h3g4 d4c5 g4f3 c5b4
86747 <first : 5 -273 0 1024 b6d4 h3g4 d4c5 g4f3 c5b4
86747 <first : # engine said: info depth 6 seldepth 8 multipv 1 score cp -266 time 1 nodes 1706 nps 1706000 pv b6c5 h3g4 c5b6 g4f3 b6c5 e4d5 c5e3
86747 <first : 6 -266 0 1706 b6c5 h3g4 c5b6 g4f3 b6c5 e4d5 c5e3
86763 <first : # engine said: info depth 7 seldepth 8 multipv 1 score cp -266 time 1 nodes 2148 nps 2148000 pv b6c5 h3g4 c5b6 g4f3 b6c5 e4d5 c5e3
86763 <first : 7 -266 0 2148 b6c5 h3g4 c5b6 g4f3 b6c5 e4d5 c5e3
86763 <first : # engine said: info depth 8 seldepth 10 multipv 1 score cp -267 time 1 nodes 3718 nps 3718000 pv b6f2 h3g4 f2c5 e4d5 c5b6 g4h3 d2e3 h3d7 e3d2
86763 <first : 8 -267 0 3718 b6f2 h3g4 f2c5 e4d5 c5b6 g4h3 d2e3 h3d7 e3d2
86763 <first : # engine said: info depth 9 seldepth 10 multipv 1 score cp -270 time 16 nodes 4717 nps 294812 pv b6f2 h3g4 f2c5 e4d5 c5b6 g4f3 d2e3 f3e4 e3d2
86763 <first : 9 -270 1 4717 b6f2 h3g4 f2c5 e4d5 c5b6 g4f3 d2e3 f3e4 e3d2
86763 <first : # engine said: info time 16 nodes 4717
86763 <first : # engine said: bestmove b6f2
86763 <first : move b6f2
GameEnds(28, Black wins on time, 4)

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

Re: Engines playing Musketeer Chess, good price

Post by hgm » Thu Jul 02, 2020 5:12 pm

The 'silence' should not consume any time, other than needed to flush the message to the debug file. It means that the routine MyPlaySound() for playing the move sound was called with a null argument, which would make it return immediately. It would also not matter if it did, because the move at that point has already been sent to the engine (to UCI2WB in this case). So the engine is already thinking, and will measure the time it will take from the point when it received that.

From the POV of WinBoard the engine is forfeiting: it is told it has still 160ms at t=86591, so its flag will fall at t=86751, and the move is only received at t=56763, i.e. 12ms too late. If the engine'log says differently, the cause must have been communication lag. I once measured the lag caused by UCI2WB, and it was only 1.5ms roundtrip (on a slow laptop). So I don't know how the lag can be so large. WinBoard by default runs the engines at a lower priority (option -niceEngines), and in recent versions it exempts known adapters from this when they are installed with a a command line (in -adapterCommand) that passes the -niceEngines option to them. Assuming this means the adapter will nice down the engine when it launches it, but can keep running at high priority itself. It could be that this scheme somehow backfires, because other stuff running on your PC occasionally competes for CPU at normal priority, and then pushes the engine out of business.

Ferdy
Posts: 4271
Joined: Sun Aug 10, 2008 1:15 pm
Location: Philippines

Re: Engines playing Musketeer Chess, good price

Post by Ferdy » Fri Jul 03, 2020 12:56 am

I run that test in winboard tourney manager with concurrency of 4. I have 4 cores/8 threads, hyperthreading is ON. I am sure there are enough cpu resources as I have not run other programs not even browsing, also I look at the task manager occasionally and cpu utilization is only around 50% to 60%.

From log:

Code: Select all

StartChildProcess (dir=".") UCI2WB debug -nice 10 -kill 1 "Deuterium.exe" "D:\Chess\Engines\Deuterium"
StartChildProcess (dir="D:\Chess\Engines\Crafty") Crafty_25.6_pop.exe
There are 17 time forfeits out of 225 games in that test.

Sample part of log where Crafty loses on time.

Code: Select all

537139 >second: time 11
537139 >second: otim 37
book hit = (NULL)
537139 >second: Rh4+
silence
537264 <first : 
537264 <second:       11    -12       5 167201 178. Kg5 Ra4 179. Qb6 Kd5 180. Qb3+ Rc4 181. Kf5 Bd7+ 182. Kf6 Ba4 183. Qh3 Rc5 184. Qe6+ Kd4
537264 <second: move Kg5
GameEnds(28, Black wins on time, 4)

Ferdy
Posts: 4271
Joined: Sun Aug 10, 2008 1:15 pm
Location: Philippines

Re: Engines playing Musketeer Chess, good price

Post by Ferdy » Fri Jul 03, 2020 2:37 am

Another observation based from reading the logs is that if time left is 20cs or 200ms or less, there is a high chance that the engine will be forfeited due to time.

The current solution is to add a time buffer of 200ms.

Code: Select all

tbuf = 200
movesleft = 40

timeleft -= tbuf
movetime = timeleft/movesleft

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

Re: Engines playing Musketeer Chess, good price

Post by hgm » Fri Jul 03, 2020 8:09 am

Well, one issue was the difference in behavior between WinBoard and CuteChess. If WinBoard is running the engines at lower priority, and CuteChess is not, this is a difference. Arguing that this difference cannot be the cause of the trouble is not a reliable method to reveal the truth; we know nothing about how the Windows scheduler works. I would first make sure the engines are running under the same conditions, e.g. use -niceEngines 0 in WinBoard if that is what CuteChess does. If that would still cause time losses on WinBoard, and not on CuteChess, we have something we could look into in more detail, e.g. by making all involved entities announce time stamps for their actions that can be related to each other, rather than only to the time they have been running. Then we can see excatly where the lag originates.

Ferdy
Posts: 4271
Joined: Sun Aug 10, 2008 1:15 pm
Location: Philippines

Re: Engines playing Musketeer Chess, good price

Post by Ferdy » Mon Jul 06, 2020 12:46 am

Cutechess runs engines in normal priority. Adding -niceEngines 0 in winboard as you suggested solves my time forfeit issue.

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

Re: Engines playing Musketeer Chess, good price

Post by hgm » Mon Jul 06, 2020 9:01 am

It used to be that running the engines at lower priority would make things work more reliably. Apparently on newer Windows systems this is no longer true, to the point where one can wonder whether the OS should be considered broken. With so many (HT) cores in reserve, and no other heavy computational task running it is really strange that a process, even a lower-priority proces, should get suspended by as much as 250 ms. It is almost like the process image must have been swapped to disk. (To make room for what? Garbage that MicroSoft wanted to pollute your memory with?)

Post Reply