bugpokersource - Bugs: bug #15016, tourney hang in running state

 
 
Show feedback again

You are not allowed to post comments on this tracker with your current authentification level.

bug #15016: tourney hang in running state

Submitted by:  Johan Euphrosine <proppy>
Submitted on:  Wed 30 Dec 2009 10:00:59 AM UTC  
 
Category: poker-networkSeverity: 3 - Normal
Priority: 5 - NormalStatus: Postponed
Privacy: PublicAssigned to: None
Open/Closed: Open

(Jump to the original submission Jump to the original submission)

Tue 12 Jan 2010 09:34:44 AM UTC, comment #11:

Postponed until error reproduces with patch applied.

Johan Euphrosine <proppy>
Project Member
Tue 12 Jan 2010 09:23:51 AM UTC, SVN revision 6351:

add assert for bug #15016 in pokertable.destroyPlayer

(Browse SVN revision 6351)

Johan Euphrosine <proppy>
Project Member
Tue 05 Jan 2010 06:05:00 PM UTC, comment #9:

Hi,

Feel free to apply the attached patch on version0908 production branch, it outputs a more verbose/grep'able error message if the same error occurs.

(file #7613)

Johan Euphrosine <proppy>
Project Member
Tue 05 Jan 2010 05:16:45 PM UTC, comment #8:

oot@pok02:/opt/mysql/bin-log# mysqlbinlog mysql-bin.001447 > /tmp/1
root@pok02:/opt/mysql/bin-log# ls -l mysql-bin.001447
-rw-rw---- 1 mysql mysql 104857764 2009-12-28 19:58 mysql-bin.001447
root@pok02:/opt/mysql/bin-log# head -n 4 /tmp/1
/!40019 SET @@session.max_insert_delayed_threads=0/;
/!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0/;
# at 4
#091228 6:56:48 server id 1002 end_log_pos 98 Start: binlog v 4, server v 5.0.32-Debian_7etch6-log created 091228 6:56:48
root@pok02:/opt/mysql/bin-log# tail -n 4 /tmp/1
#091228 19:58:10 server id 1002 end_log_pos 104857764 Rotate to mysql-bin.001448 pos: 4
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE/;
root@pok02:/opt/mysql/bin-log# grep -C 2 'UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 50726258' /tmp/1
#091228 18:58:30 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023110;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 50726258 AND tourney_serial = 233025;
# at 92557996
#091228 18:58:30 server id 1001 end_log_pos 92558023 Xid = 9453373
root@pok02:/opt/mysql/bin-log# grep -C 2 'UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 65101692' /tmp/1
root@pok02:/opt/mysql/bin-log#
root@pok02:/opt/mysql/bin-log# grep -C 2 'UPDATE user2tourney SET table_serial = 416539' /tmp/1
#091228 18:06:52 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262020012;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 55811117 AND tourney_serial = 233025;
# at 82344591
#091228 18:06:52 server id 1001 end_log_pos 82344618 Xid = 9410590
--
#091228 18:06:52 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262020012;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 34953614 AND tourney_serial = 233025;
# at 82345291
#091228 18:06:52 server id 1001 end_log_pos 82345318 Xid = 9410594
--
#091228 18:06:52 server id 1001 end_log_pos 182 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262020012;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 302578 AND tourney_serial = 233025;
# at 82345987
#091228 18:06:52 server id 1001 end_log_pos 82346014 Xid = 9410598
--
#091228 18:20:48 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262020848;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 47422280 AND tourney_serial = 233025;
# at 85060352
#091228 18:20:48 server id 1001 end_log_pos 85060379 Xid = 9421789
--
#091228 18:39:38 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262021978;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 52073158 AND tourney_serial = 233025;
# at 88589342
#091228 18:39:38 server id 1001 end_log_pos 88589369 Xid = 9436667
--
#091228 18:44:11 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262022251;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 62606227 AND tourney_serial = 233025;
# at 89553517
#091228 18:44:11 server id 1001 end_log_pos 89553544 Xid = 9440614
--
#091228 18:52:24 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262022744;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 62710752 AND tourney_serial = 233025;
# at 91223878
#091228 18:52:24 server id 1001 end_log_pos 91223905 Xid = 9447638
--
#091228 18:58:30 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023110;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 50726258 AND tourney_serial = 233025;
# at 92557996
#091228 18:58:30 server id 1001 end_log_pos 92558023 Xid = 9453373
--
#091228 18:58:30 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023110;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 63051017 AND tourney_serial = 233025;
# at 92558696
#091228 18:58:30 server id 1001 end_log_pos 92558723 Xid = 9453377
--
#091228 19:02:42 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023362;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 53556106 AND tourney_serial = 233025;
# at 93601200
#091228 19:02:42 server id 1001 end_log_pos 93601227 Xid = 9457702
--
#091228 19:02:42 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023362;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 11469517 AND tourney_serial = 233025;
# at 93601900
#091228 19:02:42 server id 1001 end_log_pos 93601927 Xid = 9457706
--
#091228 19:02:42 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023362;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 65884750 AND tourney_serial = 233025;
# at 93602600
#091228 19:02:42 server id 1001 end_log_pos 93602627 Xid = 9457710
--
#091228 19:02:42 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023362;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 47775322 AND tourney_serial = 233025;
# at 93603439
#091228 19:02:42 server id 1001 end_log_pos 93603466 Xid = 9457715
--
#091228 19:09:21 server id 1001 end_log_pos 184 Query thread_id=12263381 exec_time=0 error_code=0
SET TIMESTAMP=1262023761;
UPDATE user2tourney SET table_serial = 416539 WHERE user_serial = 47422280 AND tourney_serial = 233025;
# at 95122748
#091228 19:09:21 server id 1001 end_log_pos 95122775 Xid = 9463934
root@pok02:/opt/mysql/bin-log#

Thierry Delamare <thy>
Tue 05 Jan 2010 03:40:57 PM UTC, comment #7:

Check that table.destroy, and table.destroyPlayer in a row produce a different traceback:
Traceback (most recent call last):
File "./test-pokertable.py", line 1284, in test40_1_destroy_table
self.table.destroyPlayer(p1, 1)
File "../pokernetwork/pokertable.py", line 1315, in destroyPlayer
self.factory.joinedCountDecrease()
exceptions.AttributeError: PokerTable instance has no attribute 'factory'

Johan Euphrosine <proppy>
Project Member
Tue 05 Jan 2010 03:38:26 PM UTC, comment #6:

Checked that 2x self.table.destroyPlayer in a row produce the same traceback:
Traceback (most recent call last):
File "./test-pokertable.py", line 1284, in test40_1_destroy_table
self.table.destroyPlayer(p1, 1)
File "../pokernetwork/pokertable.py", line 1319, in destroyPlayer
self.avatar_collection.remove(serial, avatar)
File "../pokernetwork/pokertable.py", line 77, in remove
assert avatar in self.serial2avatars[serial], "expected %d avatar in %s" % ( serial, str(self.serial2avatars[serial]) )
exceptions.KeyError: 1

Johan Euphrosine <proppy>
Project Member
Tue 05 Jan 2010 03:09:20 PM UTC, comment #5:

Found that del client.tables[game_id] is called either from pokertable.destroyPlayer or pokertable.destroy.

Johan Euphrosine <proppy>
Project Member
Wed 30 Dec 2009 10:37:29 AM UTC, comment #4:

2009-12-28 19:02:20+0100 [-] PokerTable: Dealing hand Classic2034/19085167
2009-12-28 19:02:24+0100 [-] PokerTable: Dealing hand Table45/19085175
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] PokerResource: ERROR (x-cluster-client-ip:82.251.190.121) Traceback (most recent call last):
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 185, in addCallbacks
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self._runCallbacks()
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 323, in _runCallbacks
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.result = callback(self.result, args, *kw)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokersite.py", line 246, in <lambda>
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] deferred.addCallback(lambda result: self.deferRender(request, jsonp, packet))
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokersite.py", line 257, in deferRender
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] d = defer.maybeDeferred(session.avatar.handlePacketDefer, packet)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] --- <exception caught here> ---
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/twisted/internet/defer.py", line 105, in maybeDeferred
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] result = f(args, *kw)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokeravatar.py", line 346, in handlePacketDefer
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.handlePacketLogic(packet)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokeravatar.py", line 759, in handlePacketLogic
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] table.update()
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokertable.py", line 856, in update
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.tourneyEndTurn()
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokertable.py", line 682, in tourneyEndTurn
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.factory.tourneyEndTurn(self.tourney, game.id)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokerservice.py", line 866, in tourneyEndTurn
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] if not tourney.endTurn(game_id):
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokerengine/pokertournament.py", line 499, in endTurn
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.balanceGames()
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokerengine/pokertournament.py", line 521, in balanceGames
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.callback_move_player(self, from_id, to_id, serial)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokerservice.py", line 1002, in tourneyMovePlayer
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] to_game_id, reason = PacketPokerTable.REASON_TOURNEY_MOVE)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokertable.py", line 1049, in movePlayer
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] self.destroyPlayer(client, serial)
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] File "/usr/lib/python2.5/site-packages/pokernetwork/pokertable.py", line 1279, in destroyPlayer
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] del client.tables[self.game.id]
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3] exceptions.KeyError: 416539L
2009-12-28 19:02:36+0100 [HTTPChannel,32354783,172.19.21.3]

