ctm / mb2-doc

Mb2, poker software
https://devctm.com
7 stars 2 forks source link

Tables didn't merge properly after break #1254

Closed ctm closed 9 months ago

ctm commented 9 months ago

Find and fix the problem that caused one of the two tables from this evening's tournament (4920) from resuming after the break.

This may be a regression, so I'm labeling it as such. I don't remember if we had a table split or if we started out with two tables. I think we started with two tables. I believe the bust that caused us to get down to six hands happened after we had already gone on break, so this may just be a sufficiently rare case that the bug has been there previously.

I think that if I review the various logs that I'll be able to figure out what happened, so I'm labeling this easy, even though I don't currently even know if it's a regression.

FWIW, after a player bust, the tables merged and the stranded players were able to continue playing.

ctm commented 9 months ago

I did spend a bunch of time looking at the logs, but not enough time to come to any conclusion. I was slowed down by my inability to remember how to get Postgres to display just the key at the top level of each message, but my biggest problem was simply that I got a late start and now this evening's tournament has started.

ctm commented 9 months ago

jsonb_path_query_array(message, '$.keyvalue()[0].key') was the magic I couldn't remember and had a hard time looking up when I was tired. I thought there was a shorthand for that and perhaps there is, but I can't find it and this works. Yay.

ctm commented 9 months ago

So, table 5508 was put on break, then was paused for redraw, then was neither merged, nor taken off break when table 5507 resumed. If I look at the code, my guess is I'll simply see that when the break timer resumes, we take a table off break even if it was the table whose finish should have initiated the redraw. Furthermore, my guess is that this bug has been present for a long time and that it rarely gets hit and when it's been hit in the past either nobody noticed or nobody reported it.

mb2=> select id, received_at at time zone 'mst', substr(message::text, 1, 20), table_id, hand_id from public_table_messages where player_id is null and hand_id in (382449, 382450) order by received_at;
[...]
 10136548 | 2023-12-02 18:54:59.225045 | "ThisTableIsOnBreak" |     5508 |  382449
