PolyGlot interrupted by WinBoard?

[Fabien Letouzey]

Geschrieben von:/Posted by: Fabien Letouzey at 01 April 2004 11:22:08:


There was a specific problem that was reported by Dann, namely the engine-unloading problem. Dann said that Shredder would stay in memory after game matches in WinBoard (mg option).
He did send me a log file, but the analysis raised more questions than it gave answers. My suspicion is that, contrary to XBoard, WinBoard does strange things at exit time. I have seen in the logs WinBoard sending a "ping", and then doing something else, not even waiting for a "pong" to come back.
Here I try to describe what you should be looking for.
---
Here is a PolyGlot log extract:


POLYGLOT WAITING
< XBOARD ping 2
> XBOARD pong 2
< XBOARD quit
POLYGLOT *** QUIT ***
> ENGINE quit
> ENGINE EOF


This can be followed by either "POLYGLOT *** START ***" or the end of the log file. This is the *good* (expected) behaviour. WinBoard asks PolyGlot to quit, and then PolyGlot asks the UCI engine to quit. All should be fine (and always is with Linux XBoard).
---
This is what I have seen more than once (but not always):


POLYGLOT WAITING
< XBOARD ping 4
> XBOARD pong 4


And then "POLYGLOT *** START ***" or end of file. The meaning is that for some reason PolyGlot was "interrupted" before it had the time to notify the engine. Sometimes PolyGlot does not even have the time to answer "pong". No idea what it can be; PolyGlot asks using "feature" not to be bothered by signals, *and* is ignoring them anyway.
---
In the corresponding WinBoard debug file, I see something like this:


343658 >first : result 1-0 {White mates}
343658 >second: result 1-0 {White mates}
343658 >first : force
343658 >first : ping 4
343658 >second: force
343658 >second: ping 4
Exiting: Match Fruit vs. Shredder 7.04: final score 0-2-0
GameEnds(0, (null), 2)
343658 >first : quit
343658 >second: quit


My understanding of it is that WinBoard sends "ping" to both engines, and then asks them to quit (not waiting for a "pong"). The WinBoard log file stops here, meaning that WinBoard did not receive any answer from either PolyGlot. Also note that PolyGlot claims to have never received the "quit".
---
OK so this was pretty technical, but do you expect problems to be easy to understand?
Any log file concerning this problem is welcome.
Also, if you have heard of similar problems with WinBoard before, let me know.
Fabien.

[Volker Pittlik]

Geschrieben von:/Posted by: Volker Pittlik at 01 April 2004 11:55:51:
Als Antwort auf:/In reply to: PolyGlot interrupted by WinBoard? geschrieben von:/posted by: Fabien Letouzey at 01 April 2004 11:22:08:

...

Any log file concerning this problem is welcome.

This happend yesterday evening here. I tried a 4 games match with Gothmog and Shredder:
winboard.debug:


