Skip to content

Commit

Permalink
Improve traceback/debug output
Browse files Browse the repository at this point in the history
- Game state will now be dumped in error reports when the traceback
  verbosity is > 0
- When the user data level is > 1, treat user data level as 1 when
  dumping variable data for a more compact representation, but then
  display the full user repr at the end. Should make reading user
  containers much easier
- Add lykos and python version to the top of the trace
  • Loading branch information
skizzerz committed Jul 23, 2023
1 parent ecf7b0d commit 42a98bf
Show file tree
Hide file tree
Showing 4 changed files with 65 additions and 18 deletions.
2 changes: 1 addition & 1 deletion src/channels.py
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ def __repr__(self):
def __format__(self, format_spec):
if format_spec == "#":
return self.name
elif format_spec == "for_tb":
elif format_spec in ("for_tb", "for_tb_verbose"):
channel_data_level = config.Main.get("telemetry.errors.channel_data_level")
if channel_data_level == 0:
if self is Main:
Expand Down
12 changes: 6 additions & 6 deletions src/containers.py
Original file line number Diff line number Diff line change
Expand Up @@ -299,15 +299,15 @@ def __init__(self, _it=(), **kwargs):
raise

def __format__(self, format_spec=""):
if format_spec == "for_tb":
if format_spec in ("for_tb", "for_tb_verbose"):
# we don't know if the keys, the values, or both are Users or other user containers, so try all 3...
try:
args = ["{0:for_tb}: {1:for_tb}".format(x, y) for x, y in self.items()]
except TypeError:
args = ["{0:{2}}: {1:{2}}".format(x, y, format_spec) for x, y in self.items()]
except (TypeError, ValueError):
try:
args = ["{0:for_tb}: {1}".format(x, y) for x, y in self.items()]
except TypeError:
args = ["{0}: {1:for_tb}".format(x, y) for x, y in self.items()]
args = ["{0:{2}}: {1}".format(x, y, format_spec) for x, y in self.items()]
except (TypeError, ValueError):
args = ["{0}: {1:{2}}".format(x, y, format_spec) for x, y in self.items()]
elif format_spec == "":
# maintain a stable ordering for unit testing regardless of hash key
args = sorted(["{0}: {1}".format(x, y) for x, y in self.items()])
Expand Down
59 changes: 53 additions & 6 deletions src/debug/decorators.py
Original file line number Diff line number Diff line change
@@ -1,7 +1,9 @@
from __future__ import annotations

