Chips went missing

[ctm]

Find out why chips went missing in event 4922.

The end of event 4922 had smalltalkdan as the winner, but he had 179,400 chips. There were 9 players and everyone started with 20,000 chips, so 600 chips went missing.

In the past, missing chips have been due to people quitting, but there are no quit records in public_table_messages.

I do see two warnings (that should be errors):

2023-12-05T01:19:12.084220870Z 2023-12-05T01:19:12.084Z WARN  [mb2_commands::seat] action present
2023-12-05T01:19:12.084282392Z 2023-12-05T01:19:12.084Z WARN  [mb2_commands::seat] action present

They come from Seat::prepare_for_next_hand. The timestamps should be sufficient to see what happened.

My guess this is associated with player motion when a table has been split. I had to move action from players to seats in order to let people who had folded be moved while their action was still in the pot. I may have made a mistake somewhere. I can think this will be trivial to sort out, although it's a third black eye and I only have two!

[ctm]

Here's the player motion that I think caused it:

mb2=> select id, received_at, substr(message::text, 1, 20), table_id, hand_id from public_table_messages where player_id is null and table_id in (5510, 5511) and received_at >= '2023-12-05T01:19:00.084220870Z' and received_at <= '2023-12-05T01:19:14.084220870Z' order by received_at;
 received_at;
    id    |          received_at          |        substr        | table_id | hand_id 
