mirrors/debugpy
1
0
Fork 0
mirror of https://github.com/microsoft/debugpy.git synced 2025-12-23 08:48:12 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions 1

Improve exception logging to make swallowing/reraising explicit in all cases.

Browse source
This commit is contained in:
Pavel Minaev 2020-02-20 17:21:21 -08:00 • committed by Pavel Minaev
parent bf1fbbc8ee
commit de9ea2cb9c
20 changed files with 93 additions and 92 deletions
Download patch file Download diff file Expand all files Collapse all files

6
src/debugpy/adapter/__main__.py
View file

@ -86,7 +86,7 @@ def main(args):
finally:
sockets.close_socket(sock)
except Exception:
raise log.exception("Error sending endpoints info to debug server:")
log.reraise_exception("Error sending endpoints info to debug server:")
if "error" in endpoints:
log.error("Couldn't set up endpoints; exiting.")
@ -101,14 +101,14 @@ def main(args):
try:
os.remove(listener_file)
except Exception:
log.exception("Failed to delete {0!r}", listener_file, level="warning")
log.swallow_exception("Failed to delete {0!r}", listener_file, level="warning")
try:
with open(listener_file, "w") as f:
atexit.register(delete_listener_file)
print(json.dumps(endpoints), file=f)
except Exception:
raise log.exception("Error writing endpoints info to file:")
log.reraise_exception("Error writing endpoints info to file:")
if args.port is None:
clients.Client("stdio")

2
src/debugpy/adapter/clients.py
View file

@ -459,4 +459,4 @@ def stop_serving():
try:
listener.close()
except Exception:
log.exception(level="warning")
log.swallow_exception(level="warning")

2
src/debugpy/adapter/components.py
View file

@ -123,7 +123,7 @@ def missing(session, type):
try:
raise ComponentNotAvailable(type)
except Exception as exc:
raise log.exception("{0} in {1}", exc, session)
log.reraise_exception("{0} in {1}", exc, session)
return Missing()

10
src/debugpy/adapter/servers.py
View file