[...]
 10136583 | 2023-12-02 18:55:33.429934 | {"EndOfHand": {"pena |     5508 |  382449
 10136584 | 2023-12-02 18:55:33.453134 | {"Bust": [6, 7, 4920 |     5508 |  382449
 10136588 | 2023-12-02 18:55:33.475987 | {"OnLevel": ["Break" |     5508 |  382449
 10136589 | 2023-12-02 18:55:33.480817 | {"Status": {"board": |     5508 |  382449
 10136590 | 2023-12-02 18:55:33.486041 | {"Break": [300000, " |     5508 |  382449
 10136591 | 2023-12-02 18:55:37.488149 | {"Chat": [10, "gg"]} |     5508 |  382449
 10136592 | 2023-12-02 18:55:38.396044 | {"Chat": [3, "gg"]}  |     5508 |  382449
 10136593 | 2023-12-02 18:55:39.91493  | {"Chat": [14, "gg"]} |     5508 |  382449
 10136594 | 2023-12-02 18:55:40.415379 | "PausedForRedraw"    |     5508 |  382449
 10136596 | 2023-12-02 19:00:33.429326 | {"OnLevel": ["Level  |     5508 |  382449
 10136597 | 2023-12-02 19:00:33.434004 | {"Dealing": ["3000 6 |     5507 |  382450
 10136598 | 2023-12-02 19:00:34.416529 | {"OnLevel": ["Level  |     5507 |  382450
 10136599 | 2023-12-02 19:00:34.425145 | {"OnLevel": ["Level  |     5508 |  382449
 10136600 | 2023-12-02 19:00:35.439616 | "NoAnte"             |     5507 |  382450
 10136601 | 2023-12-02 19:00:35.444275 | {"Blinds": [17, 1500 |     5507 |  382450
 10136602 | 2023-12-02 19:00:35.450165 | {"Blinds": [24, 3000 |     5507 |  382450
 10136603 | 2023-12-02 19:00:35.454213 | {"BeginRound": [0, [ |     5507 |  382450
 10136604 | 2023-12-02 19:00:35.463644 | {"Status": {"board": |     5507 |  382450
 10136605 | 2023-12-02 19:00:35.4682   | {"Remind": [20000, 3 |     5507 |  382450
 10136606 | 2023-12-02 19:00:42.582809 | {"RaisesNtoM": [11,  |     5507 |  382450
 10136607 | 2023-12-02 19:00:42.587282 | {"Remind": [20000, 4 |     5507 |  382450
 10136608 | 2023-12-02 19:00:45.81363  | {"Folds": [17, false |     5507 |  382450
 10136609 | 2023-12-02 19:00:45.817997 | {"Remind": [20000, 3 |     5507 |  382450
 10136610 | 2023-12-02 19:00:54.334033 | {"Calls": [24, null, |     5507 |  382450
 10136611 | 2023-12-02 19:00:54.338598 | {"BeginRound": [1, [ |     5507 |  382450
 10136612 | 2023-12-02 19:00:54.342896 | {"Status": {"board": |     5507 |  382450
 10136613 | 2023-12-02 19:00:54.348039 | {"RemindDraw": [2000 |     5507 |  382450
 10136614 | 2023-12-02 19:00:57.004511 | {"Draws": [24, 2]}   |     5507 |  382450
 10136615 | 2023-12-02 19:00:57.011636 | {"Draws": [11, 1]}   |     5507 |  382450
 10136616 | 2023-12-02 19:00:57.016566 | "FinishedDrawing"    |     5507 |  382450
 10136617 | 2023-12-02 19:00:57.022846 | {"Remind": [20000, 0 |     5507 |  382450
 10136618 | 2023-12-02 19:01:03.851997 | {"Checks": [24, null |     5507 |  382450
 10136619 | 2023-12-02 19:01:03.856771 | {"Remind": [20000, 0 |     5507 |  382450
 10136620 | 2023-12-02 19:01:05.629777 | {"Chat": [14, "ruh r |     5508 |  382449
[...]
 10136655 | 2023-12-02 19:01:40.224482 | {"EndOfHand": {"pena |     5507 |  382450
 10136656 | 2023-12-02 19:01:40.245252 | {"Bust": [24, 6, 492 |     5507 |  382450
 10136657 | 2023-12-02 19:01:44.134255 | {"Chat": [24, "gg"]} |     5507 |  382450
 10136658 | 2023-12-02 19:01:44.360567 | {"Chat": [11, "gg"]} |     5507 |  382450
 10136659 | 2023-12-02 19:01:47.223714 | {"MovedFrom": [11, 5 |     5508 |  382449
 10136660 | 2023-12-02 19:01:47.228423 | {"MovedTo": [11, 550 |     5507 |  382450
 10136661 | 2023-12-02 19:01:47.24154  | {"MovedFrom": [17, 5 |     5508 |  382449
 10136662 | 2023-12-02 19:01:47.246509 | {"MovedTo": [17, 550 |     5507 |  382450
 10136663 | 2023-12-02 19:01:47.250752 | "TableFinished"      |     5507 |  382450

Oh, and I gave up on using keyvalue() and just used substr to keep the message length at bay.

I've got an appointment in about an hour that I have to get ready for, so my guess is I still won't get this fixed today, but I think I'm close.

ctm commented 9 months ago

I chose to spend my time fixing the missing chips bug (#1255), and then this one "bit" us yesterday evening again. Oh well. I'll get this one fixed today, I believe. The smoking gun is:

10136594 | 2023-12-02 18:55:40.415379 | "PausedForRedraw"    |     5508 |  382449

because the other table was already on break, meaning mb2 should have done the table redraw instead of pausing this table (5508). That also means the other table (5507) itself was never marked as pausing for redraw. Since mb2 only does redraws at the end of the hand, one hand gets played after break at 5507 while 5508 remains idle because it's still (incorrectly) paused.

Although I haven't looked at the code, the problem is probably that we're looking at the wrong fields to determine whether we should pause for redraw. We should simply check the other table to see if it's between hands, because a table on break should be between hands.

ctm commented 9 months ago

Here's the fix:

diff --git a/mb2/src/tournament.rs b/mb2/src/tournament.rs
index e5b1c69e..ea52949a 100644
--- a/mb2/src/tournament.rs
+++ b/mb2/src/tournament.rs
@@ -2136,9 +2136,7 @@ impl RunningEvent {
                             match self.mut_table_at(other_table_id) {
                                 None => false,
                                 Some(other_table) => {
-                                    if other_table.paused_due_to_too_few_players()
-                                        || other_table.awaiting_redraw
-                                    {
+                                    if other_table.between_hands() {

Deploying now.