Johan Euphrosine <proppy>
Project Member
Wed 30 Dec 2009 10:05:55 AM UTC, comment #3:

mysql> select * from user2table where table_serial = 416539;
Empty set (0.00 sec)

mysql> select * from user2table where table_serial = 416543;
+-------------+--------------+----------+-----+
| user_serial | table_serial | money | bet |
+-------------+--------------+----------+-----+
| 65101692 | 416543 | 16900500 | 0 |
+-------------+--------------+----------+-----+
1 row in set (0.00 sec)

Johan Euphrosine <proppy>
Project Member
Wed 30 Dec 2009 10:04:50 AM UTC, comment #2:

mysql> select * from pokertables where serial = 416539;
Empty set (0.00 sec)

Johan Euphrosine <proppy>
Project Member
Wed 30 Dec 2009 10:03:46 AM UTC, comment #1:

http://www.skyrock.com/poker/tournois.php?tourney_serial=233025&schedule_serial=7025

mysql> select * from pokertables where tourney_serial = 233025;
+--------+-----------------+-------+-------------+----------------+--------------+---------+-----------+---------+----------------+--------------+-----------------+-------------+---------+-------------------+---------+----------------+
| serial | resthost_serial | seats | average_pot | hands_per_hour | percent_flop | players | observers | waiting | player_timeout | muck_timeout | currency_serial | name | variant | betting_structure | skin | tourney_serial |
+--------+-----------------+-------+-------------+----------------+--------------+---------+-----------+---------+----------------+--------------+-----------------+-------------+---------+-------------------+---------+----------------+
| 416543 | 9 | 10 | 4704590 | 80 | 39 | 1 | 7 | 0 | 60 | 5 | 0 | Classic2033 | holdem | level-001 | default | 233025 |
+--------+-----------------+-------+-------------+----------------+--------------+---------+-----------+---------+----------------+--------------+-----------------+-------------+---------+-------------------+---------+----------------+
1 row in set (0.00 sec)

