Nebula 2.0 POPCNT x64 time forfeits

Discussion of anything and everything relating to chess playing software and machines.

Moderators: hgm, Rebel, chrisw

Norbert Raimund Leisner
Posts: 1643
Joined: Tue May 20, 2008 4:57 pm
Location: Augsburg - Germany

Nebula 2.0 POPCNT x64 time forfeits

Post by Norbert Raimund Leisner »

Hello,

https://sites.google.com/site/nebulachess/


time forfeit problems in a 40/2 round robin tournament under ChessGUI http://www.chess.hylogic.de/ are listed below:

[Site "ChessGUI"]
[Date "2017.06.30"]
[White "Arminius 2017-01-01"]
[Black "Nebula 2.0"]
[Result "1-0"]
[TimeControl "40/120:40/120:40/120"]
[PlyCount "79"]
[Number "19"]
[Termination "time"]
[BlackType "program"]
[WhiteType "program"]
[Variant "normal"]

1. g3 e5 2. c4 Bc5 3. Bg2 Ne7 4. a3 O-O 5. b4 Bd4 6. Ra2 d6 7. e3 Bb6 8. Nc3 a5 9. b5 Nd7 10. d4 Ba7 11. Nf3 exd4 12. exd4 Nb6 13. Nd2 Nf5 14. Ne2 Qf6 15. Ne4 Qe7 16. Qd3 c6 17. bxc6 bxc6 18. N4c3 Qd7 19. d5 Ba6 20. dxc6 Qe6 21. Qb1 Bxc4 22. Rd2 Rfe8 23. O-O g6 24. Bb2 Ne3 25. Nf4 Nxf1 26. Nxe6 Nxd2 27. Qd1 Bxe6 28. Qxd2 Nc4 29. Qc1 Bf5 30. c7 Nxb2 31. Bxa8 Nd3 32. Qg5 Bxf2+ 33. Kg2 Bb6 34. Be4 Bxc7 35. Bxf5 Re5 36. g4 Nc5 37. Qh6 gxf5 38. Nb5 Ne6 39. Nxc7 Nxc7 40. Qxd6 1-0

[Site "ChessGUI"]
[Date "2017.06.30"]
[White "Nebula 2.0"]
[Black "Arminius 2017-01-01"]
[Result "0-1"]
[TimeControl "40/120:40/120:40/120"]
[PlyCount "78"]
[Number "32"]
[Termination "time"]
[WhiteType "program"]
[BlackType "program"]
[Variant "normal"]

1. Nf3 d5 2. d4 Bg4 3. Ne5 Bf5 4. c4 f6 5. Nf3 e6 6. Qb3 Nc6 7. e3 Nb4 8. Na3 a5 9. Be2 a4 10. Qd1 Kf7 11. O-O g5 12. c5 b6 13. cxb6 cxb6 14. Bb5 Qb8 15. Bxa4 Bd3 16. Re1 b5 17. Bb3 Bd6 18. h4 g4 19. Nd2 f5 20. f4 Be7 21. g3 Nf6 22. Nab1 Rc8 23. Nc3 Bc4 24. Nxc4 dxc4 25. Bc2 Nxc2 26. Qxc2 b4 27. Ne2 b3 28. Qb1 Qa7 29. a3 Ne4 30. Rd1 Qb7 31. Rf1 Qa6 32. h5 Bb4
33. d5 exd5 34. Rf2 Be1 35. Rg2 Qa5 36. Kf1 Kg8 37. Nd4 Bxg3 38. Re2 Qd8 39. Nxf5 Qf6 0-1

[Event "Third World War"]
[EventDate "?"]
[Site "ChessGUI"]
[Date "2017.06.30"]
[Round "9.2"]
[White "Nebula 2.0"]
[Black "ruy_sse42"]
[Result "0-1"]
[TimeControl "40/120:40/120:40/120"]
[Time "12:48:37"]
[PlyCount "76"]
[Number "34"]
[Termination "time"]
[WhiteType "program"]
[BlackType "program"]
[Variant "normal"]

1. Nf3 Nf6 2. e3 d5 3. c4 Nc6 4. cxd5 Qxd5 5. Nc3 Qh5 6. d4 Bg4 7. Be2 e6 8. h3 Bd6 9. Qa4 O-O 10. Rg1 Bxf3 11. Bxf3 Qg6 12. Bxc6 bxc6 13. Qxc6 Rab8 14. b3 Rb6 15. Qf3 e5 16. Na4 Bb4+ 17. Bd2 Bxd2+ 18. Kxd2 Rd6 19. Nb2 exd4 20. Kc1 d3 21. Nc4 Rd5 22. Rb1 Ne4 23. Rb2 Rfd8 24. Rd1 f5
25. g4 Qf6 26. gxf5 d2+ 27. Kc2 Ng5 28. Qg4 h5 29. Qf4 Nxh3 30. Qf3 Ng5 31. Qf4 Rxf5 32. Qxc7 Rfd5 33. f3 Qf5+ 34. Kc3 Qxf3 35. Rbb1 Ne4+ 36. Kc2 Qf6 37. Rb2 Qg6 38. Rbb1 Nd6+ 0-1

Best wishes,
Norbert
Norbert Raimund Leisner
Posts: 1643
Joined: Tue May 20, 2008 4:57 pm
Location: Augsburg - Germany

Re: Nebula 2.0 POPCNT x64 time forfeits

Post by Norbert Raimund Leisner »

game 19 debug

Current position (Ply 78) : 6k1/2n2p1p/3p3Q/p3rp2/6P1/P7/6KP/8 w - - 0 40 = 6k1/2n2p1p/3p3Q/p3rp2/6P1/P7/6KP/8 w - - 0 40
System time lag per move = 271 milliseconds
Eng01 (Arminius 2017-01-01) thought for 1638 milliseconds, time left = 3200 milliseconds
Almost in ParcelMove(from Arminius 2017-01-01) at Time0000000015537902

DetailsOfMove(CAPTURE_MOVE: bestmove h6d6 ponder e5e2 = Qh6xd6 = Qxd6 = Qh6-d6) -> nSide = White, nPieceNr = Queen, nFrom = H6, nTo = D6, nCapturedNr = Pawn, promo = NoPiece, ep = A1, nFlags = 40, (Move = 4000000135390701 == 4611686023615284993)

Qh6xd6
Now in MakeChessMove() at Time0000000015537902, nChsProgNr = 0, ChsStrct->PlyPtr = 78

Now in MakeChessMove() at Time0000000015537902, nChsProgNr = 1, ChsStrct->PlyPtr = 78

Now in DrawGraphics() at Time0000000015537902

Now in DrawGraphics() at Time0000000015537902

