IndexError

[GoogleCodeExporter]

Played a quick game with glaurung, using one gnuchess as analyzer.
Got IndexError in historyPanel.py game_changed() method.
Just added one line to show how ply grows (print 'ply=',ply)

Original issue reported on code.google.com by gbtami on 28 Dec 2007 at 8:30

Attachments:

• 2007-12-28_21-21-17.log
• IndexError.png

[GoogleCodeExporter]

Hmm. Maybe this related to issue 240 ?

Original comment by gbtami on 28 Dec 2007 at 8:39

[GoogleCodeExporter]

Hm, it seams to be a problem in my latest commit on the toSAN function.
"else: notat = toSAN(game.boards[ply-1], game.moves[ply-1], localRepr=True)" in
historypanel should be restored to what it was before. I think.

However I don't think it should raise IndexError unless you are in a loaded fen 
game,
or something. In this case it might rather be an indication of issue 240 as you 
say.

Did you experience any of the other 240 problems? Or were you able to continue 
play?

Original comment by lobais on 28 Dec 2007 at 9:29

[GoogleCodeExporter]

Where did you actually put those "print ply" lines?
I've fixed the bug part in rev 807.
Does this reproduce as often as 240?
Does it react differently with rev 807?

Original comment by lobais on 29 Dec 2007 at 2:52

• Added labels: Milestone-Release0.8

[GoogleCodeExporter]

The error still exist with rev 807, but i can reproduce only with human vs 
glaurung
using gnuchess as analyzer. Using glaurung or pychess as analyzer i can't 
reproduce.

Itresting the print ply used in game_changed call skipping from 81 to 85 in 
console!
print is here:

    def game_changed (self, game):
        ply = game.ply
        print 'ply=',ply
        row, view, other = self._ply_to_row_col_other(ply)

Seems 

Original comment by gbtami on 29 Dec 2007 at 3:41

Attachments:

• 2007-12-29_16-20-03.log
• glaurung.pgn
• IndexError.png

[GoogleCodeExporter]

I have a strong feeling, the root of this bug and 240 is the same, but 240 
doesn't
seem to reappear with trunk anymore. Seems it changed to this issue as codebase
changed. Maybe...

Original comment by gbtami on 29 Dec 2007 at 4:08

[GoogleCodeExporter]

Now got an AttributeError !

Original comment by gbtami on 29 Dec 2007 at 4:10

Attachments:

• 2007-12-29_16-58-49.log
• AttributeError.png

[GoogleCodeExporter]

I've looked closely into this, and I think the Attribute error has more to do 
with
bad locking in BoardView than with the other issues. I hope to have some 
cleanup of
the entire locking thing in Stauton. Something with moving every module that 
requires
glock locking to their own package.

For the IndexError I think the reason why the old error stopped occuring, is 
simply
that this happens before it, so we never reach it.

board.ply is defined by len(board.lboard.history). Therefore it would be 
interesting
to see a print of that list as well. It could seam like a lot of moves are 
added to
that lowlevel history, but only one board is added to gamemodel.boards.

Original comment by lobais on 29 Dec 2007 at 5:11

[GoogleCodeExporter]

Hm, I played a Human vs. Human game, and got an AssertionError in Board.py -> 
def
move, at the point "assert self[move.cord0]".
The interesting thing is that my log doesn't show any moves emitted (that 
didn't show
up on the board at least).
I also played without analyzers.

Could have somthing to do with those strange jumping plies. Not sure. I've 
added a
little more debuginfo, that should show us, if it happens again.

Original comment by lobais on 29 Dec 2007 at 11:14

Attachments:

• Skærmbillede-Pychess.png
• 2007-12-29_20-58-11.log

[GoogleCodeExporter]

Played a game with rev 811 while removed the history panel, as you suggested in 
240
issue. After i played 0-0, seems black wanted to play 2 moves or something.

Original comment by gbtami on 30 Dec 2007 at 10:29

Attachments:

• 2007-12-30_11-22-24.log
• no_history_panel.png

[GoogleCodeExporter]

self.emit("game_changed")
for spectactor in self.spectactors.values():
    spectactor.makeMove(self)

Interesting, so what we see is, that where a problem normally occours in
game_changed, we now continue to the spectactors, which also seems to suffer 
from the
straneg ply jump.

I see you have removed the ply= debugging? I'd still much like to see the "print
game.boards[-1].lboard.history"

Original comment by lobais on 30 Dec 2007 at 2:33

[GoogleCodeExporter]

The shot's upper right corner you can see the try:...except... i added.
Is this what you like to see?

Original comment by gbtami on 30 Dec 2007 at 4:07

Attachments:

• 2007-12-30_16-54-41.log
• glaurung.png
• galurung.pgn

[GoogleCodeExporter]

Strange. I thought I'd looked through the code a thousand times for this, but it
certanly seams like the analyzers corrupt the game.
If you look at the three last items in the first history print, it is c1e3, 
a7a5,
c7c5. Be3 is played by you, and c5 by Glaurung, but a5 is only mentioned by 
GnuChess.

I've looked the code through very carefully before, to be sure that players 
make no
changes to the game. However I might have missed something.
To know for sure if this is where the problem lies, I'd like to know if the bug 
is
reproduceable with

for spectactor in self.spectactors.values():
    model = GameModel()
    model.boards = [board.clone() for board in self.boards]
    model.moves = self.moves
    model.players = self.players
    model.status = self.status
    model.reason = self.reason
    spectactor.makeMove(model)

instead of

for spectactor in self.spectactors.values():
    spectactor.makeMove(self)

in line 331 in GameModel.py

Original comment by lobais on 30 Dec 2007 at 6:10

