Site Freezing and Odd Behavior

Report bugs found in Poker Mavens
Post Reply
escorpius
Posts: 64
Joined: Wed Apr 29, 2020 12:47 am

Re: Site Freezing and Odd Behavior

Post by escorpius »

Thanks. We installed. Took some time, but did have a freeze occur. The watchdog service we've written captures the logs and then restarts the server automatically. The last (obviously abbreviated) segment leading into the crash was:

Code: Select all

2022-09-25 01:19:22|PM_Timer ThreadTop: 174853
2022-09-25 01:19:22|PM_Timer KillInactive: 174853
We can also provide the full log if that would help.
Kent Briggs
Site Admin
Posts: 5673
Joined: Wed Mar 19, 2008 8:47 pm

Re: Site Freezing and Odd Behavior

Post by Kent Briggs »

Are you still seeing multiple calls to AccountsSessionKey in the API and if so have you tried logging those on your end? I'm wondering if these things could be related where the "KillInactive" routine is crashing because it's finding multiple sessions per player.
Kent Briggs - [email protected]
Briggs Softworks - http://www.briggsoft.com
escorpius
Posts: 64
Joined: Wed Apr 29, 2020 12:47 am

Re: Site Freezing and Odd Behavior

Post by escorpius »

We're keeping an eye on the calls to AccountsSessionKey. Thus far, any "duplicate calls" within a few seconds seem to be tied to the user getting impatient perhaps in periods when their connection is a bit slow as they wait for the transfer to the server after their session is established.

Is there something in the KillInactive code that you would suspect would crash in such a case ... and, specifically, crash in a way that would not be caught by your try/catch block? Is deadlock possible in the KillInactive?
Kent Briggs
Site Admin
Posts: 5673
Joined: Wed Mar 19, 2008 8:47 pm

Re: Site Freezing and Odd Behavior

Post by Kent Briggs »

escorpius wrote: Sun Sep 25, 2022 11:12 pm Is there something in the KillInactive code that you would suspect would crash in such a case ... and, specifically, crash in a way that would not be caught by your try/catch block? Is deadlock possible in the KillInactive?
Any error should be caught by the exception block but I'll make up a new beta and insert multiple log dumps inside that routine.
Kent Briggs - [email protected]
Briggs Softworks - http://www.briggsoft.com
Kent Briggs
Site Admin
Posts: 5673
Joined: Wed Mar 19, 2008 8:47 pm

Re: Site Freezing and Odd Behavior

Post by Kent Briggs »

escorpius wrote: Sun Sep 25, 2022 11:12 pm Is deadlock possible in the KillInactive?
I just sent you a link via email for beta #3 that should answer this question.
Kent Briggs - [email protected]
Briggs Softworks - http://www.briggsoft.com
escorpius
Posts: 64
Joined: Wed Apr 29, 2020 12:47 am

Re: Site Freezing and Odd Behavior

Post by escorpius »

Crashed with b3. Capture from ErrorLog is below. I included the full block from immediately before the crash and then the partial block from when it crashed.

Code: Select all

2022-09-29 18:39:49|[debug] KillInactiveSession Begin
2022-09-29 18:39:49|[debug] Sessions found: 7
2022-09-29 18:39:49|[debug] Begin Session #: 0
2022-09-29 18:39:49|[debug] Session #0 player: "BD"
2022-09-29 18:39:49|[debug] No Purge #0
2022-09-29 18:39:49|[debug] End Session #: 0
2022-09-29 18:39:49|[debug] Begin Session #: 1
2022-09-29 18:39:49|[debug] Session #1 player: ""
2022-09-29 18:39:49|[debug] No Purge #1
2022-09-29 18:39:49|[debug] End Session #: 1
2022-09-29 18:39:49|[debug] Begin Session #: 2
2022-09-29 18:39:49|[debug] Session #2 player: "CN"
2022-09-29 18:39:49|[debug] No Purge #2
2022-09-29 18:39:49|[debug] End Session #: 2
2022-09-29 18:39:49|[debug] Begin Session #: 3
2022-09-29 18:39:49|[debug] Session #3 player: "H4TB"
2022-09-29 18:39:49|[debug] No Purge #3
2022-09-29 18:39:49|[debug] End Session #: 3
2022-09-29 18:39:49|[debug] Begin Session #: 4
2022-09-29 18:39:49|[debug] Session #4 player: "F"
2022-09-29 18:39:49|[debug] No Purge #4
2022-09-29 18:39:49|[debug] End Session #: 4
2022-09-29 18:39:49|[debug] Begin Session #: 5
2022-09-29 18:39:49|[debug] Session #5 player: "MC"
2022-09-29 18:39:49|[debug] No Purge #5
2022-09-29 18:39:49|[debug] End Session #: 5
2022-09-29 18:39:49|[debug] Begin Session #: 6
2022-09-29 18:39:49|[debug] Session #6 player: "TS"
2022-09-29 18:39:49|[debug] No Purge #6
2022-09-29 18:39:49|[debug] End Session #: 6
2022-09-29 18:39:49|[debug] KillInactiveSessions End
2022-09-29 18:40:49|[debug]
2022-09-29 18:40:49|[debug] KillInactiveSession Begin
2022-09-29 18:40:49|[debug] Sessions found: 7
2022-09-29 18:40:49|[debug] Begin Session #: 0
2022-09-29 18:40:49|[debug] Session #0 player: "BD"
2022-09-29 18:40:49|[debug] No Purge #0
2022-09-29 18:40:49|[debug] End Session #: 0
2022-09-29 18:40:49|[debug] Begin Session #: 1
2022-09-29 18:40:49|[debug] Session #1 player: ""
2022-09-29 18:40:49|[debug] No Purge #1
2022-09-29 18:40:49|[debug] End Session #: 1
2022-09-29 18:40:49|[debug] Begin Session #: 2
Kent Briggs
Site Admin
Posts: 5673
Joined: Wed Mar 19, 2008 8:47 pm