Memory: 71 MB + 72 MB (2105 MB free)
CPU Load: 46% + 47%
Total Time Elapsed = 00:04:01
MoveNr. = 39, SideToMove = black.
50 moves to 50-Move-Rule.
Last Move = h6d6 = Qxd6 = Qh6-d6
Expected Move = e5e2
Now in CheckForEndOfGame() at Time0000000015537917

Now in MakeTimeControlString() at Time0000000015537917

Now in ParcelMove() at Time0000000015537917

CASTLING_MOVE: nChessVariant = 1, for EngName = Nebula 2.0

CASTLING_MOVE: nChessVariant = 1, for EngName = Nebula 2.0

SendToEng2Time 0000000015537917 : Eng02 (Nebula 2.0) -> position startpos moves g2g3 e7e5 c2c4 f8c5 f1g2 g8e7 a2a3 e8g8 b2b4 c5d4 a1a2 d7d6 e2e3 d4b6 b1c3 a7a5 b4b5 b8d7 d2d4 b6a7 g1f3 e5d4 e3d4 d7b6 f3d2 e7f5 c3e2 d8f6 d2e4 f6e7 d1d3 c7c6 b5c6 b7c6 e4c3 e7d7 d4d5 c8a6 d5c6 d7e6 d3b1 a6c4 a2d2 f8e8 e1g1 g7g6 c1b2 f5e3 e2f4 e3f1 f4e6 f1d2 b1d1 c4e6 d1d2 b6c4 d2c1 e6f5 c6c7 c4b2 g2a8 b2d3 c1g5 a7f2 g1g2 f2b6 a8e4 b6c7 e4f5 e8e5 g3g4 d3c5 g5h6 g6f5 c3b5 c5e6 b5c7 e6c7 h6d6
.
Now in SendTimeControlString() at Time0000000015537933

SideToMove=b, nInterval = 1, nmoves = 0, imoves = 39, movestogo = 40, wtime = 120000, btime = 120000, winc = 0, binc = 0, PlyPtr = 79, TimeLeft = 906 ms
White's TimeLeft = 3200 ms, hiding 1638 ms from Black movestogo 1

SendToEng2Time 0000000015537933 : Eng02 (Nebula 2.0) -> go movestogo 1 wtime 4838 btime 906
.
SideToMove = Black.
SendToEng9Time 0000000015537933 : Eng09 (TimeLagEngine) -> LagTo 0000000015537933
.
Extra time for Nebula 2.0 = 0 milliseconds.
==========================================================================================================================
Scheduling GameMoveTimerEvent() for Nebula 2.0 at 0000000015537933.
Eng02 (Nebula 2.0) <- info depth 1 score cp -451 time 0 nodes 7 nps 7000 seldepth 3 pv f5g4 d6e5
Eng02 (Nebula 2.0) <- info depth 1 score cp -221 time 0 nodes 16 nps 16000 seldepth 3 pv e5e2 g2f3 c7e8
Eng02 (Nebula 2.0) <- info depth 2 score cp -221 time 0 nodes 197 nps 197000 seldepth 2 pv e5e2 g2f3 c7e8
Eng02 (Nebula 2.0) <- info depth 3 score cp -221 time 0 nodes 308 nps 308000 seldepth 3 pv e5e2 g2f3 c7e8
Eng02 (Nebula 2.0) <- info depth 4 score cp -221 time 0 nodes 506 nps 506000 seldepth 4 pv e5e2 g2f3 c7e8 d6d5
Eng02 (Nebula 2.0) <- info depth 5 score cp -221 time 0 nodes 1114 nps 1114000 seldepth 5 pv e5e2 g2f3 c7e8 d6d5 e2h2
Eng02 (Nebula 2.0) <- info depth 6 seldepth 6
Eng02 (Nebula 2.0) <- info depth 6 score cp -186 lowerbound time 1 nodes 2608 nps 2608000 seldepth 6 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5
Eng02 (Nebula 2.0) <- info depth 6 seldepth 6
Eng02 (Nebula 2.0) <- info depth 6 score cp -221 time 1 nodes 2624 nps 2624000 seldepth 6 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5
Eng02 (Nebula 2.0) <- info depth 7 seldepth 7
Eng02 (Nebula 2.0) <- info depth 7 score cp -186 lowerbound time 1 nodes 4804 nps 4804000 seldepth 7 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3
Eng02 (Nebula 2.0) <- info depth 7 seldepth 7
Eng02 (Nebula 2.0) <- info depth 7 score cp -221 time 1 nodes 4820 nps 4820000 seldepth 7 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3
WM_TimeLagEngine() says TimeLagReturn 0000000015538183 SystemLag LagTo 0000000015537933 0000000015538058
WM_TimeLagEngine() : To = 125 ms, From = 125 ms, Total = 250 ms
Eng02 (Nebula 2.0) <- info depth 8 seldepth 8
Eng02 (Nebula 2.0) <- info depth 8 score cp -186 lowerbound time 3 nodes 9676 nps 3225333 seldepth 8 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2
Eng02 (Nebula 2.0) <- info depth 8 seldepth 8
Eng02 (Nebula 2.0) <- info depth 8 score cp -221 time 3 nodes 9692 nps 3230666 seldepth 8 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2
Eng02 (Nebula 2.0) <- info depth 9 seldepth 9
Eng02 (Nebula 2.0) <- info depth 9 score cp -186 lowerbound time 4 nodes 16999 nps 4249750 seldepth 9 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4
Eng02 (Nebula 2.0) <- info depth 9 seldepth 9
Eng02 (Nebula 2.0) <- info depth 9 score cp -221 time 4 nodes 17015 nps 4253750 seldepth 9 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4
Eng02 (Nebula 2.0) <- info depth 10 seldepth 10
Eng02 (Nebula 2.0) <- info depth 10 score cp -186 lowerbound time 7 nodes 30667 nps 4381000 seldepth 10 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8
Eng02 (Nebula 2.0) <- info depth 10 seldepth 10
Eng02 (Nebula 2.0) <- info depth 10 score cp -221 time 7 nodes 30691 nps 4384428 seldepth 10 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8
Eng02 (Nebula 2.0) <- info depth 11 seldepth 11
Eng02 (Nebula 2.0) <- info depth 11 score cp -186 lowerbound time 14 nodes 57950 nps 4139285 seldepth 11 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8 g8g7
Eng02 (Nebula 2.0) <- info depth 11 seldepth 11
Eng02 (Nebula 2.0) <- info depth 11 score cp -221 time 14 nodes 57974 nps 4141000 seldepth 11 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8 g8g7
Eng02 (Nebula 2.0) <- info depth 12 seldepth 12
Eng02 (Nebula 2.0) <- info depth 12 score cp -221 time 30 nodes 181647 nps 6054900 seldepth 24 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8 g8g7 e8e5
Eng02 (Nebula 2.0) <- info depth 13 seldepth 13
Eng02 (Nebula 2.0) <- Pipe02Time 0000000015538947
Exact move time for Nebula 2.0
Eng02 (Nebula 2.0) <- bestmove e5e2
Cancelling GameMoveTimerEvent() for Nebula 2.0 at 0000000015538947.
nChessVariant(1) = 1, bestmove.
==========================================================================================================================
Current position (Ply 79) : 6k1/2n2p1p/3Q4/p3rp2/6P1/P7/6KP/8 b - - 0 40 = 6k1/2n2p1p/3Q4/p3rp2/6P1/P7/6KP/8 b - - 0 40
System time lag per move = 270 milliseconds
Eng02 (Nebula 2.0) thought for 1014 milliseconds, time left = -108 milliseconds
Almost in ParcelMove(from Nebula 2.0) at Time0000000015538947