[GoogleCodeExporter]

if it helps, it would also be interesting to see (without the above change) what
changing in CECPEngine.py at line 233

moves = listToMoves (self.board, mvstrs, type=None, validate=True)

to

ply = self.board.ply
moves = listToMoves (self.board, mvstrs, type=None, validate=True)
if not ply == self.board.ply:
    print ply, self.board.ply, self.board.board.history

would print. My best guess is, that that could be the source, but I can't find
anything that should cause a such problem.

Original comment by lobais on 30 Dec 2007 at 6:42

[GoogleCodeExporter]

Applyed the latest and got the history attached.

Original comment by gbtami on 30 Dec 2007 at 8:45

Attachments:

• glaurung.png
• 2007-12-30_21-36-06.log

[GoogleCodeExporter]

I got similar with change in comment 13 applied too!

Original comment by gbtami on 30 Dec 2007 at 8:50

Attachments:

• 2007-12-30_21-46-06.log
• glaurung.png

[GoogleCodeExporter]

You mean you get similar with change from comment 12?

Original comment by lobais on 30 Dec 2007 at 9:19

[GoogleCodeExporter]

Well, you should get the same with change gamemodel clone from comment 12.
The important thing is that the two numbers er different, and we never seem to 
catch
the problem before the ply jump.

I guess we can conclude that the problem happens in the listToMoves function. 
I'll
just have to read it carefully to find out where. Perhaps adding a few "print
len(board.history)" around in the function will help pinpoint.

Original comment by lobais on 30 Dec 2007 at 9:25

[GoogleCodeExporter]

I came to think that the change in listToMoves could very well be due to 
parseLine
running in a different thread than makeMove. This way the GameModel could 
change the
self.board while we were in listToMoves, so that the before and after 
comparison in
comment 13, would actually be on different objects.

To ensure this doesn't happen, and generally to avoid stupid bugs, I've added 
some
locks in makeMove, setupBoard, undoMoves and parseLine. All the methods that 
changes
self.board.

This might fix the entire problem, or at least filter out some red herrings.

To test if it fixes the problem, you should naturally run without the clone 
changes
in comment 12.
The debug changes in comment 13 will still be interesting. More than before, 
actually.

Original comment by lobais on 31 Dec 2007 at 12:53

[GoogleCodeExporter]

This game was played with svn 813 (with comment 13, but seems it's not playing 
here).
My last played move was Kd3.
Maybe there is another stealthy bug somewhere.

Original comment by gbtami on 31 Dec 2007 at 11:08

Attachments:

• 2007-12-31_11-54-11.log
• glaurung.png

[GoogleCodeExporter]

From last log attached, i see the problem here:
11:55:53 Human Debug: emit_move_signal e3 d3
... here gnuchess touched the board somehow with mowe Kd5, as the next FEN 
shows!
11:55:53 Glaurung Log:  8/8/8/p1pk1B2/P5P1/1PPK4/8/8 w - - 2 41

Original comment by gbtami on 31 Dec 2007 at 11:42

[GoogleCodeExporter]

Can you, or can you not, reproduce this with change from comment 12?
It should entirely isolate the gnuchess call.

Original comment by lobais on 5 Jan 2008 at 12:39

[GoogleCodeExporter]

Not yet. Just the attached AttributeError.

Original comment by gbtami on 5 Jan 2008 at 6:21

Attachments:

• glaurung.png

[GoogleCodeExporter]

Hm. That indicates that the moves list is also changed.
Now that is tremendously strange, because I can think of only one place where 
the
moves list is changed - in GameModel.run.
However if you can reproduce with:

for spectactor in self.spectactors.values():
    model = GameModel()
    model.boards = [board.clone() for board in self.boards]
    model.moves = [move for move in self.moves]
    model.players = self.players
    model.status = self.status
    model.reason = self.reason
    spectactor.makeMove(model)

I might have to take that back.
There is a slight chance that the spectactor could be manipulating the players, 
so if
you really can reproduce with the above change, try "model.players = []".

Original comment by lobais on 5 Jan 2008 at 10:37

[GoogleCodeExporter]

Seems to me that the last AttributeError not indicates the move list change, 
because
these games can be continued and finished correctly, unlike when i got 
IndexError the
game was always frozen. I think it only indicates that self.lastMove was set to 
None
by f.e. _set_shown or by another function.

With changing from:
model.moves = self.moves
to
model.moves = [move for move in self.moves]
i got no error yet indicating move list change.

Btw. you never get that annoying xcb_lock assertion?

Original comment by gbtami on 7 Jan 2008 at 4:30

[GoogleCodeExporter]

Hm the lastMove would be set to None if a field in self.moves was None.

I haven't yet produced an xcb_lock assertion error. I guess having only one core
saves me from a lot of trouble :) However I'm buing a dualcore, so perhaps I'll 
have
an easier time reproduce these things.

Original comment by lobais on 7 Jan 2008 at 4:43

[GoogleCodeExporter]

Anyhow, these AttributeError's never prevented to continue the game without any 
problem.

Original comment by gbtami on 7 Jan 2008 at 5:28

[GoogleCodeExporter]

If it seams to fix stuff, I think we should commit the kludge from comment 23.
I'll soon have my own dual core machine, and perhaps then I'll be able to 
recreate
this, and hopefully find a more satisfying fix.

Original comment by lobais on 10 Jan 2008 at 7:08

[GoogleCodeExporter]

Ok, committed to ver 843

Original comment by gbtami on 10 Jan 2008 at 7:50

[GoogleCodeExporter]

I think i can close this, if it reappears, one can reopen.

Original comment by gbtami on 11 Jan 2008 at 7:57

• Changed state: Fixed