import json
import platform
import re
import subprocess
import threading
import traceback
import urllib.request
Expand Down Expand Up @@ -71,6 +73,7 @@ def __exit__(self, exc_type: Optional[type], exc_value: Optional[BaseException],
exc_log = logging.getLogger("exception.{}".format(exc_type.__name__))
exc_tb = tb
variables = ["", ""]
game_state = None

if _local.handler is None:
_local.handler = chain_exceptions(exc_value)
Expand All @@ -97,32 +100,39 @@ def __exit__(self, exc_type: Optional[type], exc_value: Optional[BaseException],
frames = [frames[-1]]

with _local.handler:
from src.gamestate import GameState, PregameState
from src.dispatcher import MessageDispatcher
for i, frame in enumerate(frames, start=1):
if frame is None:
continue
variables.append(word.format(i, frame.f_code.co_name))
for name, value in frame.f_locals.items():
# Capture game state for later display
if isinstance(value, GameState) or isinstance(value, PregameState):
game_state = value
elif isinstance(value, MessageDispatcher) and value.game_state is not None:
game_state = value.game_state

try:
if isinstance(value, dict):
try:
log_value = "{{{0}}}".format(", ".join("{0:for_tb}: {1:for_tb}".format(k, v) for k, v in value.items()))
except:
except (TypeError, ValueError):
try:
log_value = "{{{0}}}".format(", ".join("{0!r}: {1:for_tb}".format(k, v) for k, v in value.items()))
except:
except (TypeError, ValueError):
log_value = "{{{0}}}".format(", ".join("{0:for_tb}: {1!r}".format(k, v) for k, v in value.items()))
elif isinstance(value, list):
log_value = "[{0}]".format(", ".join(format(v, "for_tb") for v in value))
elif isinstance(value, set):
log_value = "{{{0}}}".format(", ".join(format(v, "for_tb") for v in value))
else:
log_value = format(value, "for_tb")
except:
except (TypeError, ValueError):
log_value = repr(value)
variables.append("{0} = {1}".format(name, log_value))

if len(variables) > 3:
variables.append("\n")
if traceback_verbosity > 1:
variables[2] = "Local variables in all frames (most recent call last):"
else:
Expand All @@ -131,6 +141,43 @@ def __exit__(self, exc_type: Optional[type], exc_value: Optional[BaseException],
variables[2] = "No local variables found in all frames."

variables[1] = _local.handler.traceback

# dump game state if we found it in our traceback
if game_state is not None:
variables.append("\nGame state:\n")
for key, value in game_state.__dict__.items():
# Skip over things like __module__, __dict__, and __weakrefs__
if key.startswith("__") and key.endswith("__"):
continue
# Only interested in data members, not properties or methods
if isinstance(value, property) or callable(value):
continue
try:
variables.append("{0} = {1:for_tb}".format(key, value))
except (TypeError, ValueError):
variables.append("{0} = {1!r}".format(key, value))

# dump full list of known users with verbose output, as everything above has truncated output for readability
if config.Main.get("telemetry.errors.user_data_level") > 1:
import src.users
variables.append("\nAll connected users:\n")
for user in src.users.users():
variables.append("{0:x} = {1:for_tb_verbose}".format(id(user), user))
if len(list(src.users.disconnected())) > 0:
variables.append("\nAll disconnected users:\n")
for user in src.users.disconnected():
variables.append("{0:x} = {1:for_tb_verbose}".format(id(user), user))
else:
variables.append("\nNo disconnected users.")

# obtain bot version
try:
ans = subprocess.check_output(["git", "log", "-n", "1", "--pretty=format:%h"])
variables[0] = "lykos {0}, Python {1}\n".format(str(ans.decode()), platform.python_version())
except (OSError, subprocess.CalledProcessError):
variables[0] = "lykos <unknown>, Python {0}\n".format(platform.python_version())

# capture variables before sanitization for local logging
extra_data = {"variables": "\n".join(variables)}

# sanitize paths in tb: convert backslash to forward slash and remove prefixes from src and library paths
Expand All @@ -147,7 +194,7 @@ def __exit__(self, exc_type: Optional[type], exc_value: Optional[BaseException],
channels.Main.send(messages["error_log"])
message = [str(messages["error_log"])]

link = _tracebacks.get("\n".join(variables))
link = _tracebacks.get(variables[1])
if link is None and not config.Main.get("debug.enabled"):
api_url = "https://ww.chat/submit"
data = None # prevent UnboundLocalError when error log fails to upload
Expand All @@ -165,7 +212,7 @@ def __exit__(self, exc_type: Optional[type], exc_value: Optional[BaseException],
message.append(messages["error_pastebin"].format())
extra_data["paste_error"] = _local.handler.traceback
else:
link = _tracebacks["\n".join(variables)] = data["url"]
link = _tracebacks[variables[1]] = data["url"]
message.append(link)

elif link is not None:
Expand Down
10 changes: 5 additions & 5 deletions src/users.py
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@
_ghosts: CheckedSet[User] = CheckedSet("users._ghosts")
_pending_account_updates: CheckedDict[User, CheckedDict[str, Callable]] = CheckedDict("users._pending_account_updates")

_arg_msg = "(user={0:for_tb}, allow_bot={1})"
_arg_msg = "(user={0:for_tb_verbose}, allow_bot={1})"

# This is used to tell if this is a fake nick or not. If this function
# returns a true value, then it's a fake nick. This is useful for
Expand Down Expand Up @@ -364,12 +364,12 @@ def __repr__(self):
def __format__(self, format_spec):
if format_spec == "@":
return "\u0002{0}\u0002".format(self.name)
elif format_spec == "for_tb":
elif format_spec in ("for_tb", "for_tb_verbose"):
user_data_level = config.Main.get("telemetry.errors.user_data_level")
if user_data_level == 0:
return "{self.__class__.__name__}({0:x})".format(id(self), self=self)
elif user_data_level == 1:
return "{self.__class__.__name__}({self.nick!r})".format(self=self)
elif user_data_level == 1 or format_spec == "for_tb":
return "{self.__class__.__name__}({self.nick!r}, {0:x})".format(id(self), self=self)
else:
return repr(self)
return super().__format__(format_spec)
Expand Down Expand Up @@ -689,7 +689,7 @@ def __hash__(self):
return hash(self.nick)

def __format__(self, format_spec):
if format_spec == "for_tb" and self.nick.startswith("@"):
if format_spec in ("for_tb", "for_tb_verbose") and self.nick.startswith("@"):
# fakes starting with @ are used internally for various purposes (such as @WolvesAgree@)
# so it'd be good to keep that around when debugging in tracebacks
return "{self.__class__.__name__}({self.nick!r})".format(self=self)
Expand Down

0 comments on commit 42a98bf

Please sign in to comment.