DetailsOfMove(bestmove e5e2 = Re5-e2 = Re2 = Re5-e2) -> nSide = Black, nPieceNr = Rook, nFrom = E5, nTo = E2, nCapturedNr = NoPiece, promo = NoPiece, ep = A1, nFlags = 40, (Move = 400000000E2C0400 == 4611686018665153536)

Nebula 2.0 loses on time in ParcelMove().
Now in CheckForEndOfGame() at Time0000000015538947

Now in EndTheGame() at Time0000000015538963

1-0
.

1-0
SendToEng2Time 0000000015538963 : Eng02 (Nebula 2.0) -> stop
.
SendToEng2Time 0000000015538963 : Eng02 (Nebula 2.0) -> quit
.
SendToEng1Time 0000000015538963 : Eng01 (Arminius 2017-01-01) -> stop
.
SendToEng1Time 0000000015538978 : Eng01 (Arminius 2017-01-01) -> quit
.
Now in KillEngines() at Time0000000015539977

Now in PutResultInSchedule() at Time0000000015539977

Now in SavePGN() at Time0000000015539977

1-0
.

Now in PutResultInStringList() at Time0000000015539992

Now in EndChildProcess() at Time0000000015540008 to kill Nebula 2.0.

!!! Disk Space !!! (229232275456 Bytes free)
DestroyChildProcess(Eng02 = Nebula 2.0) is already dead.
Now in EndChildProcess() at Time0000000015540008 to kill Arminius 2017-01-01.

!!! Disk Space !!! (229232275456 Bytes free)
DestroyChildProcess(Eng01 = Arminius 2017-01-01) is already dead.
Now in EndChildProcess() at Time0000000015540008 to kill TimeLagEngine.

!!! Disk Space !!! (229232275456 Bytes free)
SendToEng9Time 0000000015540117 : Eng09 (TimeLagEngine) -> stop
.
SendToEng9Time 0000000015540117 : Eng09 (TimeLagEngine) -> quit
.
DestroyChildProcess(Eng09 = TimeLagEngine), soft termination, trial 1.
Now in EraseInputBuffers(TimeLagEngine).
Now in EraseInputBuffers(Nebula 2.0).
Now in EraseInputBuffers(Arminius 2017-01-01).
Now in SaveDeleteDebugFiles() at Time0000000015544126
Norbert Raimund Leisner
Posts: 1643
Joined: Tue May 20, 2008 4:57 pm
Location: Augsburg - Germany

Re: Nebula 2.0 POPCNT x64 time forfeits

Post by Norbert Raimund Leisner »

game 32 debug

Current position (Ply 77) : r1rq2k1/7p/8/3p1N1P/2p1nPp1/Pp2P1b1/1P2R3/RQB2K2 b - - 0 39 = r1rq2k1/7p/8/3p1N1P/2p1nPp1/Pp2P1b1/1P2R3/RQB2K2 b - - 0 39
System time lag per move = 236 milliseconds
Eng02 (Arminius 2017-01-01) thought for 3167 milliseconds, time left = 3623 milliseconds
Almost in ParcelMove(from Arminius 2017-01-01) at Time0000000020229164

DetailsOfMove(bestmove d8f6 ponder b1e4 = Qd8-f6 = Qf6 = Qd8-f6) -> nSide = Black, nPieceNr = Queen, nFrom = D8, nTo = F6, nCapturedNr = NoPiece, promo = NoPiece, ep = A1, nFlags = 40, (Move = 4000000037490700 == 4611686019354920704)

Qd8-f6
Now in MakeChessMove() at Time0000000020229164, nChsProgNr = 1, ChsStrct->PlyPtr = 77

Now in MakeChessMove() at Time0000000020229164, nChsProgNr = 0, ChsStrct->PlyPtr = 77

Now in DrawGraphics() at Time0000000020229164

Now in DrawGraphics() at Time0000000020229164

Memory: 72 MB + 71 MB (2252 MB free)
CPU Load: 48% + 46%
Total Time Elapsed = 00:04:00
MoveNr. = 39, SideToMove = white.
49 moves to 50-Move-Rule.
Last Move = d8f6 = Qf6 = Qd8-f6
Expected Move = b1e4
Now in CheckForEndOfGame() at Time0000000020229195

Now in MakeTimeControlString() at Time0000000020229195

Now in ParcelMove() at Time0000000020229195

CASTLING_MOVE: nChessVariant = 1, for EngName = Nebula 2.0

SendToEng1Time 0000000020229195 : Eng01 (Nebula 2.0) -> position startpos moves g1f3 d7d5 d2d4 c8g4 f3e5 g4f5 c2c4 f7f6 e5f3 e7e6 d1b3 b8c6 e2e3 c6b4 b1a3 a7a5 f1e2 a5a4 b3d1 e8f7 e1g1 g7g5 c4c5 b7b6 c5b6 c7b6 e2b5 d8b8 b5a4 f5d3 f1e1 b6b5 a4b3 f8d6 h2h4 g5g4 f3d2 f6f5 f2f4 d6e7 g2g3 g8f6 a3b1 h8c8 b1c3 d3c4 d2c4 d5c4 b3c2 b4c2 d1c2 b5b4 c3e2 b4b3 c2b1 b8a7 a2a3 f6e4 e1d1 a7b7 d1f1 b7a6 h4h5 e7b4 d4d5 e6d5 f1f2 b4e1 f2g2 a6a5 g1f1 f7g8 e2d4 e1g3 g2e2 a5d8 d4f5 d8f6
.
Now in SendTimeControlString() at Time0000000020229195