@ -99,7 +99,7 @@ if 'debugpy' not in sys.modules:
# Failure to inject is not a fatal error - such a subprocess can
# still be debugged, it just won't support "import debugpy" in user
# code - so don't terminate the session.
log.exception(
log.swallow_exception(
"Failed to inject debugpy into {0}:", self, level="warning"
)
@ -119,7 +119,7 @@ if 'debugpy' not in sys.modules:
_connections_changed.set()
except Exception:
log.exception("Failed to accept incoming server connection:")
log.swallow_exception("Failed to accept incoming server connection:")
self.channel.close()
# If this was the first server to connect, and the main thread is inside
@ -142,7 +142,7 @@ if 'debugpy' not in sys.modules:
# session. We still want to keep the connection around, in case the
# client reconnects later. If the parent session was "launch", it'll take
# care of closing the remaining server connections.
log.exception("Failed to notify parent session about {0}:", self)
log.swallow_exception("Failed to notify parent session about {0}:", self)
def __str__(self):
return "Server" + fmt("[?]" if self.pid is None else "[pid={0}]", self.pid)
@ -354,7 +354,7 @@ def stop_serving():
try:
listener.close()
except Exception:
log.exception(level="warning")
log.swallow_exception(level="warning")
def connections():
@ -442,7 +442,7 @@ def inject(pid, debugpy_args):
stderr=subprocess.STDOUT,
)
except Exception as exc:
log.exception("Failed to inject debug server into process with PID={0}", pid)
log.swallow_exception("Failed to inject debug server into process with PID={0}", pid)
raise messaging.MessageHandlingError(
fmt(
"Failed to inject debug server into process with PID={0}: {1}", pid, exc

6
src/debugpy/adapter/sessions.py
View file

@ -163,7 +163,7 @@ class Session(util.Observable):
except Exception:
# Finalization should never fail, and if it does, the session is in an
# indeterminate and likely unrecoverable state, so just fail fast.
log.exception("Fatal error while finalizing {0}", self)
log.swallow_exception("Fatal error while finalizing {0}", self)
os._exit(1)
log.info("{0} finalized.", self)
@ -215,7 +215,7 @@ class Session(util.Observable):
try:
self.launcher.channel.close()
except Exception:
log.exception()
log.swallow_exception()
if self.client:
if self.client.is_connected:
@ -253,7 +253,7 @@ class Session(util.Observable):
try:
os.kill(conn.pid, signal.SIGTERM)
except Exception:
log.exception("Failed to kill {0}", conn)
log.swallow_exception("Failed to kill {0}", conn)
pids_killed.add(conn.pid)

51
src/debugpy/common/log.py
View file

@ -152,8 +152,7 @@ def write_format(level, format_string, *args, **kwargs):
try:
text = fmt(format_string, *args, **kwargs)
except Exception:
exception()
raise
reraise_exception()
return write(level, text, kwargs.pop("_to_files", all))
@ -178,26 +177,7 @@ def error(*args, **kwargs):
return AssertionError(write_format("error", *args, **kwargs))
def exception(format_string="", *args, **kwargs):
"""Logs an exception with full traceback.
If format_string is specified, it is formatted with fmt(*args, **kwargs), and
prepended to the exception traceback on a separate line.
If exc_info is specified, the exception it describes will be logged. Otherwise,
sys.exc_info() - i.e. the exception being handled currently - will be logged.
If level is specified, the exception will be logged as a message of that level.
The default is "error".
Returns the exception object, for convenient re-raising::
try:
...
except Exception:
raise log.exception() # log it and re-raise
"""
def _exception(format_string="", *args, **kwargs):
level = kwargs.pop("level", "error")
exc_info = kwargs.pop("exc_info", sys.exc_info())
@ -218,7 +198,30 @@ def exception(format_string="", *args, **kwargs):
level, format_string, *args, exception=exception, stack=stack, **kwargs
)
return exc_info[1]
def swallow_exception(format_string="", *args, **kwargs):
"""Logs an exception with full traceback.
If format_string is specified, it is formatted with fmt(*args, **kwargs), and
prepended to the exception traceback on a separate line.
If exc_info is specified, the exception it describes will be logged. Otherwise,
sys.exc_info() - i.e. the exception being handled currently - will be logged.
If level is specified, the exception will be logged as a message of that level.
The default is "error".
"""
_exception(format_string, *args, **kwargs)
def reraise_exception(format_string="", *args, **kwargs):
"""Like swallow_exception(), but re-raises the current exception after logging it.
"""
assert "exc_info" not in kwargs
_exception(format_string, *args, **kwargs)
raise
def to_file(filename=None, prefix=None, levels=LEVELS):
@ -300,7 +303,7 @@ def describe_environment(header):
report("{0}<missing>\n", prefix)
return
except Exception:
exception(
swallow_exception(
"Error evaluating {0}",
repr(expr) if expr else compat.srcnameof(get_paths),
)

36
src/debugpy/common/messaging.py
View file

@ -177,7 +177,7 @@ class JsonIOStream(object):
# read() or write(), which is a common and expected occurrence with
# JsonMessageChannel, so don't even bother logging it.
if sys.version_info >= (3,):
raise log.exception("Error while closing {0} message stream", self.name)
log.reraise_exception("Error while closing {0} message stream", self.name)
def _log_message(self, dir, data, logger=log.debug):
format_string = "{0} {1} " + (
@ -190,8 +190,8 @@ class JsonIOStream(object):
while True:
try:
line += reader.readline()
except Exception as ex:
raise NoMoreMessages(str(ex), stream=self)
except Exception as exc:
raise NoMoreMessages(str(exc), stream=self)
if not line:
raise NoMoreMessages(stream=self)
if line.endswith(b"\r\n"):
@ -212,7 +212,7 @@ class JsonIOStream(object):
# If any error occurs while reading and parsing the message, log the original
# raw message data as is, so that it's possible to diagnose missing or invalid
# headers, encoding issues, JSON syntax errors etc.
def log_message_and_exception(format_string="", *args, **kwargs):
def log_message_and_reraise_exception(format_string="", *args, **kwargs):
if format_string:
format_string += "\n\n"
format_string += "{name} -->\n{raw_lines}"
@ -220,7 +220,7 @@ class JsonIOStream(object):
raw_lines = b"".join(raw_chunks).split(b"\n")
raw_lines = "\n".join(repr(line) for line in raw_lines)
return log.exception(
log.reraise_exception(
format_string, *args, name=self.name, raw_lines=raw_lines, **kwargs
)
@ -236,8 +236,9 @@ class JsonIOStream(object):
# there's no message data to log in any case, and the caller might
# be anticipating the error - e.g. NoMoreMessages on disconnect.
if headers:
log_message_and_exception("Error while reading message headers:")
raise
log_message_and_reraise_exception("Error while reading message headers:")
else:
raise
raw_chunks += [line, b"\n"]
if line == b"":
@ -254,7 +255,7 @@ class JsonIOStream(object):
try:
raise IOError("Content-Length is missing or invalid:")
except Exception:
raise log_message_and_exception()
log_message_and_reraise_exception()
body_start = len(raw_chunks)
body_remaining = length
@ -265,9 +266,6 @@ class JsonIOStream(object):
raise EOFError
except Exception as exc:
# Not logged due to https://github.com/microsoft/ptvsd/issues/1699
# log_message_and_exception(
# "Couldn't read the expected {0} bytes of body:", length
# )
raise NoMoreMessages(str(exc), stream=self)
raw_chunks.append(chunk)
@ -278,12 +276,12 @@ class JsonIOStream(object):
try:
body = body.decode("utf-8")
except Exception:
raise log_message_and_exception()
log_message_and_reraise_exception()
try:
body = decoder.decode(body)
except Exception:
raise log_message_and_exception()
log_message_and_reraise_exception()
# If parsed successfully, log as JSON for readability.
self._log_message("-->", body)
@ -628,7 +626,7 @@ class Event(Message):
str(exc),
)
except Exception:
raise log.exception(
log.reraise_exception(
"Handler {0}\ncouldn't handle {1}:",
compat.srcnameof(handler),
self.describe(),
@ -785,7 +783,7 @@ class Request(Message):
)
except Exception:
raise log.exception(
log.reraise_exception(
"Handler {0}\ncouldn't handle {1}:",
compat.srcnameof(handler),
self.describe(),
@ -868,7 +866,7 @@ class OutgoingRequest(Request):
str(exc),
)
except Exception:
raise log.exception(
log.reraise_exception(
"Handler {0}\ncouldn't handle {1}:",
compat.srcnameof(handler),
response.describe(),
@ -1059,7 +1057,7 @@ class MessageHandlingError(Exception):
try:
raise self
except MessageHandlingError:
log.exception()
log.swallow_exception()
def __hash__(self):
return hash((self.reason, id(self.cause)))
@ -1423,7 +1421,7 @@ class JsonMessageChannel(object):
except Exception as exc:
if isinstance(exc, NoMoreMessages) and exc.stream is self.stream:
raise
log.exception(
log.swallow_exception(
"Fatal error in channel {0} while parsing:\n{1!j}", self, message_dict
)
os._exit(1)
@ -1533,7 +1531,7 @@ class JsonMessageChannel(object):
try:
handler()
except Exception:
raise log.exception(
log.reraise_exception(
"Handler {0}\ncouldn't handle disconnect from {1}:",
compat.srcnameof(handler),
self,

2
src/debugpy/common/sockets.py
View file

@ -68,7 +68,7 @@ def serve(name, handler, host, port=0, backlog=socket.SOMAXCONN, timeout=None):
try:
listener = create_server(host, port, backlog, timeout)
except Exception:
raise log.exception(
log.reraise_exception(
"Error listening for incoming {0} connections on {1}:{2}:", name, host, port
)
host, port = listener.getsockname()

2
src/debugpy/common/stacks.py
View file

@ -59,7 +59,7 @@ def dump_after(secs):
try:
dump()
except:
log.exception()
log.swallow_exception()
thread = threading.Thread(target=dumper)
thread.daemon = True

2
src/debugpy/launcher/__main__.py
View file

@ -35,7 +35,7 @@ def main():
try:
return type(os.environ.pop(name, *args))
except Exception:
raise log.exception("Error parsing {0!r}:", name)
log.reraise_exception("Error parsing {0!r}:", name)
launcher_port = option("DEBUGPY_LAUNCHER_PORT", int)

6
src/debugpy/launcher/debuggee.py
View file

@ -92,7 +92,7 @@ def spawn(process_name, cmdline, cwd, env, redirect_output):
try:
os.close(fd)
except Exception:
log.exception()
log.swallow_exception()
def kill():
@ -103,7 +103,7 @@ def kill():
log.info("Killing {0}", describe())
process.kill()
except Exception:
log.exception("Failed to kill {0}", describe())
log.swallow_exception("Failed to kill {0}", describe())
def wait_for_exit():
@ -116,7 +116,7 @@ def wait_for_exit():
# taking the lowest 8 bits of that negative returncode.
code &= 0xFF
except Exception:
log.exception("Couldn't determine process exit code:")
log.swallow_exception("Couldn't determine process exit code:")
code = -1
log.info("{0} exited with code {1}", describe(), code)

12
src/debugpy/server/api.py
View file

@ -121,7 +121,7 @@ def _starts_debugging(func):
try:
return func(address, settrace_kwargs, **kwargs)
except Exception:
raise log.exception("{0}() failed:", func.__name__, level="info")
log.reraise_exception("{0}() failed:", func.__name__, level="info")
return debug
@ -138,7 +138,7 @@ def listen(address, settrace_kwargs):
try:
endpoints_listener = sockets.create_server("127.0.0.1", 0, timeout=10)
except Exception as exc:
log.exception("Can't listen for adapter endpoints:")
log.swallow_exception("Can't listen for adapter endpoints:")
raise RuntimeError("can't listen for adapter endpoints: " + str(exc))
endpoints_host, endpoints_port = endpoints_listener.getsockname()
log.info(
@ -188,7 +188,7 @@ def listen(address, settrace_kwargs):
_adapter_process.returncode = 0
pydevd.add_dont_terminate_child_pid(_adapter_process.pid)
except Exception as exc:
log.exception("Error spawning debug adapter:", level="info")
log.swallow_exception("Error spawning debug adapter:", level="info")
raise RuntimeError("error spawning debug adapter: " + str(exc))
try:
@ -203,10 +203,10 @@ def listen(address, settrace_kwargs):
finally:
sockets.close_socket(sock)
except socket.timeout:
log.exception("Timed out waiting for adapter to connect:", level="info")
log.swallow_exception("Timed out waiting for adapter to connect:", level="info")
raise RuntimeError("timed out waiting for adapter to connect")
except Exception as exc:
log.exception("Error retrieving adapter endpoints:", level="info")
log.swallow_exception("Error retrieving adapter endpoints:", level="info")
raise RuntimeError("error retrieving adapter endpoints: " + str(exc))
log.info("Endpoints received from adapter: {0!j}", endpoints)
@ -220,7 +220,7 @@ def listen(address, settrace_kwargs):
client_host = str(endpoints["client"]["host"])
client_port = int(endpoints["client"]["port"])
except Exception as exc:
log.exception(
log.swallow_exception(
"Error parsing adapter endpoints:\n{0!j}\n", endpoints, level="info"
)
raise RuntimeError("error parsing adapter endpoints: " + str(exc))

7
src/debugpy/server/attach_pid_injected.py
View file

@ -86,8 +86,9 @@ def attach(setup):
import traceback
traceback.print_exc()
if log is not None:
log.exception()
raise
if log is None:
raise
else:
log.reraise_exception()
log.info("debugpy injected successfully")

13
src/debugpy/server/cli.py
View file

@ -284,7 +284,7 @@ def run_module():
else:
_, _, _, argv_0 = runpy._get_module_details(options.target)
except Exception:
log.exception("Error determining module path for sys.argv")
log.swallow_exception("Error determining module path for sys.argv")
start_debugging(argv_0)
@ -392,7 +392,7 @@ attach_pid_injected.attach(setup);
show_debug_info=int(os.getenv("DEBUGPY_ATTACH_BY_PID_DEBUG_INFO", "0")),
)
except Exception:
raise log.exception("Code injection into PID={0} failed:", pid)
log.reraise_exception("Code injection into PID={0} failed:", pid)
log.info("Code injection into PID={0} completed.", pid)
@ -400,8 +400,8 @@ def main():
original_argv = list(sys.argv)
try:
parse_argv()
except Exception as ex:
print(HELP + "\nError: " + str(ex), file=sys.stderr)
except Exception as exc:
print(HELP + "\nError: " + str(exc), file=sys.stderr)
sys.exit(2)
if options.log_to is not None:
@ -425,6 +425,5 @@ def main():
"pid": attach_to_pid,
}[options.target_kind]
run()
except SystemExit as ex:
log.exception("Debuggee exited via SystemExit: {0!r}", ex.code, level="debug")
raise
except SystemExit as exc:
log.reraise_exception("Debuggee exited via SystemExit: {0!r}", exc.code, level="debug")

4
tests/debug/comms.py
View file

@ -47,12 +47,12 @@ class BackChannel(object):
if self._server_socket is None:
return
else:
raise log.exception("Timed out waiting for {0} to connect", self)
log.reraise_exception("Timed out waiting for {0} to connect", self)
except Exception:
if self._server_socket is None:
return
else:
raise log.exception("Error accepting connection for {0}:", self)
log.reraise_exception("Error accepting connection for {0}:", self)
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
log.info("Incoming connection from {0} accepted.", self)

4
tests/debug/session.py
View file

@ -227,7 +227,7 @@ class Session(object):
self.wait_for_exit()
else:
# Log the error, in case another one happens during shutdown.
log.exception(exc_info=(exc_type, exc_val, exc_tb))
log.swallow_exception(exc_info=(exc_type, exc_val, exc_tb))
if exc_type is None:
self.disconnect()
@ -498,7 +498,7 @@ class Session(object):
self.spawn_debuggee(args, cwd, exe=exe)
return {}
except OSError as exc:
log.exception('"runInTerminal" failed:')
log.swallow_exception('"runInTerminal" failed:')
raise request.cant_handle(str(exc))
else:
raise request.isnt_valid("not supported")

4
tests/debugpy/test_path_mapping.py
View file

@ -134,8 +134,8 @@ def test_with_path_mappings(pyfile, long_tmpdir, target, run):
try:
session.request("source", {"sourceReference": 0})
except Exception as ex:
assert "Source unavailable" in str(ex)
except Exception as exc:
assert "Source unavailable" in str(exc)
else:
pytest.fail("sourceReference=0 should not be valid")

2
tests/net.py
View file

@ -130,7 +130,7 @@ class WebRequest(object):
self.request = func(self.url, *args, **kwargs)
except Exception as exc:
if self.log_errors:
log.exception("{0} failed:", self)
log.swallow_exception("{0} failed:", self)
self.exception = exc
else:
log.info(

4
tests/watchdog/__init__.py
View file

@ -74,7 +74,7 @@ def _dump_worker_log(command, problem, exc_info=None):
if exc_info is None:
log.error("{0}", reason)
else:
log.exception("{0}", reason, exc_info=exc_info)
log.swallow_exception("{0}", reason, exc_info=exc_info)
return reason
@ -111,7 +111,7 @@ def stop():
_invoke("stop")
_stream.close()
except Exception:
log.exception()
log.swallow_exception()
def register_spawn(pid, name):

10
tests/watchdog/worker.py
View file

@ -93,15 +93,15 @@ def main(tests_pid):
stream.write_json(["ok"])
except Exception as ex:
stream.write_json(["error", str(ex)])
raise log.exception()
except Exception as exc:
stream.write_json(["error", str(exc)])
log.reraise_exception()
finally:
try:
stream.close()
except Exception:
log.exception()
log.swallow_exception()
# If the test runner becomes a zombie process, it is still considered alive,
# and wait() will block indefinitely. Poll status instead.
@ -156,7 +156,7 @@ def main(tests_pid):
except psutil.NoSuchProcess:
pass
except Exception:
log.exception()
log.swallow_exception()
log.info("WatchDog-{0} exiting", tests_pid)