Re: Site Freezing and Odd Behavior

Post by Kent Briggs »

escorpius wrote: Thu Sep 29, 2022 7:03 pm Crashed with b3. Capture from ErrorLog is below. I included the full block from immediately before the crash and then the partial block from when it crashed.
It should have immediately spit out the player name after the "Begin Session" line. That was the next line of code. Was there anything unusual in the Event Log at that last time stamp?
Kent Briggs - [email protected]
Briggs Softworks - http://www.briggsoft.com
escorpius
Posts: 64
Joined: Wed Apr 29, 2020 12:47 am

Re: Site Freezing and Odd Behavior

Post by escorpius »

From the Event Log at that timestamp:

Code: Select all

2022-09-29 18:40:30|House|Rake +0.03 balance ******.** (Black AA Cracked .50/1C Jackpot Table)
2022-09-29 18:41:37|API|AccountsSessionKey from ***.***.***.***
2022-09-29 18:41:39|Connect|Connection 0000009C accepted from IP ***.***.***.***, PC 6047ABCD
2022-09-29 18:41:40|Logout|BD logged out session 0000008F, PC 6047ABCD
2022-09-29 18:41:40|Login|BD logged into session 0000009C from IP ***.***.***.***, PC 6047ABCD
Kent Briggs
Site Admin
Posts: 5673
Joined: Wed Mar 19, 2008 8:47 pm

Re: Site Freezing and Odd Behavior

Post by Kent Briggs »

escorpius wrote: Thu Sep 29, 2022 9:58 pm From the Event Log at that timestamp:
How much longer passed 18:40:49 were events being recorded? Remind me again what are the symptoms of these crashes? What do the players see on their end and what are you seeing on the admin side?
Kent Briggs - [email protected]
Briggs Softworks - http://www.briggsoft.com
escorpius
Posts: 64
Joined: Wed Apr 29, 2020 12:47 am

Re: Site Freezing and Odd Behavior

Post by escorpius »

Symptoms
As noted in the first post in this thread, the site freezes. The server may intermittently respond for some players, but many of them can't see their cards, even after refreshing the table. Players cannot connect / reconnect. We cannot connect to the admin.

Your Question
How much longer passed 18:40:49 were events being recorded?
As noted in my Thu Sep 29, 2022 9:58 pm post, it kept recording events through 18:41:40 as seen here:

Code: Select all

2022-09-29 18:40:30|House|Rake +0.03 balance ******.** (Black AA Cracked .50/1C Jackpot Table)
2022-09-29 18:41:37|API|AccountsSessionKey from ***.***.***.***
2022-09-29 18:41:39|Connect|Connection 0000009C accepted from IP ***.***.***.***, PC 6047ABCD
2022-09-29 18:41:40|Logout|BD logged out session 0000008F, PC 6047ABCD
2022-09-29 18:41:40|Login|BD logged into session 0000009C from IP ***.***.***.***, PC 6047ABCD
Another
Tonight, we had another such crash. From the ErrorLog, the last full dump and the partial dump at the time of the crash:

Code: Select all