SideToMove=w, nInterval = 1, nmoves = 0, imoves = 39, movestogo = 40, wtime = 120000, btime = 120000, winc = 0, binc = 0, PlyPtr = 78, TimeLeft = 335 ms
SendToEng1Time 0000000020229195 : Eng01 (Nebula 2.0) -> go movestogo 1 wtime 335 btime 3623
.
SideToMove = White.
SendToEng9Time 0000000020229195 : Eng09 (TimeLagEngine) -> LagTo 0000000020229195
.
Extra time for Nebula 2.0 = 0 milliseconds.
==========================================================================================================================
Scheduling GameMoveTimerEvent() for Nebula 2.0 at 0000000020229195.
Eng01 (Nebula 2.0) <- info depth 1 score cp -359 time 0 nodes 5 nps 5000 seldepth 3 pv b1e4 d5e4 f5g3
Eng01 (Nebula 2.0) <- info depth 1 score cp -223 time 0 nodes 24 nps 24000 seldepth 5 pv f5g3 e4g3 f1e1 g3e2 e1e2
Eng01 (Nebula 2.0) <- info depth 2 score cp -223 time 0 nodes 160 nps 160000 seldepth 5 pv f5g3 e4g3 f1e1 g3e2 e1e2
Eng01 (Nebula 2.0) <- info depth 3 score cp -223 time 0 nodes 376 nps 376000 seldepth 10 pv f5g3 e4g3 f1e1 g3e2 e1e2
Eng01 (Nebula 2.0) <- info depth 4 score cp -239 time 0 nodes 850 nps 850000 seldepth 13 pv f5g3 e4g3 f1e1 g3e2 e1e2 g4g3
Eng01 (Nebula 2.0) <- info depth 5 score cp -231 time 0 nodes 2112 nps 2112000 seldepth 15 pv f5g3 e4g3 f1e1 g3e2 e1e2 c8e8 e2d1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -248 upperbound time 0 nodes 2455 nps 2455000 seldepth 13 pv f5g3 e4g3 f1e1 g3e2 e1e2 c8e8 e2d1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -278 upperbound time 0 nodes 2734 nps 2734000 seldepth 14 pv f5g3 e4g3 f1e1 g3e2 e1e2 c8e8 e2d1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -210 lowerbound time 0 nodes 3306 nps 3306000 seldepth 15 pv f5d4 f6h4 e2g2 h4h1 g2g1 h1h3
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -210 time 0 nodes 3478 nps 3478000 seldepth 15 pv f5d4 f6h4 e2g2 h4h1 g2g1 h1h3
Eng01 (Nebula 2.0) <- info depth 7 seldepth 7
Eng01 (Nebula 2.0) <- info depth 7 score cp -302 upperbound time 0 nodes 3568 nps 3568000 seldepth 7 pv f5d4 f6h4 e2g2 h4h1 g2g1 h1h3 g1g2
Eng01 (Nebula 2.0) <- info depth 7 seldepth 7
Eng01 (Nebula 2.0) <- info depth 7 score cp -318 upperbound time 10 nodes 39996 nps 3999600 seldepth 24 pv f5d4 f6h4 e2g2 h4h1 g2g1 h1h3 g1g2
Eng01 (Nebula 2.0) <- info depth 7 seldepth 7
Eng01 (Nebula 2.0) <- info depth 7 score cp -350 upperbound time 10 nodes 48020 nps 4802000 seldepth 24 pv f5d4 f6h4 e2g2 h4h1 g2g1 h1h3 g1g2
Eng01 (Nebula 2.0) <- info depth 7 seldepth 7
Eng01 (Nebula 2.0) <- info depth 7 score cp -373 time 32 nodes 101594 nps 3174812 seldepth 24 pv b1e4 d5e4 f5g3 c8e8 f1g2 a8a4 e2d2 c4c3 b2c3 f6c3 d2b2
WM_TimeLagEngine() says TimeLagReturn 0000000020229445 SystemLag LagTo 0000000020229195 0000000020229320
WM_TimeLagEngine() : To = 125 ms, From = 125 ms, Total = 250 ms
Eng01 (Nebula 2.0) <- Pipe01Time 0000000020229554
Exact move time for Nebula 2.0
Eng01 (Nebula 2.0) <- info depth 8 seldepth 8
Eng01 (Nebula 2.0) <- info depth 8 score cp -369 time 55 nodes 186447 nps 3389945 seldepth 21 pv b1e4 d5e4 f5g3 f6h4 e2g2 c8d8 f1e1 h4h3 g2g1 h3h2
Eng01 (Nebula 2.0) <- info depth 8 score cp -357 lowerbound time 55 nodes 200632 nps 3647854 seldepth 21 pv f5g3 e4g3 f1e1 g3e2 e1e2 f6f7 c1d2 f7h5
Eng01 (Nebula 2.0) <- info depth 8 seldepth 8
Eng01 (Nebula 2.0) <- info depth 8 score cp -341 lowerbound time 55 nodes 205095 nps 3729000 seldepth 21 pv f5g3 e4g3 f1e1 g3e2 e1e2 f6f7 c1d2 f7h5
Eng01 (Nebula 2.0) <- info depth 8 seldepth 8
Eng01 (Nebula 2.0) <- info depth 8 score cp -369 time 65 nodes 211199 nps 3249215 seldepth 26 pv b1e4 d5e4 f5g3 f6h4 e2g2 c8d8 f1e1 h4h3
Eng01 (Nebula 2.0) <- info depth 9 seldepth 9
Eng01 (Nebula 2.0) <- info depth 9 score cp -379 time 75 nodes 266890 nps 3558533 seldepth 22 pv b1e4 d5e4 f5g3 f6h4 e2g2 c8d8 a3a4 d8d1 f1e2 a8d8 a4a5 c4c3 a5a6
Eng01 (Nebula 2.0) <- info depth 10 seldepth 10
Eng01 (Nebula 2.0) <- info depth 10 score cp -385 time 145 nodes 481033 nps 3317468 seldepth 24 pv b1e4 d5e4 f5g3 f6h4 e2g2 c8d8 a3a4 d8d1 f1e2 a8d8 h5h6 h4h3 e2f2 d8d3
Eng01 (Nebula 2.0) <- bestmove b1e4
Cancelling GameMoveTimerEvent() for Nebula 2.0 at 0000000020229694.
nChessVariant(0) = 1, bestmove.
==========================================================================================================================
Current position (Ply 78) : r1r3k1/7p/5q2/3p1N1P/2p1nPp1/Pp2P1b1/1P2R3/RQB2K2 w - - 1 40 = r1r3k1/7p/5q2/3p1N1P/2p1nPp1/Pp2P1b1/1P2R3/RQB2K2 w - - 1 40
System time lag per move = 236 milliseconds
Eng01 (Nebula 2.0) thought for 359 milliseconds, time left = -24 milliseconds
Almost in ParcelMove(from Nebula 2.0) at Time0000000020229694

DetailsOfMove(CAPTURE_MOVE: bestmove b1e4 = Qb1xNe4 = Qxe4 = Qb1-Ne4) -> nSide = White, nPieceNr = Queen, nFrom = B1, nTo = E4, nCapturedNr = Knight, promo = NoPiece, ep = A1, nFlags = 40, (Move = 4000000222010701 == 4611686027587815169)