3955419 <first : 13 -1325 2720 7440382 Nc4 b1Q Ne3 Rd4 h3 Qe4 Kh2 Qf4+ Kg1 Rd2 Nf1 
3955419 <first : move d2c4
3955435 >second: time 27180
otim 35456
3955435 >second: usermove 3955435 >second: d2c4
3955544 <first : 0-1 {White resigns}
GameEnds(32, White resigns, 1)
3955560 >first : result 0-1 {White resigns}
3955560 >second: result 0-1 {White resigns}
3955575 >first : force
3955575 >first : ping 2
3955575 >second: force
3955575 >second: ping 1 /* It seems Shredder ignores the result*/
3955575 <second: 1 +1620 0 1 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955575 <second: 1 +1620 0 2 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955575 <second: 2 +1292 0 28 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955575 <second: 2 +1620 0 45 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955575 <second: 3 +1446 0 147 b1=Q Ne3 Rd5
3955575 <second: 3 +1620 0 177 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955575 <second: 4 +1471 0 322 b1=Q Ne3 Qe4
3955575 <second: 4 +1421 0 365 b1=Q Ne3 Qf5 Nxf5 Kc7
3955591 <second: 4 +1620 0 459 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955591 <second: 5 +1595 0 783 b1=Q Ne3 Qe4 Nxd1 Qg4+ Kxg4
3955591 <second: 5 +1545 0 943 b1=Q Ne3 Qe4 Nxd1 Qg4+ Kxg4
3955591 <second: 5 +1620 0 1206 b1=Q Ne3 Rd2 Ng4 Rd4 Kxf3 Qf5+ Ke2 Rxg4 Ke3 Rxa4 h3
3955591 <second: 6 +1595 1 2117 b1=Q Ne3 Qe4 Nxd1 Qe3 fxe3
3955591 <second: 6 +1545 6 2552 b1=Q Ne3 Qe4 Nxd1 Qe3 fxe3
3955591 <second: 6 +1293 8 5441 b1=Q Ne3 Rd2 Ng4 Qh1 Kf4
3955591 <second: 7 +1321 8 6820 b1=Q Ne3 Rd2 Ng4 Qh1 Kf4 Rd4+ Kg5 Qg2 h3 Qxh3
3955591 <second: 7 +1374 8 6907 b1=Q Ne3 Rd2 Ng4 Qh1 h3 Qg2+ Kh4 Rxf2
3955591 <second: 7 +1620 11 9829 b1=Q Ne3 Rd2 Ng4 Rd4 h4 Qg1+ Kh3 Rxg4 h5
3955591 <second: pong 1
3955622 <first : pong 2
Reset(0, 1) from gameMode 8
recognized 'normal' (-1) as variant normal
GameEnds(0, (null), 2)
3965575 >first : new
random
3965575 >first : ics -
3965575 >first : level 0 30 10
3965575 >first : post
3965575 >first : hard
3965575 >first : easy
3965575 >first : ping 3
3965575 <first : pong 3
3966575 >first : force
3966575 >second: new
random
3966575 >second: ics -
3966575 >second: level 0 30 10
3966575 >second: post
3966575 >second: hard
3966575 >second: easy
3966575 >second: ping 2
3966575 >second: force
3966575 >first : computer
3966575 >second: computer
3966575 >second: name Gothmog 0.4.7
3966575 >second: time 180000
otim 180000
3966575 >second: go
3966575 <second: Illegal move: ics -
3966575 <second: Illegal move: ping 2
3966575 <second: Illegal move: name Gothmog 0.4.7
3966575 <second: move d2d4
Undoing extra move from second, gameMode 5
3966575 >second: undo
GameEnds(32, Black wins on time, 4)
5766581 >first : result 0-1 {Black wins on time}
5766581 >second: result 0-1 {Black wins on time}
5766581 >first : force
5766581 >first : ping 4
5766581 >second: force
5766581 >second: ping 3
5766581 <second: Illegal move: result 0-1 {Black wins on time}
5766581 <second: Illegal move: ping 3
5766581 <first : pong 4
Reset(0, 1) from gameMode 8
recognized 'normal' (-1) as variant normal
GameEnds(0, (null), 2)
5776581 >first : new
random
5776581 >first : ics -
5776581 >first : level 0 30 10
5776581 >first : post
5776581 >first : hard
5776581 >first : easy
5776581 >first : ping 5
5776581 <first : pong 5
GameEnds(0, (null), 2)
7239315 >first : force
7239331 >first : ping 6
7239331 >first : quit
7239331 >second: quit


Shredder.log:


< ENGINE info depth 7 seldepth 18 time 109 score cp 1620 nodes 9829 nps 90174 hashfull 0 pv b2b1q c4e3 d1d2 e3g4 d2d4 h2h4 b1g1 g3h3 d4g4 h4h5
> XBOARD 7 +1620 11 9829 b1=Q Ne3 Rd2 Ng4 Rd4 h4 Qg1+ Kh3 Rxg4 h5
< XBOARD result 0-1 {White resigns}
POLYGLOT GAME END
POLYGLOT STOP SEARCH
> ENGINE stop
POLYGLOT WAITING
< ENGINE info nodes 10830
< ENGINE info currmovenumber 1 currmove b2b1q
< ENGINE info depth 8 seldepth 8
< XBOARD force
POLYGLOT WAITING
< XBOARD ping 1
> XBOARD pong 1
< ENGINE info depth 8 seldepth 22 time 171 score cp 1595 upperbound nodes 21430 nps 125321 hashfull 1 pv b2b1q c4e3 d1d2 g3f3 b1h1 f3g4 h1g2 e3g2 d2d4 g4g3
< ENGINE info currmovenumber 1 currmove b2b1q
< ENGINE info nps 125882 cpuload 417 nodes 23540 hashfull 1 
< ENGINE bestmove b2b1q ponder c4e3
< XBOARD new
POLYGLOT NEW GAME
POLYGLOT WAITING
< XBOARD new
POLYGLOT NEW GAME
POLYGLOT WAITING
< XBOARD random
< XBOARD level 0 30 10
< XBOARD post
< XBOARD hard
> ENGINE setoption name Ponder value true
POLYGLOT WAITING
< XBOARD easy
> ENGINE setoption name Ponder value false
POLYGLOT WAITING
< XBOARD computer
< XBOARD time 180000
< XBOARD otim 180000
< XBOARD force
POLYGLOT WAITING
< XBOARD d2d4
POLYGLOT MOVE d4
POLYGLOT WAITING
< XBOARD EOF


