Session Has Expired Is Not Dismissed
Closed this issue · 5 comments
Just wanted to log this since I don't have time to fix it right now, I encountered this this morning after I took a peek at the bot:
Full verbose log: tft-bot-debug-2023-04-12_00-30-32_212793.log
Relevant code snippet from the log that is repeated for thousands of lines:
2023-04-12 04:59:24.773 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 04:59:24.778 | DEBUG | tft_bot.league_api.league_api_integration:should_reconnect:305 - Checking if we should reconnect
2023-04-12 04:59:24.781 | DEBUG | tft_bot.league_api.league_api_integration:is_dead:424 - Checking if we have more than 0 HP
2023-04-12 04:59:24.787 | INFO | __main__:check_if_game_complete:434 - The game considers us dead, checking the screen again for exit buttons
2023-04-12 04:59:24.788 | INFO | __main__:check_if_game_complete:419 - Waiting an additional ~25s for any exit buttons
2023-04-12 04:59:27.792 | INFO | __main__:check_screen_for_exit_button:403 - End of game detected (exit now)
2023-04-12 04:59:31.432 | DEBUG | tft_bot.helpers.click_helpers:click_to_middle:164 - M|Could not find 'captures/buttons/exit_now_highlighted.png', skipping
2023-04-12 04:59:33.340 | DEBUG | __main__:check_screen_for_exit_button:405 - Exit now clicking success: True
2023-04-12 04:59:38.341 | INFO | __main__:print_timer:694 - -----------------------------------------
2023-04-12 04:59:38.341 | INFO | __main__:print_timer:695 - Game End
2023-04-12 04:59:38.342 | INFO | __main__:print_timer:696 - Time since start: 4h 28m 23s
2023-04-12 04:59:38.344 | INFO | __main__:print_timer:697 - Games played: 11
2023-04-12 04:59:39.098 | INFO | __main__:print_timer:698 - Win rate (at most last 20 games): 72.73%
2023-04-12 04:59:39.098 | INFO | __main__:print_timer:699 - -----------------------------------------
2023-04-12 04:59:39.100 | INFO | __main__:match_complete:643 - Match complete! Cleaning up and restarting
2023-04-12 04:59:39.101 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 04:59:40.862 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 04:59:40.866 | DEBUG | tft_bot.league_api.league_api_integration:in_queue:224 - Checking if we are already in a queue
2023-04-12 04:59:40.870 | INFO | tft_bot.league_api.league_api_integration:create_lobby:186 - Creating a TFT lobby
2023-04-12 04:59:45.874 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 04:59:45.877 | DEBUG | tft_bot.league_api.league_api_integration:in_queue:224 - Checking if we are already in a
[..]
2023-04-12 09:28:07.515 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 09:28:07.518 | DEBUG | tft_bot.league_api.league_api_integration:in_queue:224 - Checking if we are already in a queue
2023-04-12 09:28:07.522 | INFO | tft_bot.league_api.league_api_integration:create_lobby:186 - Creating a TFT lobby
2023-04-12 09:28:12.526 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 09:28:12.529 | DEBUG | tft_bot.league_api.league_api_integration:in_queue:224 - Checking if we are already in a queue
2023-04-12 09:28:12.532 | INFO | tft_bot.league_api.league_api_integration:create_lobby:186 - Creating a TFT lobby
2023-04-12 09:28:17.536 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 09:28:17.539 | DEBUG | tft_bot.league_api.league_api_integration:in_queue:224 - Checking if we are already in a queue
2023-04-12 09:28:17.544 | INFO | tft_bot.league_api.league_api_integration:create_lobby:186 - Creating a TFT lobby
2023-04-12 09:28:22.550 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 09:28:22.553 | DEBUG | tft_bot.league_api.league_api_integration:in_queue:224 - Checking if we are already in a queue
2023-04-12 09:28:22.558 | INFO | tft_bot.league_api.league_api_integration:create_lobby:186 - Creating a TFT lobby
[me interfering to get the logs:]
2023-04-12 09:28:25.701 | DEBUG | __main__:toggle_pause:151 - alt+p pressed, toggling pause from False to True
2023-04-12 09:28:25.701 | WARNING | __main__:toggle_pause:154 - Bot now paused, remember to unpause to continue botting!
After resuming the session (after manually dismissing League), it looks like it got stuck in a loop for the next hour with this logic repeating:
2023-04-12 11:58:44.720 | WARNING | tft_bot.league_api.league_api_integration:connect_to_lcu:87 - Couldn't find the League client within 5 minutes, exiting
2023-04-12 11:58:44.721 | DEBUG | tft_bot.league_api.league_api_integration:in_game:283 - Checking if we are in a game
2023-04-12 11:58:46.751 | INFO | tft_bot.league_api.league_api_integration:connect_to_lcu:81 - Waiting for the League client (~5m timeout)
2023-04-12 11:58:47.066 | DEBUG | tft_bot.league_api.league_api_integration:connect_to_lcu:89 - Couldn't find LCUx process yet. Re-searching process list...
2023-04-12 11:58:48.377 | DEBUG | tft_bot.league_api.league_api_integration:connect_to_lcu:89 - Couldn't find LCUx process yet. Re-searching process list...
According to the stack trace in console that was printed on exit, it looks like there may be something getting called recursively instead of it exiting after a failure and falling back to the main event loop, which probably explains why this was being looped and not recovering like we'd expect it to.
That's weird. Both calls to tft_bot.league_api.league_api_integration:connect_to_lcu check the False return and call sys.exit(1) if False is returned.
// EDIT I just saw the According to the stack trace in console that was printed on exit and feel very stupid now lol. What's the stack trace?
Unfortunately my console crashed right after and it was printed in the console and not the log, but it appeared to be a recursive call issue with the logic surrounding those timeouts (that time out after ~5 minutes)
Log file with the extras for debugging purposes: tft-bot-debug-2023-04-12_00-30-32_212793.log
I think I see what the cause is, it's this block:
TFT-Bot/tft_bot/league_api/league_api_integration.py
Lines 288 to 290 in 325efaf
And now that I'm thinking about it, I don't think sys.exit(1) is needed -- if connect_to_lcu fails, could it not just restart the league processes and then try again? 🤔
The block in question no longer exists if we merge the PR linked, so that's one way to go about it :)
The connect to logic at the moment is only running on start-up and if we restart the league client. So I'm not sure how much sense it would make to constantly try to restart the client, what do you think?
Yeah that's fair -- we can explore if this loop happens again!