Nebula 2.0 loses on time in ParcelMove().
Now in CheckForEndOfGame() at Time0000000020229694

Now in EndTheGame() at Time0000000020229694

0-1
.

0-1
SendToEng1Time 0000000020229710 : Eng01 (Nebula 2.0) -> stop
.
SendToEng1Time 0000000020229710 : Eng01 (Nebula 2.0) -> quit
.
SendToEng2Time 0000000020229710 : Eng02 (Arminius 2017-01-01) -> stop
.
SendToEng2Time 0000000020229710 : Eng02 (Arminius 2017-01-01) -> quit
.
Now in KillEngines() at Time0000000020230708

Now in PutResultInSchedule() at Time0000000020230708

Now in SavePGN() at Time0000000020230724

0-1
.

Now in PutResultInStringList() at Time0000000020230740

Now in EndChildProcess() at Time0000000020230740 to kill Nebula 2.0.

!!! Disk Space !!! (229192142848 Bytes free)
DestroyChildProcess(Eng01 = Nebula 2.0) is already dead.
Now in EndChildProcess() at Time0000000020230740 to kill Arminius 2017-01-01.

!!! Disk Space !!! (229192142848 Bytes free)
DestroyChildProcess(Eng02 = Arminius 2017-01-01) is already dead.
Now in EndChildProcess() at Time0000000020230755 to kill TimeLagEngine.

!!! Disk Space !!! (229192142848 Bytes free)
SendToEng9Time 0000000020230849 : Eng09 (TimeLagEngine) -> stop
.
SendToEng9Time 0000000020230849 : Eng09 (TimeLagEngine) -> quit
.
DestroyChildProcess(Eng09 = TimeLagEngine), soft termination, trial 1.
Now in EraseInputBuffers(TimeLagEngine).
Now in EraseInputBuffers(Nebula 2.0).
Now in EraseInputBuffers(Arminius 2017-01-01).
Now in SaveDeleteDebugFiles() at Time0000000020234842
Norbert Raimund Leisner
Posts: 1643
Joined: Tue May 20, 2008 4:57 pm
Location: Augsburg - Germany

Re: Nebula 2.0 POPCNT x64 time forfeits

Post by Norbert Raimund Leisner »

game 34 debug

Current position (Ply 75) : 3r2k1/p1Q3p1/6q1/3r3p/2N1n3/1P2P3/P1Kp4/1R1R4 b - - 7 38 = 3r2k1/p1Q3p1/6q1/3r3p/2N1n3/1P2P3/P1Kp4/1R1R4 b - - 7 38
System time lag per move = 389 milliseconds
Eng02 (ruy_sse42) thought for 1311 milliseconds, time left = 8308 milliseconds
Almost in ParcelMove(from ruy_sse42) at Time0000000020906411

DetailsOfMove(bestmove e4d6 ponder c2b2 = Ne4-d6 = Nd6 = Ne4-d6) -> nSide = Black, nPieceNr = Knight, nFrom = E4, nTo = D6, nCapturedNr = NoPiece, promo = NoPiece, ep = A1, nFlags = 40, (Move = 4000000035220200 == 4611686019318809088)

Ne4-d6
Now in MakeChessMove() at Time0000000020906411, nChsProgNr = 1, ChsStrct->PlyPtr = 75

Now in MakeChessMove() at Time0000000020906411, nChsProgNr = 0, ChsStrct->PlyPtr = 75

Now in DrawGraphics() at Time0000000020906411

Now in DrawGraphics() at Time0000000020906411

Memory: 72 MB + 215 MB (1864 MB free)
CPU Load: 48% + 44%
Total Time Elapsed = 00:03:56
MoveNr. = 38, SideToMove = white.
46 moves to 50-Move-Rule.
Last Move = e4d6 = Nd6 = Ne4-d6
Expected Move = c2b2
Now in CheckForEndOfGame() at Time0000000020906427

Now in MakeTimeControlString() at Time0000000020906427

Now in ParcelMove() at Time0000000020906427

CASTLING_MOVE: nChessVariant = 1, for EngName = Nebula 2.0

SendToEng1Time 0000000020906427 : Eng01 (Nebula 2.0) -> position startpos moves g1f3 g8f6 e2e3 d7d5 c2c4 b8c6 c4d5 d8d5 b1c3 d5h5 d2d4 c8g4 f1e2 e7e6 h2h3 f8d6 d1a4 e8g8 h1g1 g4f3 e2f3 h5g6 f3c6 b7c6 a4c6 a8b8 b2b3 b8b6 c6f3 e6e5 c3a4 d6b4 c1d2 b4d2 e1d2 b6d6 a4b2 e5d4 d2c1 d4d3 b2c4 d6d5 a1b1 f6e4 b1b2 f8d8 g1d1 f7f5 g2g4 g6f6 g4f5 d3d2 c1c2 e4g5 f3g4 h7h5 g4f4 g5h3 f4f3 h3g5 f3f4 d5f5 f4c7 f5d5 f2f3 f6f5 c2c3 f5f3 b2b1 g5e4 c3c2 f3f6 b1b2 f6g6 b2b1 e4d6
.
Now in SendTimeControlString() at Time0000000020906427

