Lockout goal click resulted in non deterministic state for multiple players.

[Lego6245]

On the following bingo board (PW provided on request, please message me directly), the goal "15 Delfino Blues" was clicked at similar times by both players. Bingosync did not resolve the click in a deterministic way, resulting in multiple clients seeing different states of the goal. In addition, the goal was unable to be unclicked by multiple people until a couple of attempts by multiple people.

I hope that we can figure out what went wrong here. If you need anymore information from me, let me know. https://bingosync.com/room/dSl4f8YTQlewztEStPKOCA

[kbuzsaki]

Thanks for reporting this bug. I think the underlying issues are that:

1. the /api/select endpoint isn't using transactions when it performs the lockout check. When both players clicked the goal ~simultaneously the bingosync server performed the lockout check for both of them at the same time, saw that the goal was unmarked in each handler, and then allowed both of them to mark the goal.
2. the event publishing in tornado isn't using a queue or other mechanism to enforce consistent ordering of events. Each event just tries to publish to all connected users as fast as it can. This means that it was possible to have a race where the server sent events in the order [(e1 to p1), (e2 to p1), (e2 to p2), (e1 to p2)], leading to p1 seeing e1 first and p2 seeing e2 first. The bingosync frontend javascript's clientside enforcement of lockout behavior then led to the players each seeing a different color on their board.

Bug 1) should be fairly straightforward to fix, though it could be tricky to test. Bug 2) is a bit more involved to fix and is more costly to iterate on since restarting the tornado server breaks ongoing game connections right now, forcing users to refresh. I'll therefore try to take a look at fixing bug 1) at some point, but no promises for bug 2) :). Fortunately I think fixing bug 1) alone will make it much less likely for something like this to happen again.

If you're curious, there was actually a "winner" for who clicked the goal first, which we can see from the id numbers and timestamps in the bingosync database:

   id    |           timestamp           |  player  |                        goal                         |     event     | color_value | remove_color 
---------+-------------------------------+----------+-----------------------------------------------------+---------------+-------------+--------------
 4710465 | 2021-04-05 01:48:41.312358+00 | Libre    | Ricco 3 Hoverless                                   | add teal      |           8 | f
 4710592 | 2021-04-05 01:55:52.933852+00 | MrYhatoh | 17 M Graffiti Blue Coins                            | add red       |           2 | f
 4710646 | 2021-04-05 01:58:46.399405+00 | Libre    | 5 Blue Bird Blue Coins                              | add teal      |           8 | f
 4710699 | 2021-04-05 02:00:09.833479+00 | MrYhatoh | 45 Total Blue Coins                                 | add red       |           2 | f
 4710755 | 2021-04-05 02:04:05.030714+00 | Libre    | 7 Pinna Beach Blue Coins OR 4 Fruit Lady Blue Coins | add teal      |           8 | f
 4710820 | 2021-04-05 02:10:08.644808+00 | Libre    | 3 Hidden Shines                                     | add teal      |           8 | f
 4710823 | 2021-04-05 02:11:27.282643+00 | MrYhatoh | Pinna 5 from the back Hoverless                     | add red       |           2 | f
 4710843 | 2021-04-05 02:14:11.025316+00 | MrYhatoh | 15 Delfino Blue Coins                               | add red       |           2 | f
 4710844 | 2021-04-05 02:14:11.02745+00  | Libre    | 15 Delfino Blue Coins                               | add teal      |           8 | f
 4710867 | 2021-04-05 02:19:26.005063+00 | zLarvi   | 7 Pinna Beach Blue Coins OR 4 Fruit Lady Blue Coins | remove teal   |           8 | t
 4710869 | 2021-04-05 02:19:36.197223+00 | zLarvi   | 7 Pinna Beach Blue Coins OR 4 Fruit Lady Blue Coins | add teal      |           8 | f
 4710872 | 2021-04-05 02:19:40.500472+00 | zJeff    | 5 NPC Blue Coins                                    | add blue      |           3 | f
 4710873 | 2021-04-05 02:19:41.720841+00 | zJeff    | 5 NPC Blue Coins                                    | remove blue   |           3 | t
 4710890 | 2021-04-05 02:20:04.123332+00 | zTomato  | 15 Delfino Blue Coins                               | remove teal   |           8 | t
 4710891 | 2021-04-05 02:20:11.213838+00 | zLego    | 15 Delfino Blue Coins                               | add purple    |           6 | f
 4710932 | 2021-04-05 02:23:45.485966+00 | MrYhatoh | 5 NPC Blue Coins                                    | add red       |           2 | f
 4710936 | 2021-04-05 02:25:33.793766+00 | Libre    | 5 Shines from Bianco                                | add teal      |           8 | f

Congratulations to MrYhatoh over 3 years later, you beat Libre in marking 15 Delfino Blue Coins by about 2 milliseconds :)