Tourney manager is showing:
Table Players Max money Min money Go to table
416539 1 Go to table
416543 1 Go to table

Johan Euphrosine <proppy>
Project Member
Wed 30 Dec 2009 10:00:59 AM UTC, original submission:
Johan Euphrosine <proppy>
Project Member

 

Attached Files
file #7613:  pokertable-destroy-player-assert.patch added by proppy (2kB - text/x-diff)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -unavailable- added by thy (Posted a comment)
  • -unavailable- added by proppy (Submitted the item)

    •  

    Do you think this task is very important?
    If so, you can click here to add your encouragement to it.
    This task has 0 encouragements so far.

    Only logged-in users can vote.

     

    Please enter the title of George Orwell's famous dystopian book (it's a date):

     

     

    Follow 4 latest changes.

    Date Changed By Updated Field Previous Value => Replaced By
    Tue 23 Feb 2010 06:01:18 PM UTCproppyCategoryNone=>poker-network
    Tue 12 Jan 2010 09:34:44 AM UTCproppyStatusNone=>Postponed
    Tue 05 Jan 2010 06:05:00 PM UTCproppyAttached File-=>Added pokertable-destroy-player-assert.patch, #7613
    Wed 30 Dec 2009 10:03:46 AM UTCproppyPriority1 - Later=>5 - Normal
    Show feedback again

    Back to the top


    Copyright (C) 2004-2006, the Gna! people. Posted items are owned by whoever posted them.
    Verbatim copying and distribution of this entire article is permitted in any medium, provided this notice is preserved.

    Powered by Savane 3.1-cleanup