SideToMove=w, nInterval = 1, nmoves = 0, imoves = 38, movestogo = 40, wtime = 120000, btime = 120000, winc = 0, binc = 0, PlyPtr = 76, TimeLeft = 237 ms
SendToEng1Time 0000000020906427 : Eng01 (Nebula 2.0) -> go movestogo 2 wtime 237 btime 8308
.
SideToMove = White.
SendToEng9Time 0000000020906427 : Eng09 (TimeLagEngine) -> LagTo 0000000020906427
.
Extra time for Nebula 2.0 = 0 milliseconds.
==========================================================================================================================
Scheduling GameMoveTimerEvent() for Nebula 2.0 at 0000000020906427.
Eng01 (Nebula 2.0) <- Pipe01Time 0000000020906676
Exact move time for Nebula 2.0
Eng01 (Nebula 2.0) <- info depth 1 score cp -236 time 0 nodes 15 nps 15000 seldepth 5 pv e3e4 g6e4 c2b2 d6c4 b3c4
Eng01 (Nebula 2.0) <- info depth 2 score cp -236 time 0 nodes 91 nps 91000 seldepth 9 pv e3e4 g6e4 c2b2 d6c4 b3c4
Eng01 (Nebula 2.0) <- info depth 3 score cp -252 upperbound time 0 nodes 956 nps 956000 seldepth 13 pv e3e4 g6e4 c2b2 d6c4 b3c4
Eng01 (Nebula 2.0) <- info depth 3 score cp -268 upperbound time 0 nodes 1140 nps 1140000 seldepth 13 pv e3e4 g6e4 c2b2 d6c4 b3c4
Eng01 (Nebula 2.0) <- info depth 3 score cp -283 time 0 nodes 1529 nps 1529000 seldepth 13 pv e3e4 d8c8 c7a7 g6e4 c2b2 d6c4 b3c4 c8c4
Eng01 (Nebula 2.0) <- info depth 4 score cp -391 upperbound time 0 nodes 1546 nps 1546000 seldepth 6 pv e3e4 d8c8 c7a7 g6e4 c2b2 d6c4 b3c4 c8c4
Eng01 (Nebula 2.0) <- info depth 4 score cp -391 time 0 nodes 1955 nps 1955000 seldepth 11 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1
Eng01 (Nebula 2.0) <- info depth 5 score cp -391 time 0 nodes 3035 nps 3035000 seldepth 12 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -436 upperbound time 0 nodes 3372 nps 3372000 seldepth 11 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -453 upperbound time 0 nodes 3801 nps 3801000 seldepth 14 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -491 upperbound time 0 nodes 4269 nps 4269000 seldepth 15 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -557 upperbound time 0 nodes 5027 nps 5027000 seldepth 20 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1
Eng01 (Nebula 2.0) <- info depth 6 seldepth 6
Eng01 (Nebula 2.0) <- info depth 6 score cp -634 time 0 nodes 9271 nps 9271000 seldepth 23 pv e3e4 g6e4 c2b2 e4d4 b2c2 d6e4 b1a1 d4c3 c2b1 e4f2 d1d2 d5d2
Eng01 (Nebula 2.0) <- info depth 6 score cp -627 time 0 nodes 9350 nps 9350000 seldepth 23 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4
Eng01 (Nebula 2.0) <- info depth 7 seldepth 7
Eng01 (Nebula 2.0) <- info depth 7 score cp -512 lowerbound time 0 nodes 9360 nps 9360000 seldepth 7 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4 e3d4
Eng01 (Nebula 2.0) <- info depth 7 seldepth 7
Eng01 (Nebula 2.0) <- info depth 7 score cp -627 time 0 nodes 9438 nps 9438000 seldepth 7 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4 e3d4
Eng01 (Nebula 2.0) <- info depth 8 seldepth 8
Eng01 (Nebula 2.0) <- info depth 8 score cp -512 lowerbound time 0 nodes 12137 nps 12137000 seldepth 8 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4 e3d4 f6f5
Eng01 (Nebula 2.0) <- info depth 8 seldepth 8
Eng01 (Nebula 2.0) <- info depth 8 score cp -627 time 0 nodes 12215 nps 12215000 seldepth 8 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4 e3d4 f6f5
Eng01 (Nebula 2.0) <- info depth 9 seldepth 9
Eng01 (Nebula 2.0) <- info depth 9 score cp -627 time 0 nodes 12388 nps 12388000 seldepth 9 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4 e3d4 f6f5 c2d2
Eng01 (Nebula 2.0) <- info depth 10 seldepth 10
Eng01 (Nebula 2.0) <- info depth 10 score cp -627 time 31 nodes 130336 nps 4204387 seldepth 24 pv c2b2 g6f6 b2c2 d6b5 c7a5 b5d4 e3d4 f6f5 c2d2 d5a5
Eng01 (Nebula 2.0) <- bestmove c2b2
Cancelling GameMoveTimerEvent() for Nebula 2.0 at 0000000020907097.
nChessVariant(0) = 1, bestmove.
==========================================================================================================================
Current position (Ply 76) : 3r2k1/p1Q3p1/3n2q1/3r3p/2N5/1P2P3/P1Kp4/1R1R4 w - - 8 39 = 3r2k1/p1Q3p1/3n2q1/3r3p/2N5/1P2P3/P1Kp4/1R1R4 w - - 8 39
System time lag per move = 384 milliseconds
Eng01 (Nebula 2.0) thought for 249 milliseconds, time left = -12 milliseconds
Almost in ParcelMove(from Nebula 2.0) at Time0000000020907097

DetailsOfMove(bestmove c2b2 = Kc2-b2 = Kb2 = Kc2-b2) -> nSide = White, nPieceNr = King, nFrom = C2, nTo = B2, nCapturedNr = NoPiece, promo = NoPiece, ep = A1, nFlags = 40, (Move = 400000000B0C0801 == 4611686018612725761)

Nebula 2.0 loses on time in ParcelMove().
Now in CheckForEndOfGame() at Time0000000020907097

Now in EndTheGame() at Time0000000020907097

0-1
.

0-1
SendToEng1Time 0000000020907113 : Eng01 (Nebula 2.0) -> stop
.
SendToEng1Time 0000000020907113 : Eng01 (Nebula 2.0) -> quit
.
SendToEng2Time 0000000020907113 : Eng02 (ruy_sse42) -> stop
.
SendToEng2Time 0000000020907113 : Eng02 (ruy_sse42) -> quit
.
Now in KillEngines() at Time0000000020908127

Now in PutResultInSchedule() at Time0000000020908127

Now in SavePGN() at Time0000000020908127

0-1
.

Now in PutResultInStringList() at Time0000000020908158

Now in EndChildProcess() at Time0000000020908158 to kill Nebula 2.0.

!!! Disk Space !!! (229187907584 Bytes free)
DestroyChildProcess(Eng01 = Nebula 2.0) is already dead.
Now in EndChildProcess() at Time0000000020908158 to kill ruy_sse42.

!!! Disk Space !!! (229187907584 Bytes free)
DestroyChildProcess(Eng02 = ruy_sse42) is already dead.
Now in EndChildProcess() at Time0000000020908158 to kill TimeLagEngine.

!!! Disk Space !!! (229187907584 Bytes free)
SendToEng9Time 0000000020908268 : Eng09 (TimeLagEngine) -> stop
.
SendToEng9Time 0000000020908268 : Eng09 (TimeLagEngine) -> quit
.
DestroyChildProcess(Eng09 = TimeLagEngine), soft termination, trial 1.
Now in EraseInputBuffers(TimeLagEngine).
Now in EraseInputBuffers(Nebula 2.0).
Now in EraseInputBuffers(ruy_sse42).
Now in SaveDeleteDebugFiles() at Time0000000020912277
User avatar
Guenther
Posts: 4611
Joined: Wed Oct 01, 2008 6:33 am
Location: Regensburg, Germany
Full name: Guenther Simon

Re: Nebula 2.0 POPCNT x64 time forfeits

Post by Guenther »

Norbert Raimund Leisner wrote:game 19 debug

Code: Select all

Current position &#40;Ply 78&#41; &#58; 6k1/2n2p1p/3p3Q/p3rp2/6P1/P7/6KP/8 w - - 0 40 = 6k1/2n2p1p/3p3Q/p3rp2/6P1/P7/6KP/8 w - - 0 40
System time lag per move = 271 milliseconds
Eng01 &#40;Arminius 2017-01-01&#41; thought for 1638 milliseconds, time left = 3200 milliseconds
Almost in ParcelMove&#40;from Arminius 2017-01-01&#41; at Time0000000015537902