PGN:
[Event "Computer chess game"]
[Site "VPITTLIK"]
[Date "2004.03.31"]
[Round "1"]
[White "Gothmog 0.4.7"]
[Black "Bookthinker-Shredder"]
[Result "0-1"]
[TimeControl "1800+10"]
1. d4 d5 2. c4 c6 3. Nf3 Nf6 4. Nc3 e6 5. Bg5 dxc4 6. e4 b5 7. e5 h6 8. Bh4
g5 9. exf6 gxh4 10. Ne5 Qxf6 11. a4 Bb7 12. Be2 Nd7 13. Nxd7 Kxd7 14. Bf3
b4 15. Ne4 Qf5 16. Rc1 Rd8 17. Rxc4 Kc7 18. Qc1 h3 19. Ng3 Qg5 20. Qc2 Kb8
21. gxh3 Ba6 22. Rxc6 Bb7 23. O-O Bd6 24. Bg2 Rhg8 25. Qc4 h5 26. Rxd6 Rxd6
27. Bxb7 Kxb7 28. h4 Qd2 29. Qb5+ Ka8 30. Qxh5 f5 31. Qf3+ Kb8 32. Rd1 Qxb2
33. Qf4 Rd8 34. h5 Qb3 35. Rc1 Qd3 36. Rc6 Qxd4 37. Qxd4 Rxd4 38. Rxe6 b3
39. Re3 Rd3 40. Re5 f4 41. Kg2 R8d5 42. Rxd5 f3+ 43. Kh3 Rxd5 44. Ne4 b2
45. Nc3 Rxh5+ 46. Kg3 Rc5 47. Nb1 Rc1 48. Nd2 Rd1 49. Nc4
{White resigns} 0-1

Volker

[Fabien Letouzey]

Geschrieben von:/Posted by: Fabien Letouzey at 01 April 2004 12:12:20:
Als Antwort auf:/In reply to: Re: PolyGlot interrupted by WinBoard? geschrieben von:/posted by: Volker Pittlik at 01 April 2004 11:55:51:

This happend yesterday evening here. I tried a 4 games match with Gothmog and Shredder:
winboard.debug:
Shredder.log:

If I understand correctly "first" is Gothmog XB, and "second" is PolyGlot + Shredder?


>3955575 >second: force
>3955575 >second: ping 1 /* It seems Shredder ignores the result*/
>...
>3955591 <second: pong 1


No the number in the left margin represents the time, I think in ms.
So all those events occured in the blink of an eye.
"pong 1" was answered eventually.
All seems fine here.


>3966575 <second: Illegal move: ics -
>3966575 <second: Illegal move: ping 2
>3966575 <second: Illegal move: name Gothmog 0.4.7
>3966575 <second: move d2d4
>Undoing extra move from second, gameMode 5
>3966575 >second: undo
>GameEnds(32, Black wins on time, 4)
>5766581 >first : result 0-1 {Black wins on time}
>5766581 >second: result 0-1 {Black wins on time}


I have no idea what this is about.
PolyGlot knows about "ics", "ping", "name" etc ...
Complaining about illegal move (or command) makes no sense here.


>5766581 >first : force
>5766581 >first : ping 4
>5766581 >second: force
>5766581 >second: ping 3
>5766581 <second: Illegal move: result 0-1 {Black wins on time}
>5766581 <second: Illegal move: ping 3
>5766581 <first : pong 4
>Reset(0, 1) from gameMode 8
>recognized 'normal' (-1) as variant normal
>GameEnds(0, (null), 2)
>5776581 >first : new
>random
>5776581 >first : ics -
>5776581 >first : level 0 30 10
>5776581 >first : post
>5776581 >first : hard
>5776581 >first : easy
>5776581 >first : ping 5
>5776581 <first : pong 5
>GameEnds(0, (null), 2)
>7239315 >first : force
>7239331 >first : ping 6
>7239331 >first : quit
>7239331 >second: quit




>POLYGLOT WAITING
>< XBOARD new
>...
>< XBOARD EOF


That's the sort of clue I'm looking for.
WinBoard is supposed to always sent "quit" before closing the connection (EOF).
So my question is, ever heard of some similar problem with WinBoard?
Fabien.