(Winboard bug) Mysterious move in PGN?

[Guenther Simon]

What could have happened with Scorpios last 40th move,
which obviously was too late for WB?
(Hint: the PGN shows a _different_ move than Scorpios log!)
It's a pity that I had overwritten exactly this debug by accident.
The informations below are from Scorpios and Fruits logs.

[Event "Computer chess game"]
[Site "ESPRESSO"]
[Date "2005.06.08"]
[Round "24"]
[White "Scorpio_111"]
[Black "Fruit_20fast"]
[Result "0-1"]
[TimeControl "40/300"]

1. d4 d5 2. c4 c6 3. Nf3 Nf6 4. Nc3 a6 5. e3 b5 6. cxd5 cxd5 7. Ne5 e6 8.
Bd3 {+0.18/10} Bb7 9. a4 {+0.36/10} b4 {+0.05/11} 10. Na2 {+0.08/11}
Nc6 {+0.16/12} 11. Bd2 {+0.43/11} Nxe5 {+0.34/13} 12. dxe5 {+0.00/14}
Nd7 {+0.34/11} 13. f4 {+0.00/12} Qh4+ {+0.53/11} 14. g3 {+0.00/13}
Qh3 {+0.57/11} 15. Bf1 {+0.00/12} Qf5 {+0.48/12} 16. Rg1 {+0.00/11}
a5 {+0.75/11} 17. Rc1 {-0.17/11} Nc5 {+0.89/11} 18. Bb5+ {-0.28/11}
Kd8 {+1.08/11} 19. g4 {-0.76/12} Nd3+ {+1.39/12} 20. Kf1 {-0.71/12}
Qe4 {+1.39/12} 21. Rc2 {-0.79/11} b3 {+1.42/11} 22. Rc3 {-0.47/10}
Nxf4 {+1.23/11} 23. Rxb3 {-0.74/11} Ng6 {+1.41/11} 24. Bc3 {-0.95/10}
Nxe5 {+1.62/10} 25. Bxe5 {-1.17/10} Qxe5 {+2.15/11} 26. Rg2 {-1.33/10}
Bc5 {+2.38/10} 27. Qf3 {-1.14/10} Rc8 {+2.32/10} 28. Rc3 {-1.68/11}
Rf8 {+2.46/11} 29. Rgc2 {-1.45/9} f5 {+3.31/11} 30. g5 {-2.68/12}
f4 {+3.91/12} 31. e4 {-4.75/12} d4 {+4.34/12} 32. Rc4 {-4.71/11}
Qxe4 {+4.17/12} 33. Qxe4 {-4.70/12} Bxe4 {+3.91/12} 34. Rd2 {-4.86/12}
e5 {+3.91/13} 35. b4 {-4.72/11} axb4 {+3.78/12} 36. Nxb4 {-4.72/10}
Bxb4 {+3.67/12} 37. Rxb4 {-4.50/9} Rc1+ {+3.67/11} 38. Kf2 {-4.35/9}
Rf5 {+3.68/12} 39. h4 {-4.36/8} Rh1 {+3.97/13} 40. Rxe4 {-4.54/5}
{Black wins on time} 0-1

Code: Select all

// Scorpio log excerpt //