DetailsOfMove&#40;CAPTURE_MOVE&#58; bestmove h6d6 ponder e5e2 = Qh6xd6 = Qxd6 = Qh6-d6&#41; -> nSide = White, nPieceNr = Queen, nFrom = H6, nTo = D6, nCapturedNr = Pawn, promo = NoPiece, ep = A1, nFlags = 40, &#40;Move = 4000000135390701 == 4611686023615284993&#41;

Qh6xd6
Now in MakeChessMove&#40;) at Time0000000015537902, nChsProgNr = 0, ChsStrct->PlyPtr = 78

Now in MakeChessMove&#40;) at Time0000000015537902, nChsProgNr = 1, ChsStrct->PlyPtr = 78

Now in DrawGraphics&#40;) at Time0000000015537902

Now in DrawGraphics&#40;) at Time0000000015537902

Memory&#58; 71 MB + 72 MB &#40;2105 MB free&#41;
CPU Load&#58; 46% + 47%
Total Time Elapsed = 00&#58;04&#58;01
MoveNr. = 39, SideToMove = black.
50 moves to 50-Move-Rule.
Last Move = h6d6 = Qxd6 = Qh6-d6
Expected Move = e5e2
Now in CheckForEndOfGame&#40;) at Time0000000015537917

Now in MakeTimeControlString&#40;) at Time0000000015537917

Now in ParcelMove&#40;) at Time0000000015537917

CASTLING_MOVE&#58; nChessVariant = 1, for EngName = Nebula 2.0

CASTLING_MOVE&#58; nChessVariant = 1, for EngName = Nebula 2.0

SendToEng2Time 0000000015537917 &#58; Eng02 &#40;Nebula 2.0&#41; -> position startpos moves g2g3 e7e5 c2c4 f8c5 f1g2 g8e7 a2a3 e8g8 b2b4 c5d4 a1a2 d7d6 e2e3 d4b6 b1c3 a7a5 b4b5 b8d7 d2d4 b6a7 g1f3 e5d4 e3d4 d7b6 f3d2 e7f5 c3e2 d8f6 d2e4 f6e7 d1d3 c7c6 b5c6 b7c6 e4c3 e7d7 d4d5 c8a6 d5c6 d7e6 d3b1 a6c4 a2d2 f8e8 e1g1 g7g6 c1b2 f5e3 e2f4 e3f1 f4e6 f1d2 b1d1 c4e6 d1d2 b6c4 d2c1 e6f5 c6c7 c4b2 g2a8 b2d3 c1g5 a7f2 g1g2 f2b6 a8e4 b6c7 e4f5 e8e5 g3g4 d3c5 g5h6 g6f5 c3b5 c5e6 b5c7 e6c7 h6d6
.
Now in SendTimeControlString&#40;) at Time0000000015537933

SideToMove=b, nInterval = 1, nmoves = 0, imoves = 39, movestogo = 40, wtime = 120000, btime = 120000, winc = 0, binc = 0, PlyPtr = 79, TimeLeft = 906 ms
White's TimeLeft = 3200 ms, hiding 1638 ms from Black movestogo 1

SendToEng2Time 0000000015537933 &#58; Eng02 &#40;Nebula 2.0&#41; -> go movestogo 1 wtime 4838 btime 906
.
SideToMove = Black.
SendToEng9Time 0000000015537933 &#58; Eng09 &#40;TimeLagEngine&#41; -> LagTo 0000000015537933
.
Extra time for Nebula 2.0 = 0 milliseconds.
==========================================================================================================================
Scheduling GameMoveTimerEvent&#40;) for Nebula 2.0 at 0000000015537933.
Eng02 &#40;Nebula 2.0&#41; <- info depth 1 score cp -451 time 0 nodes 7 nps 7000 seldepth 3 pv f5g4 d6e5
Eng02 &#40;Nebula 2.0&#41; <- info depth 1 score cp -221 time 0 nodes 16 nps 16000 seldepth 3 pv e5e2 g2f3 c7e8
Eng02 &#40;Nebula 2.0&#41; <- info depth 2 score cp -221 time 0 nodes 197 nps 197000 seldepth 2 pv e5e2 g2f3 c7e8
Eng02 &#40;Nebula 2.0&#41; <- info depth 3 score cp -221 time 0 nodes 308 nps 308000 seldepth 3 pv e5e2 g2f3 c7e8
Eng02 &#40;Nebula 2.0&#41; <- info depth 4 score cp -221 time 0 nodes 506 nps 506000 seldepth 4 pv e5e2 g2f3 c7e8 d6d5
Eng02 &#40;Nebula 2.0&#41; <- info depth 5 score cp -221 time 0 nodes 1114 nps 1114000 seldepth 5 pv e5e2 g2f3 c7e8 d6d5 e2h2
Eng02 &#40;Nebula 2.0&#41; <- info depth 6 seldepth 6
Eng02 &#40;Nebula 2.0&#41; <- info depth 6 score cp -186 lowerbound time 1 nodes 2608 nps 2608000 seldepth 6 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5
Eng02 &#40;Nebula 2.0&#41; <- info depth 6 seldepth 6
Eng02 &#40;Nebula 2.0&#41; <- info depth 6 score cp -221 time 1 nodes 2624 nps 2624000 seldepth 6 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5
Eng02 &#40;Nebula 2.0&#41; <- info depth 7 seldepth 7
Eng02 &#40;Nebula 2.0&#41; <- info depth 7 score cp -186 lowerbound time 1 nodes 4804 nps 4804000 seldepth 7 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3
Eng02 &#40;Nebula 2.0&#41; <- info depth 7 seldepth 7
Eng02 &#40;Nebula 2.0&#41; <- info depth 7 score cp -221 time 1 nodes 4820 nps 4820000 seldepth 7 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3
WM_TimeLagEngine&#40;) says TimeLagReturn 0000000015538183 SystemLag LagTo 0000000015537933 0000000015538058
WM_TimeLagEngine&#40;) &#58; To = 125 ms, From = 125 ms, Total = 250 ms
Eng02 &#40;Nebula 2.0&#41; <- info depth 8 seldepth 8
Eng02 &#40;Nebula 2.0&#41; <- info depth 8 score cp -186 lowerbound time 3 nodes 9676 nps 3225333 seldepth 8 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2
Eng02 &#40;Nebula 2.0&#41; <- info depth 8 seldepth 8
Eng02 &#40;Nebula 2.0&#41; <- info depth 8 score cp -221 time 3 nodes 9692 nps 3230666 seldepth 8 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2
Eng02 &#40;Nebula 2.0&#41; <- info depth 9 seldepth 9
Eng02 &#40;Nebula 2.0&#41; <- info depth 9 score cp -186 lowerbound time 4 nodes 16999 nps 4249750 seldepth 9 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4
Eng02 &#40;Nebula 2.0&#41; <- info depth 9 seldepth 9
Eng02 &#40;Nebula 2.0&#41; <- info depth 9 score cp -221 time 4 nodes 17015 nps 4253750 seldepth 9 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4
Eng02 &#40;Nebula 2.0&#41; <- info depth 10 seldepth 10
Eng02 &#40;Nebula 2.0&#41; <- info depth 10 score cp -186 lowerbound time 7 nodes 30667 nps 4381000 seldepth 10 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8
Eng02 &#40;Nebula 2.0&#41; <- info depth 10 seldepth 10
Eng02 &#40;Nebula 2.0&#41; <- info depth 10 score cp -221 time 7 nodes 30691 nps 4384428 seldepth 10 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8
Eng02 &#40;Nebula 2.0&#41; <- info depth 11 seldepth 11
Eng02 &#40;Nebula 2.0&#41; <- info depth 11 score cp -186 lowerbound time 14 nodes 57950 nps 4139285 seldepth 11 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8 g8g7
Eng02 &#40;Nebula 2.0&#41; <- info depth 11 seldepth 11
Eng02 &#40;Nebula 2.0&#41; <- info depth 11 score cp -221 time 14 nodes 57974 nps 4141000 seldepth 11 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8 g8g7
Eng02 &#40;Nebula 2.0&#41; <- info depth 12 seldepth 12
Eng02 &#40;Nebula 2.0&#41; <- info depth 12 score cp -221 time 30 nodes 181647 nps 6054900 seldepth 24 pv e5e2 g2f3 c7e8 d6d5 e2h2 d5e5 h2h3 f3g2 f5g4 e5e8 g8g7 e8e5
Eng02 &#40;Nebula 2.0&#41; <- info depth 13 seldepth 13
Eng02 &#40;Nebula 2.0&#41; <- Pipe02Time 0000000015538947
Exact move time for Nebula 2.0
Eng02 &#40;Nebula 2.0&#41; <- bestmove e5e2
Cancelling GameMoveTimerEvent&#40;) for Nebula 2.0 at 0000000015538947.
nChessVariant&#40;1&#41; = 1, bestmove.
==========================================================================================================================
Current position &#40;Ply 79&#41; &#58; 6k1/2n2p1p/3Q4/p3rp2/6P1/P7/6KP/8 b - - 0 40 = 6k1/2n2p1p/3Q4/p3rp2/6P1/P7/6KP/8 b - - 0 40
System time lag per move = 270 milliseconds
Eng02 &#40;Nebula 2.0&#41; thought for 1014 milliseconds, time left = -108 milliseconds
Almost in ParcelMove&#40;from Nebula 2.0&#41; at Time0000000015538947