2022-09-30 19:33:12|[debug] KillInactiveSession Begin
2022-09-30 19:33:12|[debug] Sessions found: 17
2022-09-30 19:33:12|[debug] Begin Session #: 0
2022-09-30 19:33:12|[debug] Session #0 player: "H4TB"
2022-09-30 19:33:12|[debug] No Purge #0
2022-09-30 19:33:12|[debug] End Session #: 0
2022-09-30 19:33:12|[debug] Begin Session #: 1
2022-09-30 19:33:12|[debug] Session #1 player: "BG"
2022-09-30 19:33:12|[debug] No Purge #1
2022-09-30 19:33:12|[debug] End Session #: 1
2022-09-30 19:33:12|[debug] Begin Session #: 2
2022-09-30 19:33:12|[debug] Session #2 player: "ts"
2022-09-30 19:33:12|[debug] No Purge #2
2022-09-30 19:33:12|[debug] End Session #: 2
2022-09-30 19:33:12|[debug] Begin Session #: 3
2022-09-30 19:33:12|[debug] Session #3 player: "Mc"
2022-09-30 19:33:12|[debug] No Purge #3
2022-09-30 19:33:12|[debug] End Session #: 3
2022-09-30 19:33:12|[debug] Begin Session #: 4
2022-09-30 19:33:12|[debug] Session #4 player: "Sd"
2022-09-30 19:33:12|[debug] No Purge #4
2022-09-30 19:33:12|[debug] End Session #: 4
2022-09-30 19:33:12|[debug] Begin Session #: 5
2022-09-30 19:33:12|[debug] Session #5 player: "Sj2"
2022-09-30 19:33:12|[debug] No Purge #5
2022-09-30 19:33:12|[debug] End Session #: 5
2022-09-30 19:33:12|[debug] Begin Session #: 6
2022-09-30 19:33:12|[debug] Session #6 player: "d"
2022-09-30 19:33:12|[debug] No Purge #6
2022-09-30 19:33:12|[debug] End Session #: 6
2022-09-30 19:33:12|[debug] Begin Session #: 7
2022-09-30 19:33:12|[debug] Session #7 player: "LM"
2022-09-30 19:33:12|[debug] No Purge #7
2022-09-30 19:33:12|[debug] End Session #: 7
2022-09-30 19:33:12|[debug] Begin Session #: 8
2022-09-30 19:33:12|[debug] Session #8 player: "M"
2022-09-30 19:33:12|[debug] No Purge #8
2022-09-30 19:33:12|[debug] End Session #: 8
2022-09-30 19:33:12|[debug] Begin Session #: 9
2022-09-30 19:33:12|[debug] Session #9 player: "f"
2022-09-30 19:33:12|[debug] No Purge #9
2022-09-30 19:33:12|[debug] End Session #: 9
2022-09-30 19:33:12|[debug] Begin Session #: 10
2022-09-30 19:33:12|[debug] Session #10 player: ""
2022-09-30 19:33:12|[debug] No Purge #10
2022-09-30 19:33:12|[debug] End Session #: 10
2022-09-30 19:33:12|[debug] Begin Session #: 11
2022-09-30 19:33:12|[debug] Session #11 player: "Cn"
2022-09-30 19:33:12|[debug] No Purge #11
2022-09-30 19:33:12|[debug] End Session #: 11
2022-09-30 19:33:12|[debug] Begin Session #: 12
2022-09-30 19:33:12|[debug] Session #12 player: "rjb101"
2022-09-30 19:33:12|[debug] No Purge #12
2022-09-30 19:33:12|[debug] End Session #: 12
2022-09-30 19:33:12|[debug] Begin Session #: 13
2022-09-30 19:33:12|[debug] Session #13 player: "L78"
2022-09-30 19:33:12|[debug] No Purge #13
2022-09-30 19:33:12|[debug] End Session #: 13
2022-09-30 19:33:12|[debug] Begin Session #: 14
2022-09-30 19:33:12|[debug] Session #14 player: "T"
2022-09-30 19:33:12|[debug] No Purge #14
2022-09-30 19:33:12|[debug] End Session #: 14
2022-09-30 19:33:12|[debug] Begin Session #: 15
2022-09-30 19:33:12|[debug] Session #15 player: "gc10"
2022-09-30 19:33:12|[debug] No Purge #15
2022-09-30 19:33:12|[debug] End Session #: 15
2022-09-30 19:33:12|[debug] Begin Session #: 16
2022-09-30 19:33:12|[debug] Session #16 player: "nd"
2022-09-30 19:33:12|[debug] No Purge #16
2022-09-30 19:33:12|[debug] End Session #: 16
2022-09-30 19:33:12|[debug] KillInactiveSessions End
2022-09-30 19:34:12|[debug]
2022-09-30 19:34:12|[debug] KillInactiveSession Begin
2022-09-30 19:34:12|[debug] Sessions found: 19
2022-09-30 19:34:12|[debug] Begin Session #: 0
2022-09-30 19:34:12|[debug] Session #0 player: "H4TB"
2022-09-30 19:34:12|[debug] No Purge #0
2022-09-30 19:34:12|[debug] End Session #: 0
2022-09-30 19:34:12|[debug] Begin Session #: 1
2022-09-30 19:34:12|[debug] Session #1 player: "BG"
2022-09-30 19:34:12|[debug] No Purge #1
2022-09-30 19:34:12|[debug] End Session #: 1
2022-09-30 19:34:12|[debug] Begin Session #: 2
2022-09-30 19:34:12|[debug] Session #2 player: "ts"
2022-09-30 19:34:12|[debug] No Purge #2
2022-09-30 19:34:12|[debug] End Session #: 2
2022-09-30 19:34:12|[debug] Begin Session #: 3
2022-09-30 19:34:12|[debug] Session #3 player: "Mc"
2022-09-30 19:34:12|[debug] No Purge #3
2022-09-30 19:34:12|[debug] End Session #: 3
2022-09-30 19:34:12|[debug] Begin Session #: 4
2022-09-30 19:34:12|[debug] Session #4 player: "Sd"
2022-09-30 19:34:12|[debug] No Purge #4
2022-09-30 19:34:12|[debug] End Session #: 4
2022-09-30 19:34:12|[debug] Begin Session #: 5
2022-09-30 19:34:12|[debug] Session #5 player: "Sj2"
2022-09-30 19:34:12|[debug] No Purge #5
2022-09-30 19:34:12|[debug] End Session #: 5
2022-09-30 19:34:12|[debug] Begin Session #: 6
2022-09-30 19:34:12|[debug] Session #6 player: "d"
2022-09-30 19:34:12|[debug] No Purge #6
2022-09-30 19:34:12|[debug] End Session #: 6
2022-09-30 19:34:12|[debug] Begin Session #: 7
2022-09-30 19:34:12|[debug] Session #7 player: "LM"
2022-09-30 19:34:12|[debug] No Purge #7
2022-09-30 19:34:12|[debug] End Session #: 7
2022-09-30 19:34:12|[debug] Begin Session #: 8
2022-09-30 19:34:12|[debug] Session #8 player: "M"
2022-09-30 19:34:12|[debug] No Purge #8
2022-09-30 19:34:12|[debug] End Session #: 8
2022-09-30 19:34:12|[debug] Begin Session #: 9
From the EventLog, the lines from this time:

Code: Select all

2022-09-30 19:34:12|Connect|Connection 00000096 accepted from IP ***.***.89.129, PC 3661E5DD
2022-09-30 19:34:20|Connect|Connection 00000097 accepted from IP ***.***.89.129, PC 3661E5DD
2022-09-30 19:34:28|API|AccountsSessionKey from ***.***.232.227
2022-09-30 19:34:28|Connect|IP ***.***.89.129 disconnects session 00000097, PC 3661E5DD
2022-09-30 19:34:33|Connect|Connection 00000098 accepted from IP ***.***.146.95, PC 5E9CC141
2022-09-30 19:34:44|API|AccountsSessionKey from ***.***.232.227
2022-09-30 19:34:46|Connect|Connection 00000099 accepted from IP ***.***.89.129, PC 3661E5DD
2022-09-30 19:34:55|Connect|rjb disconnects session 00000087, PC 03081596
2022-09-30 19:35:05|API|AccountsSessionKey from ***.***.232.227
2022-09-30 19:35:06|Connect|Connection 0000009A accepted from IP ***.***.183.82, PC 6CA31782
2022-09-30 19:35:07|Logout|LM logged out session 00000079, PC 6CA31782
2022-09-30 19:35:07|Login|LM logged into session 0000009A from IP ***.***.183.82, PC 6CA31782
2022-09-30 19:35:14|API|AccountsSessionKey from ***.***.232.227
2022-09-30 19:35:18|Connect|Connection 0000009B accepted from IP ***.***.146.239, PC 5E9CC141
2022-09-30 19:35:26|Connect|Rogue connection on port 8088 rejected from ***.***.46.179
Post Reply