search

jromang / picochess

GNU General Public License v3.0
74 stars 56 forks source link

Computer's clock getting set back #108

Closed djdekker closed 9 years ago

djdekker commented 9 years ago

The following video shows a problem with the clock. It's a 1 minute blitz game against Stockfish on a Bluetooth DGT Board with DGT 3000 clock and Picochess 0.44.

http://youtube.com/watch?v=-ltJwVlD8aQ

At 1:23 of this video you can see White playing 16. Qe3. The clock is displaying the correct thinking time: 0.20 for White and 0.33 Black.

At 1:43 Black announces its move 16... Ne1+. The clock now displays 0.20 for White and 0.15 for Black. White now plays 17. Kg1 promptly. Now the clock displays 0.19 for White and 0.25 for Black! So Black suddenly has got 10 seconds extra time?? Or was there merely a delay in displaying 16... Ne1+ on the clock?

Next, supposedly related, problem: the position reached after 17. Kg1 is a simple mate in 1. Still, the video shows Picochess taking no less than 18 seconds to announce Black's move 17... Qg2#. I'm quite certain that Stockfish 6 does not need that much time to see this. (Note: I actually once won a game because of such a long delay, because the engine's flag fell before the checkmating move appeared on the clock!)

I suspect that Picochess is not always sending the engine moves to the clock immediately, i.e., as soon as the engine has sent them to Picochess.

djdekker commented 9 years ago

Picochess 0.44 also needs a lot of time to display the best move for Black after 1. f3 e5 2. g4. It's a mate in one (of course 2... Qh4#).

2015-07-03 17:22:11.146 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << uci
2015-07-03 17:22:11.150 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> Stockfish 150215 by Tord Romstad, Marco Costalba and Joona Kiiski
2015-07-03 17:22:11.813 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> id name Stockfish 150215
2015-07-03 17:22:11.815 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> id author Tord Romstad, Marco Costalba and Joona Kiiski
2015-07-03 17:22:11.816 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> 
2015-07-03 17:22:11.817 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Write Debug Log type check default false
2015-07-03 17:22:11.818 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Contempt type spin default 0 min -100 max 100
2015-07-03 17:22:11.818 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Min Split Depth type spin default 0 min 0 max 12
2015-07-03 17:22:11.819 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Threads type spin default 1 min 1 max 128
2015-07-03 17:22:11.820 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Hash type spin default 16 min 1 max 2048
2015-07-03 17:22:11.821 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Clear Hash type button
2015-07-03 17:22:11.822 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Ponder type check default true
2015-07-03 17:22:11.822 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name MultiPV type spin default 1 min 1 max 500
2015-07-03 17:22:11.823 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Skill Level type spin default 20 min 0 max 20
2015-07-03 17:22:11.824 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Move Overhead type spin default 30 min 0 max 5000
2015-07-03 17:22:11.825 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Minimum Thinking Time type spin default 20 min 0 max 5000
2015-07-03 17:22:11.826 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Slow Mover type spin default 80 min 10 max 1000
2015-07-03 17:22:11.826 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name UCI_Chess960 type check default false
2015-07-03 17:22:11.827 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name SyzygyPath type string default <empty>
2015-07-03 17:22:11.828 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name SyzygyProbeDepth type spin default 1 min 1 max 100
2015-07-03 17:22:11.829 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name Syzygy50MoveRule type check default true
2015-07-03 17:22:11.831 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> option name SyzygyProbeLimit type spin default 6 min 0 max 6
2015-07-03 17:22:11.831 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> uciok
2015-07-03 17:22:11.833 DEBUG picochess - main: Loaded engine [Stockfish 150215]
2015-07-03 17:22:11.836 DEBUG picochess - main: Supported options [OptionMap({'Move Overhead': Option(name='Move Overhead', type='spin', default=30, min=0, max=5000, var=[]), 'Skill Level': Option(name='Skill Level', type='spin', default=20, min=0, max=20, var=[]), 'SyzygyProbeDepth': Option(name='SyzygyProbeDepth', type='spin', default=1, min=1, max=100, var=[]), 'Contempt': Option(name='Contempt', type='spin', default=0, min=-100, max=100, var=[]), 'MultiPV': Option(name='MultiPV', type='spin', default=1, min=1, max=500, var=[]), 'Ponder': Option(name='Ponder', type='check', default=True, min=None, max=None, var=[]), 'SyzygyProbeLimit': Option(name='SyzygyProbeLimit', type='spin', default=6, min=0, max=6, var=[]), 'Syzygy50MoveRule': Option(name='Syzygy50MoveRule', type='check', default=True, min=None, max=None, var=[]), 'Minimum Thinking Time': Option(name='Minimum Thinking Time', type='spin', default=20, min=0, max=5000, var=[]), 'Threads': Option(name='Threads', type='spin', default=1, min=1, max=128, var=[]), 'Clear Hash': Option(name='Clear Hash', type='button', default='', min=None, max=None, var=[]), 'Write Debug Log': Option(name='Write Debug Log', type='check', default=False, min=None, max=None, var=[]), 'Min Split Depth': Option(name='Min Split Depth', type='spin', default=0, min=0, max=12, var=[]), 'UCI_Chess960': Option(name='UCI_Chess960', type='check', default=False, min=None, max=None, var=[]), 'Slow Mover': Option(name='Slow Mover', type='spin', default=80, min=10, max=1000, var=[]), 'SyzygyPath': Option(name='SyzygyPath', type='string', default='<empty>', min=None, max=None, var=[]), 'Hash': Option(name='Hash', type='spin', default=16, min=1, max=2048, var=[])})]
2015-07-03 17:22:11.839 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << setoption name Threads value 1
2015-07-03 17:22:11.840 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << setoption name Hash value 64
2015-07-03 17:22:11.840 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << setoption name Threads  value  4
2015-07-03 17:22:11.841 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << isready
2015-07-03 17:22:11.867 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> readyok
2015-07-03 17:22:11.869 DEBUG picochess - main: Starting picochess with DGT board on [/dev/rfcomm0]
2015-07-03 17:22:11.871 DEBUG selector_events - __init__: Using selector: EpollSelector
2015-07-03 17:22:12.878 DEBUG picochess - main: ChessTalker disabled
2015-07-03 17:22:12.982 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_VERSION]
2015-07-03 17:22:13.137 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_VERSION]
2015-07-03 17:22:13.241 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:13.244 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_VERSION], length:2
2015-07-03 17:22:13.245 DEBUG dgt - read_message: DGT board version 3.10
2015-07-03 17:22:13.349 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:13.350 DEBUG dgt - read_message: Clock ACK (16, 9, 32, 0)
2015-07-03 17:22:13.351 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:13.403 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:13.405 DEBUG dgt - read_message: 
rnbqkbnr
pppppppp
........
........
........
........
PPPPPPPP
RNBQKBNR
2015-07-03 17:22:13.406 DEBUG dgt - read_message: rnbqkbnr/pppppppp/8/8/8/8/PPPPPPPP/RNBQKBNR
2015-07-03 17:22:13.406 DEBUG dgt - read_message: New game
2015-07-03 17:22:13.408 DEBUG picochess - main: Received event in event loop : Event.NEW_GAME
2015-07-03 17:22:13.471 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << stop
2015-07-03 17:22:13.472 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << isready
2015-07-03 17:22:13.473 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> readyok
2015-07-03 17:22:13.809 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:13.811 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:14.615 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:15.723 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:15.977 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:15.979 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:16.382 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:17.594 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:17.597 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:17.699 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:17.702 DEBUG dgt - read_message: 
rnbqkbnr
pppppppp
........
........
Q.......
........
PPPPPPPP
RNBQKBNR
2015-07-03 17:22:17.703 DEBUG dgt - read_message: rnbqkbnr/pppppppp/8/8/Q7/8/PPPPPPPP/RNBQKBNR
2015-07-03 17:22:17.705 DEBUG dgt - read_message: Setting time control ClockMode.BLITZ
2015-07-03 17:22:17.710 DEBUG picochess - main: Received event in event loop : Event.SET_TIME_CONTROL
2015-07-03 17:22:17.911 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:18.165 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:18.167 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:18.571 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:18.573 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:18.676 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:18.678 DEBUG dgt - read_message: 
rnbqkbnr
pppppppp
........
........
........
........
PPPPPPPP
RNBQKBNR
2015-07-03 17:22:18.679 DEBUG dgt - read_message: rnbqkbnr/pppppppp/8/8/8/8/PPPPPPPP/RNBQKBNR
2015-07-03 17:22:18.680 DEBUG dgt - read_message: New game
2015-07-03 17:22:18.682 DEBUG picochess - main: Received event in event loop : Event.NEW_GAME
2015-07-03 17:22:18.777 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << stop
2015-07-03 17:22:18.778 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << isready
2015-07-03 17:22:18.780 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> readyok
2015-07-03 17:22:18.983 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:19.788 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:19.791 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:19.893 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:19.895 DEBUG dgt - read_message: 
rnbqkbnr
pppppppp
........
........
........
........
PPPPP.PP
RNBQKBNR
2015-07-03 17:22:19.897 DEBUG dgt - read_message: rnbqkbnr/pppppppp/8/8/8/8/PPPPP1PP/RNBQKBNR
2015-07-03 17:22:19.898 DEBUG dgt - read_message: Fen
2015-07-03 17:22:20.301 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:20.303 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:20.406 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:20.408 DEBUG dgt - read_message: 
rnbqkbnr
pppppppp
........
........
........
.....P..
PPPPP.PP
RNBQKBNR
2015-07-03 17:22:20.410 DEBUG dgt - read_message: rnbqkbnr/pppppppp/8/8/8/5P2/PPPPP1PP/RNBQKBNR
2015-07-03 17:22:20.411 DEBUG dgt - read_message: Fen
2015-07-03 17:22:20.783 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:20.794 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:20.805 DEBUG picochess - main: Received event in event loop : Event.USER_MOVE
2015-07-03 17:22:20.808 DEBUG picochess - main: User move [f2f3]
2015-07-03 17:22:20.872 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << position startpos moves f2f3
2015-07-03 17:22:20.875 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << isready
2015-07-03 17:22:20.876 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> readyok
2015-07-03 17:22:20.881 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << go wtime 60000 btime 60000
2015-07-03 17:22:20.889 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 1 seldepth 1 multipv 1 score cp 94 nodes 21 nps 3000 tbhits 0 time 7 pv e7e5
2015-07-03 17:22:20.908 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 2 seldepth 2 multipv 1 score cp 97 nodes 61 nps 7625 tbhits 0 time 8 pv e7e5 a2a3
2015-07-03 17:22:20.930 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 3 seldepth 3 multipv 1 score cp 89 nodes 200 nps 15384 tbhits 0 time 13 pv e7e6 d2d3 d7d5
2015-07-03 17:22:20.954 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 4 seldepth 4 multipv 1 score cp 75 nodes 464 nps 23200 tbhits 0 time 20 pv e7e6 e2e3 d7d5 a2a3
2015-07-03 17:22:20.982 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 5 seldepth 6 multipv 1 score cp 80 nodes 3047 nps 53456 tbhits 0 time 57 pv b8c6 e2e4 d7d5 d2d4 d5e4
2015-07-03 17:22:21.17 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 6 seldepth 6 multipv 1 score cp 65 nodes 5373 nps 60370 tbhits 0 time 89 pv d7d5 e2e4 e7e5 g1e2 b8c6 d2d3
2015-07-03 17:22:21.32 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:21.54 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 7 seldepth 7 multipv 1 score cp 44 nodes 8336 nps 68327 tbhits 0 time 122 pv d7d5 e2e4 b8c6 f1b5 e7e5 b1c3 d5d4
2015-07-03 17:22:21.88 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 8 seldepth 9 multipv 1 score cp 60 nodes 13590 nps 75500 tbhits 0 time 180 pv d7d5 e2e4 e7e5 e4d5 g8f6 d1e2 d8d5 b1c3
2015-07-03 17:22:21.203 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:21.212 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 9 seldepth 11 multipv 1 score cp 55 nodes 36577 nps 111176 tbhits 0 time 329 pv e7e5 b1c3 d7d5 e2e3 d5d4 e3d4 e5d4 f1b5 c7c6 d1e2 d8e7
2015-07-03 17:22:21.275 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 10 seldepth 14 multipv 1 score cp 56 nodes 47748 nps 121806 tbhits 0 time 392 pv e7e5 e2e4 d7d5 e4d5 g8f6 d2d4 f6d5 d4e5 f8c5 b1c3
2015-07-03 17:22:21.359 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_SETNRUN]
2015-07-03 17:22:21.473 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 11 seldepth 14 multipv 1 score cp 39 nodes 98858 nps 167555 tbhits 0 time 590 pv e7e5 e2e4 d7d5 d2d4 d5e4 d4e5 d8d1 e1d1 f8c5 b1c3 e4e3 g1e2
2015-07-03 17:22:21.518 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_END]
2015-07-03 17:22:21.672 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:21.716 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 12 seldepth 17 multipv 1 score cp 44 nodes 179069 nps 214968 tbhits 0 time 833 pv e7e5 b1c3 d7d5 d2d4 b8c6 e2e3 e5d4 e3d4 d8h4 g2g3 h4e7 g1e2 g8f6 a2a3
2015-07-03 17:22:22.61 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 13 seldepth 17 multipv 1 score cp 50 nodes 291487 nps 247232 hashfull 31 tbhits 0 time 1179 pv e7e5 e2e4 b8c6 b1c3 f8c5 f3f4 d7d6 g1f3 a7a6 c3a4 c5a7 f4e5 d6e5
2015-07-03 17:22:22.103 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> bestmove e7e5 ponder e2e4
2015-07-03 17:22:22.108 DEBUG picochess - main: Received event in event loop : Event.USER_MOVE
2015-07-03 17:22:22.109 DEBUG picochess - main: User move [f2f3]
2015-07-03 17:22:22.110 WARNING picochess - main: Illegal move [f2f3]
2015-07-03 17:22:22.111 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.113 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.115 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.117 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.119 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.121 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.123 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.125 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.127 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.129 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.131 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.133 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.135 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.137 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.140 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.141 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.144 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.145 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.148 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.149 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.152 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.153 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.156 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.157 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.160 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:22.161 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:22.164 DEBUG picochess - main: Received event in event loop : Event.BEST_MOVE
2015-07-03 17:22:22.590 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:22.591 DEBUG dgt - read_message: Clock ACK (16, 3, 0, 0)
2015-07-03 17:22:23.402 INFO dgt - run: DGT SEND BEST MOVE:e7e5
2015-07-03 17:22:23.410 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:23.412 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_SETNRUN]
2015-07-03 17:22:23.564 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:23.916 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:23.918 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:24.320 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:25.628 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:25.630 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:25.733 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:25.735 DEBUG dgt - read_message: 
rnbqkbnr
pppp.ppp
........
........
........
.....P..
PPPPP.PP
RNBQKBNR
2015-07-03 17:22:25.737 DEBUG dgt - read_message: rnbqkbnr/pppp1ppp/8/8/8/5P2/PPPPP1PP/RNBQKBNR
2015-07-03 17:22:25.738 DEBUG dgt - read_message: Fen
2015-07-03 17:22:25.739 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:26.41 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:26.43 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:26.146 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:26.148 DEBUG dgt - read_message: 
rnbqkbnr
pppp.ppp
........
....p...
........
.....P..
PPPPP.PP
RNBQKBNR
2015-07-03 17:22:26.150 DEBUG dgt - read_message: rnbqkbnr/pppp1ppp/8/4p3/8/5P2/PPPPP1PP/RNBQKBNR
2015-07-03 17:22:26.150 DEBUG dgt - read_message: Fen
2015-07-03 17:22:26.152 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:26.354 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:26.508 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_SETNRUN]
2015-07-03 17:22:26.561 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:26.563 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_END]
2015-07-03 17:22:26.615 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:26.617 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:26.618 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:26.721 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:26.723 DEBUG dgt - read_message: 
rnbqkbnr
pppp.ppp
........
....p...
........
.....P..
PPPPP..P
RNBQKBNR
2015-07-03 17:22:26.724 DEBUG dgt - read_message: rnbqkbnr/pppp1ppp/8/4p3/8/5P2/PPPPP2P/RNBQKBNR
2015-07-03 17:22:26.725 DEBUG dgt - read_message: Fen
2015-07-03 17:22:26.727 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:27.29 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:27.31 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:27.33 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:27.136 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:27.138 DEBUG dgt - read_message: 
rnbqkbnr
pppp.ppp
........
....p...
......P.
.....P..
PPPPP..P
RNBQKBNR
2015-07-03 17:22:27.139 DEBUG dgt - read_message: rnbqkbnr/pppp1ppp/8/4p3/6P1/5P2/PPPPP2P/RNBQKBNR
2015-07-03 17:22:27.140 DEBUG dgt - read_message: Fen
2015-07-03 17:22:27.142 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:27.151 DEBUG picochess - main: Received event in event loop : Event.USER_MOVE
2015-07-03 17:22:27.152 DEBUG picochess - main: User move [g2g4]
2015-07-03 17:22:27.227 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << position startpos moves f2f3 e7e5 g2g4
2015-07-03 17:22:27.229 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << isready
2015-07-03 17:22:27.230 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> readyok
2015-07-03 17:22:27.233 DEBUG uci - send_line: <PopenProcess at 0x75aee8f0 (pid=2782)> << go wtime 59004 btime 58668
2015-07-03 17:22:27.239 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 1 seldepth 2 multipv 1 score mate 1 nodes 32 nps 6400 tbhits 0 time 5 pv d8h4
2015-07-03 17:22:27.258 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 2 seldepth 2 multipv 1 score mate 1 nodes 63 nps 12600 tbhits 0 time 5 pv d8h4
2015-07-03 17:22:27.276 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 3 seldepth 2 multipv 1 score mate 1 nodes 94 nps 18800 tbhits 0 time 5 pv d8h4
2015-07-03 17:22:27.290 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 4 seldepth 2 multipv 1 score mate 1 nodes 125 nps 10416 tbhits 0 time 12 pv d8h4
2015-07-03 17:22:27.311 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 5 seldepth 2 multipv 1 score mate 1 nodes 156 nps 8666 tbhits 0 time 18 pv d8h4
2015-07-03 17:22:27.323 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 6 seldepth 2 multipv 1 score mate 1 nodes 187 nps 10388 tbhits 0 time 18 pv d8h4
2015-07-03 17:22:27.335 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 7 seldepth 2 multipv 1 score mate 1 nodes 218 nps 11473 tbhits 0 time 19 pv d8h4
2015-07-03 17:22:27.347 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 8 seldepth 2 multipv 1 score mate 1 nodes 249 nps 13105 tbhits 0 time 19 pv d8h4
2015-07-03 17:22:27.358 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:27.360 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 9 seldepth 2 multipv 1 score mate 1 nodes 280 nps 14000 tbhits 0 time 20 pv d8h4
2015-07-03 17:22:27.373 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 10 seldepth 2 multipv 1 score mate 1 nodes 311 nps 15550 tbhits 0 time 20 pv d8h4
2015-07-03 17:22:27.385 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 11 seldepth 2 multipv 1 score mate 1 nodes 342 nps 17100 tbhits 0 time 20 pv d8h4
2015-07-03 17:22:27.397 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 12 seldepth 2 multipv 1 score mate 1 nodes 373 nps 18650 tbhits 0 time 20 pv d8h4
2015-07-03 17:22:27.409 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 13 seldepth 2 multipv 1 score mate 1 nodes 404 nps 19238 tbhits 0 time 21 pv d8h4
2015-07-03 17:22:27.422 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 14 seldepth 2 multipv 1 score mate 1 nodes 435 nps 20714 tbhits 0 time 21 pv d8h4
2015-07-03 17:22:27.434 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 15 seldepth 2 multipv 1 score mate 1 nodes 466 nps 22190 tbhits 0 time 21 pv d8h4
2015-07-03 17:22:27.446 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 16 seldepth 2 multipv 1 score mate 1 nodes 497 nps 22590 tbhits 0 time 22 pv d8h4
2015-07-03 17:22:27.458 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 17 seldepth 2 multipv 1 score mate 1 nodes 528 nps 24000 tbhits 0 time 22 pv d8h4
2015-07-03 17:22:27.470 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 18 seldepth 2 multipv 1 score mate 1 nodes 559 nps 25409 tbhits 0 time 22 pv d8h4
2015-07-03 17:22:27.481 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 19 seldepth 2 multipv 1 score mate 1 nodes 590 nps 25652 tbhits 0 time 23 pv d8h4
2015-07-03 17:22:27.494 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 20 seldepth 2 multipv 1 score mate 1 nodes 621 nps 27000 tbhits 0 time 23 pv d8h4
2015-07-03 17:22:27.505 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 21 seldepth 2 multipv 1 score mate 1 nodes 652 nps 28347 tbhits 0 time 23 pv d8h4
2015-07-03 17:22:27.517 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 22 seldepth 2 multipv 1 score mate 1 nodes 683 nps 24392 tbhits 0 time 28 pv d8h4
2015-07-03 17:22:27.518 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_SETNRUN]
2015-07-03 17:22:27.531 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 23 seldepth 2 multipv 1 score mate 1 nodes 714 nps 24620 tbhits 0 time 29 pv d8h4
2015-07-03 17:22:27.543 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 24 seldepth 2 multipv 1 score mate 1 nodes 745 nps 25689 tbhits 0 time 29 pv d8h4
2015-07-03 17:22:27.555 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 25 seldepth 2 multipv 1 score mate 1 nodes 776 nps 26758 tbhits 0 time 29 pv d8h4
2015-07-03 17:22:27.567 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 26 seldepth 2 multipv 1 score mate 1 nodes 807 nps 27827 tbhits 0 time 29 pv d8h4
2015-07-03 17:22:27.579 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 27 seldepth 2 multipv 1 score mate 1 nodes 838 nps 27933 tbhits 0 time 30 pv d8h4
2015-07-03 17:22:27.592 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 28 seldepth 2 multipv 1 score mate 1 nodes 869 nps 28966 tbhits 0 time 30 pv d8h4
2015-07-03 17:22:27.604 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 29 seldepth 2 multipv 1 score mate 1 nodes 900 nps 30000 tbhits 0 time 30 pv d8h4
2015-07-03 17:22:27.616 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 30 seldepth 2 multipv 1 score mate 1 nodes 931 nps 30032 tbhits 0 time 31 pv d8h4
2015-07-03 17:22:27.628 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 31 seldepth 2 multipv 1 score mate 1 nodes 962 nps 31032 tbhits 0 time 31 pv d8h4
2015-07-03 17:22:27.640 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 32 seldepth 2 multipv 1 score mate 1 nodes 993 nps 32032 tbhits 0 time 31 pv d8h4
2015-07-03 17:22:27.657 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 33 seldepth 2 multipv 1 score mate 1 nodes 1024 nps 32000 tbhits 0 time 32 pv d8h4
2015-07-03 17:22:27.669 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 34 seldepth 2 multipv 1 score mate 1 nodes 1055 nps 32968 tbhits 0 time 32 pv d8h4
2015-07-03 17:22:27.681 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 35 seldepth 2 multipv 1 score mate 1 nodes 1086 nps 33937 tbhits 0 time 32 pv d8h4
2015-07-03 17:22:27.693 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 36 seldepth 2 multipv 1 score mate 1 nodes 1117 nps 33848 tbhits 0 time 33 pv d8h4
2015-07-03 17:22:27.694 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_END]
2015-07-03 17:22:27.707 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 37 seldepth 2 multipv 1 score mate 1 nodes 1148 nps 34787 tbhits 0 time 33 pv d8h4
2015-07-03 17:22:27.719 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 38 seldepth 2 multipv 1 score mate 1 nodes 1179 nps 35727 tbhits 0 time 33 pv d8h4
2015-07-03 17:22:27.731 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 39 seldepth 2 multipv 1 score mate 1 nodes 1210 nps 35588 tbhits 0 time 34 pv d8h4
2015-07-03 17:22:27.743 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 40 seldepth 2 multipv 1 score mate 1 nodes 1241 nps 36500 tbhits 0 time 34 pv d8h4
2015-07-03 17:22:27.755 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 41 seldepth 2 multipv 1 score mate 1 nodes 1272 nps 36342 tbhits 0 time 35 pv d8h4
2015-07-03 17:22:27.767 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 42 seldepth 2 multipv 1 score mate 1 nodes 1303 nps 37228 tbhits 0 time 35 pv d8h4
2015-07-03 17:22:27.779 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 43 seldepth 2 multipv 1 score mate 1 nodes 1334 nps 38114 tbhits 0 time 35 pv d8h4
2015-07-03 17:22:27.790 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 44 seldepth 2 multipv 1 score mate 1 nodes 1365 nps 37916 tbhits 0 time 36 pv d8h4
2015-07-03 17:22:27.803 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 45 seldepth 2 multipv 1 score mate 1 nodes 1396 nps 38777 tbhits 0 time 36 pv d8h4
2015-07-03 17:22:27.814 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 46 seldepth 2 multipv 1 score mate 1 nodes 1427 nps 39638 tbhits 0 time 36 pv d8h4
2015-07-03 17:22:27.826 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 47 seldepth 2 multipv 1 score mate 1 nodes 1458 nps 39405 tbhits 0 time 37 pv d8h4
2015-07-03 17:22:27.838 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 48 seldepth 2 multipv 1 score mate 1 nodes 1489 nps 40243 tbhits 0 time 37 pv d8h4
2015-07-03 17:22:27.850 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 49 seldepth 2 multipv 1 score mate 1 nodes 1520 nps 41081 tbhits 0 time 37 pv d8h4
2015-07-03 17:22:27.862 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 50 seldepth 2 multipv 1 score mate 1 nodes 1551 nps 40815 tbhits 0 time 38 pv d8h4
2015-07-03 17:22:27.875 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 51 seldepth 2 multipv 1 score mate 1 nodes 1582 nps 41631 tbhits 0 time 38 pv d8h4
2015-07-03 17:22:27.887 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 52 seldepth 2 multipv 1 score mate 1 nodes 1613 nps 41358 tbhits 0 time 39 pv d8h4
2015-07-03 17:22:27.899 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 53 seldepth 2 multipv 1 score mate 1 nodes 1644 nps 42153 tbhits 0 time 39 pv d8h4
2015-07-03 17:22:27.911 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 54 seldepth 2 multipv 1 score mate 1 nodes 1675 nps 42948 tbhits 0 time 39 pv d8h4
2015-07-03 17:22:27.923 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 55 seldepth 2 multipv 1 score mate 1 nodes 1706 nps 42650 tbhits 0 time 40 pv d8h4
2015-07-03 17:22:27.934 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 56 seldepth 2 multipv 1 score mate 1 nodes 1737 nps 43425 tbhits 0 time 40 pv d8h4
2015-07-03 17:22:27.947 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 57 seldepth 2 multipv 1 score mate 1 nodes 1768 nps 44200 tbhits 0 time 40 pv d8h4
2015-07-03 17:22:27.958 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 58 seldepth 2 multipv 1 score mate 1 nodes 1799 nps 43878 tbhits 0 time 41 pv d8h4
2015-07-03 17:22:27.970 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 59 seldepth 2 multipv 1 score mate 1 nodes 1830 nps 44634 tbhits 0 time 41 pv d8h4
2015-07-03 17:22:27.982 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 60 seldepth 2 multipv 1 score mate 1 nodes 1861 nps 45390 tbhits 0 time 41 pv d8h4
2015-07-03 17:22:27.999 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 61 seldepth 2 multipv 1 score mate 1 nodes 1892 nps 45047 tbhits 0 time 42 pv d8h4
2015-07-03 17:22:28.12 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 62 seldepth 2 multipv 1 score mate 1 nodes 1923 nps 45785 tbhits 0 time 42 pv d8h4
2015-07-03 17:22:28.24 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 63 seldepth 2 multipv 1 score mate 1 nodes 1954 nps 45441 tbhits 0 time 43 pv d8h4
2015-07-03 17:22:28.35 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 64 seldepth 2 multipv 1 score mate 1 nodes 1985 nps 46162 tbhits 0 time 43 pv d8h4
2015-07-03 17:22:28.47 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 65 seldepth 2 multipv 1 score mate 1 nodes 2016 nps 45818 tbhits 0 time 44 pv d8h4
2015-07-03 17:22:28.59 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 66 seldepth 2 multipv 1 score mate 1 nodes 2047 nps 46522 tbhits 0 time 44 pv d8h4
2015-07-03 17:22:28.71 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 67 seldepth 2 multipv 1 score mate 1 nodes 2078 nps 47227 tbhits 0 time 44 pv d8h4
2015-07-03 17:22:28.83 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 68 seldepth 2 multipv 1 score mate 1 nodes 2109 nps 46866 tbhits 0 time 45 pv d8h4
2015-07-03 17:22:28.95 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 69 seldepth 2 multipv 1 score mate 1 nodes 2140 nps 47555 tbhits 0 time 45 pv d8h4
2015-07-03 17:22:28.107 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 70 seldepth 2 multipv 1 score mate 1 nodes 2171 nps 47195 tbhits 0 time 46 pv d8h4
2015-07-03 17:22:28.119 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 71 seldepth 2 multipv 1 score mate 1 nodes 2202 nps 47869 tbhits 0 time 46 pv d8h4
2015-07-03 17:22:28.131 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 72 seldepth 2 multipv 1 score mate 1 nodes 2233 nps 48543 tbhits 0 time 46 pv d8h4
2015-07-03 17:22:28.142 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 73 seldepth 2 multipv 1 score mate 1 nodes 2264 nps 48170 tbhits 0 time 47 pv d8h4
2015-07-03 17:22:28.155 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 74 seldepth 2 multipv 1 score mate 1 nodes 2295 nps 48829 tbhits 0 time 47 pv d8h4
2015-07-03 17:22:28.166 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 75 seldepth 2 multipv 1 score mate 1 nodes 2326 nps 49489 tbhits 0 time 47 pv d8h4
2015-07-03 17:22:28.179 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 76 seldepth 2 multipv 1 score mate 1 nodes 2357 nps 49104 tbhits 0 time 48 pv d8h4
2015-07-03 17:22:28.190 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 77 seldepth 2 multipv 1 score mate 1 nodes 2388 nps 49750 tbhits 0 time 48 pv d8h4
2015-07-03 17:22:28.202 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 78 seldepth 2 multipv 1 score mate 1 nodes 2419 nps 50395 tbhits 0 time 48 pv d8h4
2015-07-03 17:22:28.214 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 79 seldepth 2 multipv 1 score mate 1 nodes 2450 nps 50000 tbhits 0 time 49 pv d8h4
2015-07-03 17:22:28.226 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 80 seldepth 2 multipv 1 score mate 1 nodes 2481 nps 50632 tbhits 0 time 49 pv d8h4
2015-07-03 17:22:28.238 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 81 seldepth 2 multipv 1 score mate 1 nodes 2512 nps 50240 tbhits 0 time 50 pv d8h4
2015-07-03 17:22:28.250 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 82 seldepth 2 multipv 1 score mate 1 nodes 2543 nps 50860 tbhits 0 time 50 pv d8h4
2015-07-03 17:22:28.262 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 83 seldepth 2 multipv 1 score mate 1 nodes 2574 nps 51480 tbhits 0 time 50 pv d8h4
2015-07-03 17:22:28.273 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 84 seldepth 2 multipv 1 score mate 1 nodes 2605 nps 51078 tbhits 0 time 51 pv d8h4
2015-07-03 17:22:28.286 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 85 seldepth 2 multipv 1 score mate 1 nodes 2636 nps 51686 tbhits 0 time 51 pv d8h4
2015-07-03 17:22:28.298 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 86 seldepth 2 multipv 1 score mate 1 nodes 2667 nps 52294 tbhits 0 time 51 pv d8h4
2015-07-03 17:22:28.310 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 87 seldepth 2 multipv 1 score mate 1 nodes 2698 nps 51884 tbhits 0 time 52 pv d8h4
2015-07-03 17:22:28.322 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 88 seldepth 2 multipv 1 score mate 1 nodes 2729 nps 52480 tbhits 0 time 52 pv d8h4
2015-07-03 17:22:28.348 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 89 seldepth 2 multipv 1 score mate 1 nodes 2760 nps 53076 tbhits 0 time 52 pv d8h4
2015-07-03 17:22:28.360 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 90 seldepth 2 multipv 1 score mate 1 nodes 2791 nps 52660 tbhits 0 time 53 pv d8h4
2015-07-03 17:22:28.372 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 91 seldepth 2 multipv 1 score mate 1 nodes 2822 nps 53245 tbhits 0 time 53 pv d8h4
2015-07-03 17:22:28.384 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 92 seldepth 2 multipv 1 score mate 1 nodes 2853 nps 52833 tbhits 0 time 54 pv d8h4
2015-07-03 17:22:28.396 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 93 seldepth 2 multipv 1 score mate 1 nodes 2884 nps 53407 tbhits 0 time 54 pv d8h4
2015-07-03 17:22:28.413 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 94 seldepth 2 multipv 1 score mate 1 nodes 2915 nps 53981 tbhits 0 time 54 pv d8h4
2015-07-03 17:22:28.425 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 95 seldepth 2 multipv 1 score mate 1 nodes 2946 nps 53563 tbhits 0 time 55 pv d8h4
2015-07-03 17:22:28.437 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 96 seldepth 2 multipv 1 score mate 1 nodes 2977 nps 54127 tbhits 0 time 55 pv d8h4
2015-07-03 17:22:28.449 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 97 seldepth 2 multipv 1 score mate 1 nodes 3008 nps 54690 tbhits 0 time 55 pv d8h4
2015-07-03 17:22:28.461 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 98 seldepth 2 multipv 1 score mate 1 nodes 3039 nps 54267 tbhits 0 time 56 pv d8h4
2015-07-03 17:22:28.473 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 99 seldepth 2 multipv 1 score mate 1 nodes 3070 nps 54821 tbhits 0 time 56 pv d8h4
2015-07-03 17:22:28.484 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 100 seldepth 2 multipv 1 score mate 1 nodes 3101 nps 54403 tbhits 0 time 57 pv d8h4
2015-07-03 17:22:28.497 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 101 seldepth 2 multipv 1 score mate 1 nodes 3132 nps 54947 tbhits 0 time 57 pv d8h4
2015-07-03 17:22:28.508 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 102 seldepth 2 multipv 1 score mate 1 nodes 3163 nps 54534 tbhits 0 time 58 pv d8h4
2015-07-03 17:22:28.520 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 103 seldepth 2 multipv 1 score mate 1 nodes 3194 nps 55068 tbhits 0 time 58 pv d8h4
2015-07-03 17:22:28.532 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 104 seldepth 2 multipv 1 score mate 1 nodes 3225 nps 55603 tbhits 0 time 58 pv d8h4
2015-07-03 17:22:28.544 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 105 seldepth 2 multipv 1 score mate 1 nodes 3256 nps 55186 tbhits 0 time 59 pv d8h4
2015-07-03 17:22:28.556 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 106 seldepth 2 multipv 1 score mate 1 nodes 3287 nps 55711 tbhits 0 time 59 pv d8h4
2015-07-03 17:22:28.568 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 107 seldepth 2 multipv 1 score mate 1 nodes 3318 nps 55300 tbhits 0 time 60 pv d8h4
2015-07-03 17:22:28.580 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 108 seldepth 2 multipv 1 score mate 1 nodes 3349 nps 55816 tbhits 0 time 60 pv d8h4
2015-07-03 17:22:28.591 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 109 seldepth 2 multipv 1 score mate 1 nodes 3380 nps 56333 tbhits 0 time 60 pv d8h4
2015-07-03 17:22:28.604 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 110 seldepth 2 multipv 1 score mate 1 nodes 3411 nps 55918 tbhits 0 time 61 pv d8h4
2015-07-03 17:22:28.615 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 111 seldepth 2 multipv 1 score mate 1 nodes 3442 nps 56426 tbhits 0 time 61 pv d8h4
2015-07-03 17:22:28.627 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 112 seldepth 2 multipv 1 score mate 1 nodes 3473 nps 56934 tbhits 0 time 61 pv d8h4
2015-07-03 17:22:28.639 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 113 seldepth 2 multipv 1 score mate 1 nodes 3504 nps 56516 tbhits 0 time 62 pv d8h4
2015-07-03 17:22:28.651 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 114 seldepth 2 multipv 1 score mate 1 nodes 3535 nps 57016 tbhits 0 time 62 pv d8h4
2015-07-03 17:22:28.663 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 115 seldepth 2 multipv 1 score mate 1 nodes 3566 nps 56603 tbhits 0 time 63 pv d8h4
2015-07-03 17:22:28.675 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 116 seldepth 2 multipv 1 score mate 1 nodes 3597 nps 57095 tbhits 0 time 63 pv d8h4
2015-07-03 17:22:28.692 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 117 seldepth 2 multipv 1 score mate 1 nodes 3628 nps 56687 tbhits 0 time 64 pv d8h4
2015-07-03 17:22:28.703 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 118 seldepth 2 multipv 1 score mate 1 nodes 3659 nps 57171 tbhits 0 time 64 pv d8h4
2015-07-03 17:22:28.715 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 119 seldepth 2 multipv 1 score mate 1 nodes 3690 nps 57656 tbhits 0 time 64 pv d8h4
2015-07-03 17:22:28.725 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 120 seldepth 2 multipv 1 score mate 1 nodes 3721 nps 57246 tbhits 0 time 65 pv d8h4
2015-07-03 17:22:28.736 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 121 seldepth 2 multipv 1 score mate 1 nodes 3752 nps 57723 tbhits 0 time 65 pv d8h4
2015-07-03 17:22:28.748 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 122 seldepth 2 multipv 1 score mate 1 nodes 3783 nps 57318 tbhits 0 time 66 pv d8h4
2015-07-03 17:22:28.758 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 123 seldepth 2 multipv 1 score mate 1 nodes 3814 nps 57787 tbhits 0 time 66 pv d8h4
2015-07-03 17:22:28.769 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 124 seldepth 2 multipv 1 score mate 1 nodes 3845 nps 58257 tbhits 0 time 66 pv d8h4
2015-07-03 17:22:28.780 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 125 seldepth 2 multipv 1 score mate 1 nodes 3876 nps 57850 tbhits 0 time 67 pv d8h4
2015-07-03 17:22:28.791 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 126 seldepth 2 multipv 1 score mate 1 nodes 3907 nps 58313 tbhits 0 time 67 pv d8h4
2015-07-03 17:22:28.803 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> info depth 127 seldepth 2 multipv 1 score mate 1 nodes 3938 nps 57911 tbhits 0 time 68 pv d8h4
2015-07-03 17:22:28.814 DEBUG uci - on_line_received: <PopenProcess at 0x75aee8f0 (pid=2782)> >> bestmove d8h4
2015-07-03 17:22:28.818 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:28.819 DEBUG dgt - read_message: Clock ACK (16, 3, 0, 0)
2015-07-03 17:22:28.820 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.822 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.824 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.826 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.828 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.830 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.832 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.834 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.836 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.838 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.840 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.842 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.844 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.846 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.848 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.850 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.853 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.855 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.857 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.859 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.862 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.863 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.866 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.867 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.869 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.871 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.874 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.875 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.878 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.879 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.882 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.883 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.885 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.887 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.889 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.891 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.893 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.895 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.897 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.899 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.901 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.902 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.905 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.906 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.909 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.910 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.913 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.914 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.916 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.918 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.920 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.923 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.924 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.926 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.928 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.930 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.933 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.934 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.935 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.937 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.939 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.942 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.944 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.946 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.948 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.950 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.952 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.954 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.956 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.958 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.960 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.962 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.963 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.965 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.967 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.970 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.972 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.973 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.976 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.978 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.979 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.980 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.981 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.983 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.984 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.986 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.989 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.992 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.994 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:28.996 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:28.998 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.0 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.2 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.4 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.6 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.8 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.10 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.12 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.15 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.17 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.19 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.21 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.23 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.26 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.28 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.30 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.32 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.34 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.37 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.38 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.41 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.42 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.45 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.47 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.49 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.51 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.54 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.55 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.58 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.59 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.61 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.63 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.65 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.67 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.69 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.71 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.73 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.75 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.77 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.79 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.81 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.83 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.85 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.87 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.89 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.90 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.93 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.94 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.97 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.98 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.101 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.102 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.104 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.106 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.108 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.110 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.112 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.114 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.116 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.118 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.119 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.122 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.123 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.127 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.129 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.131 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.133 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.135 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.138 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.139 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.142 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.144 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.146 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.148 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.150 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.152 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.154 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.156 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.157 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.159 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.161 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.163 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.165 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.167 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.169 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.170 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.173 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.175 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.176 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.179 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.180 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.182 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.184 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.186 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.188 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.190 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.192 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.194 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.196 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.198 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.199 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.202 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.203 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.205 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.207 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.209 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.211 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.213 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.215 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.217 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.219 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.221 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.222 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.225 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.226 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.229 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.230 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.233 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.235 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.237 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.239 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.241 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.242 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.244 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.246 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.248 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.250 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.253 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.254 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.256 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.258 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.260 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.262 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.264 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.266 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.268 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.270 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.272 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.274 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.276 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.278 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.280 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.281 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.283 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.285 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.287 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.289 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.291 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.293 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.295 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.297 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.299 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.301 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.303 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.305 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.307 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.309 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.310 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.312 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.314 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.316 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.318 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.320 DEBUG picochess - main: Received event in event loop : Event.SCORE
2015-07-03 17:22:29.322 DEBUG picochess - main: Received event in event loop : Event.NEW_PV
2015-07-03 17:22:29.324 DEBUG picochess - main: Received event in event loop : Event.BEST_MOVE
2015-07-03 17:22:29.738 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:30.547 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:31.355 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:32.265 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:33.74 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:33.882 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:35.603 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:36.415 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:37.231 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:38.146 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:38.959 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:40.583 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:40.589 INFO dgt - run: DGT SEND BEST MOVE:d8h4
2015-07-03 17:22:40.705 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_SETNRUN]
2015-07-03 17:22:40.863 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:41.117 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:41.119 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:41.522 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:42.829 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:42.832 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:42.934 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:42.937 DEBUG dgt - read_message: 
rnb.kbnr
pppp.ppp
........
....p...
......P.
.....P..
PPPPP..P
RNBQKBNR
2015-07-03 17:22:42.938 DEBUG dgt - read_message: rnb1kbnr/pppp1ppp/8/4p3/6P1/5P2/PPPPP2P/RNBQKBNR
2015-07-03 17:22:42.939 DEBUG dgt - read_message: Fen
2015-07-03 17:22:42.941 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:43.242 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_FIELD_UPDATE], length:2
2015-07-03 17:22:43.245 DEBUG dgt - send_command: ->DGT [Commands.DGT_SEND_BRD]
2015-07-03 17:22:43.348 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BOARD_DUMP], length:64
2015-07-03 17:22:43.350 DEBUG dgt - read_message: 
rnb.kbnr
pppp.ppp
........
....p...
......Pq
.....P..
PPPPP..P
RNBQKBNR
2015-07-03 17:22:43.352 DEBUG dgt - read_message: rnb1kbnr/pppp1ppp/8/4p3/6Pq/5P2/PPPPP2P/RNBQKBNR
2015-07-03 17:22:43.352 DEBUG dgt - read_message: Fen
2015-07-03 17:22:43.354 DEBUG picochess - main: Received event in event loop : Event.FEN
2015-07-03 17:22:43.360 DEBUG pgn - run: Saving game to [games.pgn]
2015-07-03 17:22:43.556 DEBUG dgt - send_command: ->DGT [Clock.DGT_CMD_CLOCK_ASCII]
2015-07-03 17:22:43.710 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:43.712 DEBUG dgt - read_message: Clock ACK (16, 12, 0, 0)
2015-07-03 17:22:43.848 DEBUG pgn - run: SMTP Mail delivery: Started
2015-07-03 17:22:43.850 DEBUG pgn - run: SMTP Mail delivery: Import SSL SMTP Lib
2015-07-03 17:22:43.902 DEBUG pgn - run: SMTP Mail delivery: trying to connect to smtp.gmail.com
2015-07-03 17:22:44.215 DEBUG dgt - read_message: <-DGT [Messages.DGT_MSG_BWTIME], length:7
2015-07-03 17:22:47.333 DEBUG pgn - run: SMTP Mail delivery: trying to log to SMTP Server
2015-07-03 17:22:47.334 DEBUG pgn - run: SMTP Mail delivery: Username=********, Pass=********
2015-07-03 17:22:47.802 DEBUG pgn - run: SMTP Mail delivery: trying to send email
2015-07-03 17:22:49.343 DEBUG pgn - run: SMTP Mail delivery: successfuly delivered message to SMTP server
2015-07-03 17:22:49.346 DEBUG pgn - run: SMTP Mail delivery: Ended
LocutusOfPenguin commented 9 years ago