DetailsOfMove&#40;bestmove e5e2 = Re5-e2 = Re2 = Re5-e2&#41; -> nSide = Black, nPieceNr = Rook, nFrom = E5, nTo = E2, nCapturedNr = NoPiece, promo = NoPiece, ep = A1, nFlags = 40, &#40;Move = 400000000E2C0400 == 4611686018665153536&#41;

Nebula 2.0 loses on time in ParcelMove&#40;).
Now in CheckForEndOfGame&#40;) at Time0000000015538947

Now in EndTheGame&#40;) at Time0000000015538963

1-0
.

1-0
SendToEng2Time 0000000015538963 &#58; Eng02 &#40;Nebula 2.0&#41; -> stop
.
SendToEng2Time 0000000015538963 &#58; Eng02 &#40;Nebula 2.0&#41; -> quit
.
SendToEng1Time 0000000015538963 &#58; Eng01 &#40;Arminius 2017-01-01&#41; -> stop
.
SendToEng1Time 0000000015538978 &#58; Eng01 &#40;Arminius 2017-01-01&#41; -> quit
.
Now in KillEngines&#40;) at Time0000000015539977

Now in PutResultInSchedule&#40;) at Time0000000015539977

Now in SavePGN&#40;) at Time0000000015539977

1-0
.

Now in PutResultInStringList&#40;) at Time0000000015539992

Now in EndChildProcess&#40;) at Time0000000015540008 to kill Nebula 2.0.

!!! Disk Space !!! &#40;229232275456 Bytes free&#41;
DestroyChildProcess&#40;Eng02 = Nebula 2.0&#41; is already dead.
Now in EndChildProcess&#40;) at Time0000000015540008 to kill Arminius 2017-01-01.

!!! Disk Space !!! &#40;229232275456 Bytes free&#41;
DestroyChildProcess&#40;Eng01 = Arminius 2017-01-01&#41; is already dead.
Now in EndChildProcess&#40;) at Time0000000015540008 to kill TimeLagEngine.

!!! Disk Space !!! &#40;229232275456 Bytes free&#41;
SendToEng9Time 0000000015540117 &#58; Eng09 &#40;TimeLagEngine&#41; -> stop
.
SendToEng9Time 0000000015540117 &#58; Eng09 &#40;TimeLagEngine&#41; -> quit
.
DestroyChildProcess&#40;Eng09 = TimeLagEngine&#41;, soft termination, trial 1.
Now in EraseInputBuffers&#40;TimeLagEngine&#41;.
Now in EraseInputBuffers&#40;Nebula 2.0&#41;.
Now in EraseInputBuffers&#40;Arminius 2017-01-01&#41;.
Now in SaveDeleteDebugFiles&#40;) at Time0000000015544126
Nebula used 108ms more than allowed for move 40.
I don't know though, if your 'system time lag', which seems unusually high to me and is around 270ms
according to the debug is the problem here, because I don't know how ChessGUI handles that.

Maybe Graham can say something on this, or at least can tell numbers he
gets normally in a ChessGUI debug for 'system time lag'.

Guenther
https://rwbc-chess.de

trollwatch:
Talkchess nowadays is a joke - it is full of trolls/idiots/people stuck in the pleistocene > 80% of the posts fall into this category...
Norbert Raimund Leisner
Posts: 1643
Joined: Tue May 20, 2008 4:57 pm
Location: Augsburg - Germany

Re: Nebula 2.0 POPCNT x64 time forfeits

Post by Norbert Raimund Leisner »

TC overstep margin" > "Preferences/GUI_1".

Adjust value for all tournaments, perhaps a modification for the current match

ChessGUI http://www.chess.hylogic.de/ updates many program windows continuously, that is the reason for the phenomenon "increase of time lag"

Norbert
Modern Times
Posts: 3553
Joined: Thu Jun 07, 2012 11:02 pm

Re: Nebula 2.0 POPCNT x64 time forfeits

Post by Modern Times »

Try 500ms perhaps.