584.971: < move h2-h4
591.811: > time 9
591.811: > otim 857
591.811: > c1h1
591.831: < 1 -670 0 24  Rb4xd4 e5xd4 Rd2xd4 Be4-d5 Bb5-c4 Rh1xh4 Rd4xd5 Kd8-e7
591.831: < 1 -506 0 50  Bb5-a6 Rh1xh4 Ba6-c4
591.831: < 1 -491 0 89  Bb5-e2 Rh1xh4 Rb4-b8 Kd8-c7
591.831: < 2 -494 0 193  Bb5-e2 Rh1xh4 Rb4-b8 Kd8-c7
591.831: < 2 -430 0 297  Rd2xd4 Kd8-e7 Rd4xe4 Rh1-e1
591.871: < 2 -659 0 317  Rd2xd4 e5xd4 Rb4xd4 Rf5-d5 Rd4xe4 h7-h5
591.871: < 2 -670 0 341  Rd2xd4 e5xd4 Rb4xd4 Be4-d5 Bb5-c4 Rh1xh4 Rd4xd5 Kd8-e7
591.871: < 2 -448 0 465  Rd2-e2 Rh1-h2 Kf2-g1 Rh2xe2 Bb5xe2
591.871: < 3 -510 0 608  Rd2-e2 Rh1-h2 Kf2-g1 Rh2xe2 Bb5xe2
591.881: < 3 -510 0 1228  Rd2-e2 Be4-d5 Re2-b2 Rh1xh4
591.881: < 3 -509 0 2616  Bb5-a6 Rh1xh4 Rb4-b8 Kd8-c7
591.881: < 3 -495 0 3725  Bb5-f1 Rh1-h2 Kf2-e1 Rh2xh4
591.881: < 3 -494 1 4529  Bb5-e2 Rh1xh4 Rb4-b8 Kd8-e7
591.881: < 4 -579 1 4804  Bb5-e2 Rh1xh4 Be2-f3 Be4xf3
591.881: < 4 -622 1 6186  Bb5-e2 Rh1xh4 a4-a5 Rh4-h2 Kf2-g1 Rh2-g2 Kg1-f1 Rf5xg5
591.881: < 4 -579 1 7922  Bb5-f1 Rh1xh4 Bf1-g2 Be4xg2 Kf2xg2 Rf5xg5 Kg2-f3
591.881: < 4 -476 1 8839  Rd2-e2 Be4-d5 Bb5-d3 Rh1-h2 Kf2-g1 Rh2xe2 Bd3xe2
591.891: < 4 -430 1 9662  Rd2xd4 Kd8-e7 Rd4xe4 Rh1-e1
591.891: < 4 -687 1 10145  Rd2xd4 e5xd4 Rb4xd4 Be4-d5 Bb5-c6 Rh1-h2 Kf2-e1
591.891: < 4 -622 1 10146  Bb5-e2 Rh1xh4 a4-a5 Rh4-h2 Kf2-g1
591.891: < 4 -579 1 10147  Bb5-f1 Rh1xh4 Bf1-g2 Be4xg2
591.891: < 4 -476 1 10148  Rd2-e2 Be4-d5 Bb5-d3 Rh1-h2 Kf2-g1
591.891: < 5 -454 4 23688  Rd2-e2 Rh1-h2 Kf2-e1 Rh2xe2 Ke1xe2 f4-f3 Ke2-f2 h7-h6 g5-g6
591.891: < 5 -421 4 23757  Rd2xd4 e5xd4 Rb4xd4 Rf5-d5 Rd4xe4 h7-h5
591.891: < 5 -555 4 24654  Rd2xd4 e5xd4 Rb4xd4 Be4-d5 Rd4-e4
591.891: < 5 -697 4 25092  Rd2xd4 e5xd4 Rb4xd4 Be4-d5 Bb5-c6 Rh1-h2 Kf2-f1
591.891: < 5 -454 4 25093  Rd2-e2 Rh1-h2 Kf2-e1 Rh2xe2 Ke1xe2 f4-f3 Ke2-f2 h7-h6 g5-g6
591.891: < nodes = 36005 <52 qnodes> time = 0.06 nps = 600083
591.891: < lazy_eval rate  56
591.891: < move Rd2-e2
591.911: > result 0-1 {Black wins on time}
591.911: < Error (unknown command): result
591.911: < Error (unknown command): 0-1
591.911: < Error (unknown command): {Black
591.911: < Error (unknown command): wins
591.911: < Error (unknown command): on
591.911: < Error (unknown command): time}
591.911: > quit

// Fruit log excerpt //