my machine calculates >120 plys ...For this a GM needs 2h to make >60moves so, 13 secs not too bad ;-) But you better not give us the complete log file...f3,e5,g4,Qh4 (12secs) enough.

Seriously: You might try this code in uci.py (exchange the Informer class)

class Informer(chess.uci.InfoHandler, Observable): def init(self): super(Informer, self).init() self.mate_found = False

def on_bestmove(self,bestmove,ponder):
    self.fire(Event.BEST_MOVE, move=bestmove, ponder=ponder)
    super().on_bestmove(bestmove, ponder)

def score(self,cp, mate, lowerbound, upperbound):
    if mate is None:
        self.fire(Event.SCORE, score=cp, mate=mate)
    else:
        self.mate_found = True
    super().score(cp, mate, lowerbound, upperbound)

def pv(self,moves):
    if not self.mate_found:
        self.fire(Event.NEW_PV, pv=moves)
    super().pv(moves)

Don't know, why github makes the code looking so ugly..but i think, y know what to do. If that's working , code can be optimized more ;-) On my PC it's alot quicker to make Qh4++ now Jürgen

LocutusOfPenguin commented 9 years ago

I think the long-wait mate problem is SOLVED. concerning the clock time back problem - this is a bug for long. Its cause of the dgt clock running independ of the internal picochess clock. I tried to do something for this (like start/stop clock more often). Should be better now, no?! Anyway, im in contact with dgt guys, to finally solve this. No promise ;-)

djdekker commented 9 years ago

Yes, Picochess announces mate in 1 almost immediately. The long-wait problem is solved. And the other bug is better now. Thank you!

LocutusOfPenguin commented 9 years ago

closed .... i know this problem (time jumping) for several months already.. wont forget ;-)

djdekker commented 9 years ago

Still in version 0.50: When the engine is playing from the opening book (and thus answering immediately) the clock nevertheless counts down 1 or 2 seconds per move, but these seconds are added again after the computer move has been carried out on the board.