----------+-------------------------------+----------------------+----------+---------
[...]
 10143520 | 2023-12-05 01:18:42.963207+00 | {"RemindDraw": [2000 |     5510 |  382611
 10143521 | 2023-12-05 01:18:51.642129+00 | {"MoreTime": [14, 40 |     5510 |  382611
 10143522 | 2023-12-05 01:18:59.107111+00 | {"NewPlayersAdded":  |     5511 |  382611
 10143523 | 2023-12-05 01:18:59.119642+00 | {"MovedFrom": [26, 5 |     5511 |  382611
 10143524 | 2023-12-05 01:18:59.123794+00 | {"MovedTo": [26, 551 |     5510 |  382611
 10143525 | 2023-12-05 01:18:59.136234+00 | {"MovedFrom": [17, 5 |     5511 |  382611
 10143526 | 2023-12-05 01:18:59.140945+00 | {"MovedTo": [17, 551 |     5510 |  382611
 10143527 | 2023-12-05 01:18:59.15337+00  | {"MovedFrom": [10, 5 |     5511 |  382611
 10143528 | 2023-12-05 01:18:59.157641+00 | {"MovedTo": [10, 551 |     5510 |  382611
 10143529 | 2023-12-05 01:18:59.181647+00 | {"MovedFrom": [3, 55 |     5511 |  382611
 10143530 | 2023-12-05 01:18:59.186139+00 | {"MovedTo": [3, 5511 |     5510 |  382611
 10143531 | 2023-12-05 01:18:59.195849+00 | {"Dealing": ["400 80 |     5511 |  382612
 10143532 | 2023-12-05 01:18:59.200377+00 | {"Dealing": ["400 80 |     5511 |  382613
[...]
 10143630 | 2023-12-05 01:19:12.090881+00 | {"Dealing": ["400 80 |     5510 |  382614

[ctm]

I do not understand what happened to hand 382612:

mb2=> select * from public_table_messages where id in (10143531, 10143532);
    id    |          received_at          | variant |                                       message                                       | table_id |          created_at           | hand_id | player_id 
----------+-------------------------------+---------+-------------------------------------------------------------------------------------+----------+-------------------------------+---------+-----------
 10143531 | 2023-12-05 01:18:59.195849+00 |      38 | {"Dealing": ["400 800 Dramaha", 1, "SplitLimit", 7, false, 382612, true, false, 0]} |     5511 | 2023-12-05 01:18:59.197904+00 |  382612 |          
 10143532 | 2023-12-05 01:18:59.200377+00 |      38 | {"Dealing": ["400 800 Dramaha", 1, "SplitLimit", 7, false, 382613, true, false, 0]} |     5511 | 2023-12-05 01:18:59.202385+00 |  382613 |          
(2 rows)

mb2=> select * from public_table_messages where hand_id = 382612;
    id    |          received_at          | variant |                                       message                                       | table_id |          created_at           | hand_id | player_id 
----------+-------------------------------+---------+-------------------------------------------------------------------------------------+----------+-------------------------------+---------+-----------
 10143531 | 2023-12-05 01:18:59.195849+00 |      38 | {"Dealing": ["400 800 Dramaha", 1, "SplitLimit", 7, false, 382612, true, false, 0]} |     5511 | 2023-12-05 01:18:59.197904+00 |  382612 |          
(1 row)

This looks like table 5511 got two messages to start the next hand when it should only have gotten one. I suspect that's related to the chip problem.

[ctm]

FWIW, the double dealing issue has been happening for a little while:

mb2=> select hand_id, count(hand_id) from public_table_messages group by hand_id having count(hand_id) = 1;
 hand_id | count 
---------+-------
  380870 |     1
  381430 |     1
  381726 |     1
  381869 |     1
  382041 |     1
  382133 |     1
  382612 |     1
(7 rows)

mb2=> select * from public_table_messages where hand_id  in (380870, 381430, 381726, 381869, 382041, 382133, 382612);
    id    |          received_at          | variant |                                                       message                                                       | table_id |          created_at           | hand_id | player_id 
----------+-------------------------------+---------+---------------------------------------------------------------------------------------------------------------------+----------+-------------------------------+---------+-----------
 10082221 | 2023-11-21 01:10:59.388359+00 |      38 | {"Dealing": ["150 300 (50) Razz", 0, "StudLimit", 5, true, 380870, true, false, 0]}                                 |     5486 | 2023-11-21 01:10:59.389808+00 |  380870 |          
 10099101 | 2023-11-25 01:10:35.65728+00  |      38 | {"Dealing": ["300 600 Chowaha (High only)", 0, "SplitLimit", 0, false, 381430, true, false, 0]}                     |     5492 | 2023-11-25 01:10:35.658873+00 |  381430 |          
 10108159 | 2023-11-27 01:12:18.676476+00 |      38 | {"Dealing": ["300 600 Badeucy", 3, "SplitLimit", 2, false, 381726, true, true, 0]}                                  |     5495 | 2023-11-27 01:12:18.678418+00 |  381726 |          
 10113145 | 2023-11-28 01:09:23.264449+00 |      38 | {"Dealing": ["50 100 Pot-Limit Omaha (High/Low Eight Qualifier)", 0, "PotLimit", 7, false, 381869, true, false, 0]} |     5497 | 2023-11-28 01:09:23.26702+00  |  381869 |          
 10119275 | 2023-11-30 01:05:39.815603+00 |      38 | {"Dealing": ["200 400 Badeucy", 3, "SplitLimit", 6, false, 382041, true, true, 0]}                                  |     5501 | 2023-11-30 01:05:39.81728+00  |  382041 |          
 10123909 | 2023-12-01 01:16:38.310373+00 |      38 | {"Dealing": ["300 600 Dramaha", 1, "SplitLimit", 6, false, 382133, true, false, 0]}                                 |     5503 | 2023-12-01 01:16:38.311794+00 |  382133 |          
 10143531 | 2023-12-05 01:18:59.195849+00 |      38 | {"Dealing": ["400 800 Dramaha", 1, "SplitLimit", 7, false, 382612, true, false, 0]}                                 |     5511 | 2023-12-05 01:18:59.197904+00 |  382612 |          
(7 rows)

[ctm]

Only 4400 was awarded at the end of hand 382611, but 5,000 was in the pot. The blinds were in the pot, but the players who had posted the blinds had folded and had been moved. This strongly implies that the pot divvying algorithm inadvertently requires a player to be at a seat for the player's chips to be counted as part of a pot. I know where that code is and I can find that problem and fix it later today.

[ctm]

I'm still hungry (which is why I'm going to take a break), but I do see the problem. TablePots::actions has this code in it:

        let actions: Vec<_> = self
            .seats_with_players_and_seat_index_starting_at(first_to_showdown)
            .filter_map(|(seat_with_player, seat)| {
...

So yeah, we're only looking at seats with players. This was an oversight on my part when I moved action from the player to the seat.

The fix is straightforward, I think: just create a SeatPerhapsWithPlayer and make its player field be Option<&'a Player> and then define the relevant methods on it, and make and use an iterator that returns SeatPerhapsWithPlayer instead of SeatWithPlayer.

[ctm]

I have a fix. I'm testing it now.

[ctm]

Deploying now.