> XBOARD 12 +387 251 1779775 Rh1 Rbxd4+ exd4 Rxd4+ Bd5 Bc6 Rh2+ Ke1 Rxh4 Rxd5+ Rxd5 Bxd5 Rh5 g6 hxg6 Be4
< ENGINE info currmove c1c3 currmovenumber 2
< ENGINE info currmove f4f3 currmovenumber 3
< ENGINE info currmove h7h6 currmovenumber 4
< ENGINE info currmove e4d5 currmovenumber 5
< ENGINE info currmove f5f7 currmovenumber 6
< ENGINE info currmove f5f8 currmovenumber 7
< ENGINE info currmove d8e7 currmovenumber 8
< ENGINE info currmove g7g6 currmovenumber 9
< ENGINE info currmove h7h5 currmovenumber 10
< ENGINE info currmove c1c7 currmovenumber 11
< ENGINE info currmove c1a1 currmovenumber 12
< ENGINE info currmove e4b7 currmovenumber 13
< ENGINE info currmove c1c5 currmovenumber 14
< ENGINE info currmove c1c8 currmovenumber 15
< ENGINE info currmove e4c6 currmovenumber 16
< ENGINE info currmove c1c2 currmovenumber 17
< ENGINE info currmove e4h1 currmovenumber 18
< ENGINE info currmove d8c7 currmovenumber 19
< ENGINE info time 3025 nodes 2130000 nps 704132 cpuload 1000
< ENGINE info hashfull 36
< ENGINE info currmove e4a8 currmovenumber 20
< ENGINE info currmove e4c2 currmovenumber 21
< ENGINE info currmove e4b1 currmovenumber 22
< ENGINE info currmove d8c8 currmovenumber 23
< ENGINE info currmove c1b1 currmovenumber 24
< ENGINE info currmove c1c6 currmovenumber 25
< ENGINE info currmove d4d3 currmovenumber 26
< ENGINE info currmove e4g2 currmovenumber 27
< ENGINE info currmove f5g5 currmovenumber 28
< ENGINE info currmove e4d3 currmovenumber 29
< ENGINE info currmove e4f3 currmovenumber 30
< ENGINE info currmove f5f6 currmovenumber 31
< ENGINE info currmove c1g1 currmovenumber 32
< ENGINE info currmove c1e1 currmovenumber 33
< ENGINE info currmove c1f1 currmovenumber 34
< ENGINE info currmove c1d1 currmovenumber 35
< ENGINE info currmove c1c4 currmovenumber 36
< ENGINE info depth 12 seldepth 27 time 3255 nodes 2289008 nps 703228
< ENGINE info depth 13
< ENGINE info currmove c1h1 currmovenumber 1
< ENGINE info time 4026 nodes 2910000 nps 722802 cpuload 1000
< ENGINE info hashfull 49
< ENGINE info time 5027 nodes 3610000 nps 718122 cpuload 1000
< ENGINE info hashfull 62
< ENGINE info depth 13 seldepth 31 score cp 397 time 5819 nodes 4177267 pv c1h1 b4d4 e5d4 d2d4 e4d5 b5c6 h1h2 f2e1 h2h4 c6d5 f5g5 e1f2 d8e7 a4a5 h4h2 f2f3 e7d6 d5e4 d6c5
> XBOARD 13 +397 582 4177267 Rh1 Rbxd4+ exd4 Rxd4+ Bd5 Bc6 Rh2+ Ke1 Rxh4 Bxd5 Rxg5 Kf2 Ke7 a5 Rh2+ Kf3 Kd6 Be4+ Kc5
< ENGINE info currmove c1c3 currmovenumber 2
< ENGINE info time 6039 nodes 4320000 nps 715350 cpuload 1000
< ENGINE info hashfull 73
< ENGINE info time 6820 nodes 4850000 nps 711144 cpuload 1000
< ENGINE info hashfull 84
< ENGINE bestmove c1h1 ponder b4d4
> XBOARD 13 +397 682 4850000 Rh1 Rbxd4+ exd4 Rxd4+ Bd5 Bc6 Rh2+ Ke1 Rxh4 Bxd5 Rxg5 Kf2 Ke7 a5 Rh2+ Kf3 Kd6 Be4+ Kc5
> XBOARD move c1h1
POLYGLOT MOVE Rh1
POLYGLOT THINK -> WAIT
< XBOARD result 0-1 {Black wins on time}
POLYGLOT GAME END

[Richard Pijl]

Looks like a timing problem. Although Scorpio thought it sent its move in time, winboard's time was already up. Transferring and responding to commands do take some time, so it is always wise not to use all the time that you have.
Richard.

[Guenther Simon]

Hi Richard,

Do you have an idea for the different moves too?

Best regards,
Guenther

[George Lyapko]

Hi Richard,

Do you have an idea for the different moves too?

Best regards,
Guenther

This is known bug in WinBoard(at least for me). Look at the game from round 23 and I am sure that in that game move 40 was Rxe4...

Best regards,
George

[Guenther Simon]

This is known bug in WinBoard(at least for me). Look at the game from round 23 and I am sure that in that game move 40 was Rxe4...

Best regards,
George

Thanks for the hint George, I will take a look if I am back from work.
Does this mean WB sometimes takes the last move from the previous game
before it flags a program?

Best regards,
Guenther

[Guenther Simon]

You hit the bull's eye George! It is like you said, WB included move 40
from the _previous_ game of the match for the too late move 40 in the real
game.
Do you have an idea how this can happen? I guess I will send a bug report
also to Alessandro, perhaps he can fix it.
BTW I suppose this bug was always there and has nothing to do with
Alessandros extensions?
Does it always happen, when an engine tries to send its last move
before the cut, but is too late by a very small margin, or what is the possible
logic behind the appearance of that bug?

Best regards,
Guenther

[Alessandro Scotti]

At a first glance it seems that the move counter is incremented without having a move added to the list. The move would then be fetched from "dirty" memory, which would be a move from the previous game if there is one, or just a meaningless value if, say, that game had not enough moves.
I'll try to take a look at the code within the next few days, although I'm quite busy with Kiwi at the moment.