def spawn_adapter(self):
assert self.adapter is None
assert self.channel is None
args = [sys.executable, os.path.dirname(ptvsd.adapter.__file__)]
env = self._make_env(self.spawn_adapter.env)
log.info(
"Spawning {0}:\n\n"
"Command line: {1!j}\n\n"
"Environment variables: {2!j}\n\n",
self.adapter_id,
args,
env,
)
self.adapter = psutil.Popen(
args,
bufsize=0,
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
env=env.for_popen(),
)
log.info("Spawned {0} with PID={1}", self.adapter_id, self.adapter.pid)
watchdog.register_spawn(self.adapter.pid, self.adapter_id)
stream = messaging.JsonIOStream.from_process(self.adapter,
name=self.adapter_id)
self._start_channel(stream)
def notify_of_subprocess(self, conn):
with self.session:
if self.start_request is None or conn in self._known_subprocesses:
return
if "processId" in self.start_request.arguments:
log.warning(
"Not reporting subprocess for {0}, because the parent process "
'was attached to using "processId" rather than "port".',
self.session,
)
return
log.info("Notifying {0} about {1}.", self, conn)
body = dict(self.start_request.arguments)
self._known_subprocesses.add(conn)
body["name"] = fmt("Subprocess {0}", conn.pid)
body["request"] = "attach"
if "host" not in body:
body["host"] = "127.0.0.1"
if "port" not in body:
_, body["port"] = self.listener.getsockname()
if "processId" in body:
del body["processId"]
body["subProcessId"] = conn.pid
self.channel.send_event("ptvsd_attach", body)
def listen(cls, host=None, port=0, timeout=None):
"""Accepts TCP connections on the specified host and port, and creates a new
instance of this class wrapping every accepted socket.
"""
assert cls.listener is None
cls.listener = create_server(host, port, timeout)
host, port = cls.listener.getsockname()
log.info(
"Waiting for incoming {0} connections on {1}:{2}...",
cls.__name__,
host,
port,
)
def accept_worker():
while True:
sock, (other_host, other_port) = cls.listener.accept()
log.info(
"Accepted incoming {0} connection from {1}:{2}.",
cls.__name__,
other_host,
other_port,
)
cls(sock)
thread = threading.Thread(target=accept_worker)
thread.daemon = True
thread.pydev_do_not_trace = True
thread.is_pydev_daemon_thread = True
thread.start()
return host, port
def main():
original_argv = list(sys.argv)
try:
sys.argv[1:] = parse(sys.argv[1:])
except Exception as ex:
print(HELP + "\nError: " + str(ex), file=sys.stderr)
sys.exit(2)
log.to_file(prefix="ptvsd.server")
log.describe_environment("ptvsd.server startup environment:")
log.info(
"sys.argv before parsing: {0!r}\n"
" after parsing: {1!r}",
original_argv,
sys.argv,
)
try:
run = {
"file": run_file,
"module": run_module,
"code": run_code,
"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
def launch(session, target, console="integratedTerminal", cwd=None):
assert console in ("internalConsole", "integratedTerminal", "externalTerminal")
log.info("Launching {0} in {1} using {2!j}.", target, session, console)
target.configure(session)
config = session.config
config.setdefaults(
{
"console": "externalTerminal",
"internalConsoleOptions": "neverOpen",
"pythonPath": sys.executable,
}
)
config["console"] = console
if cwd is not None:
config["cwd"] = cwd
env = (
session.spawn_adapter.env
if config["console"] == "internalConsole"
else config.env
)
target.cli(env)
session.spawn_adapter()
return session.request_launch()
def _send_requests_and_events(self, channel):
types = [
random.choice(("event", "request")) for _ in range(0, 100)
]
for typ in types:
name = random.choice(("fizz", "buzz", "fizzbuzz"))
body = random.randint(0, 100)
with self.lock:
self.sent.append((typ, name, body))
if typ == "event":
channel.send_event(name, body)
elif typ == "request":
req = channel.send_request(name, body)
req.on_response(self._got_response)
channel.send_event("done")
# Spin until we receive "done", and also get responses to all requests.
requests_sent = types.count("request")
log.info("{0} waiting for {1} responses...", self.name,
requests_sent)
while True:
with self.lock:
if self.done:
if requests_sent == len(self.responses_received):
break
time.sleep(0.1)
def inject(pid, ptvsd_args):
host, port = Connection.listener.getsockname()
cmdline = [
sys.executable,
compat.filename(os.path.dirname(ptvsd.__file__)),
"--client",
"--host",
host,
"--port",
str(port),
]
cmdline += ptvsd_args
cmdline += ["--pid", str(pid)]
log.info("Spawning attach-to-PID debugger injector: {0!r}", cmdline)
try:
subprocess.Popen(
cmdline,
bufsize=0,
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
)
except Exception as exc:
log.exception(
"Failed to inject debug server into process with PID={0}", pid)
raise messaging.MessageHandlingError(
"Failed to inject debug server into process with PID={0}: {1}",
pid, exc)
def wait_for_enable_attach(self):
log.info(
"Waiting for debug server in {0} to open a listener socket...",
self.debuggee_id,
)
while not self.listener_file.check():
time.sleep(0.1)
def finalize(self, why, terminate_debuggee=False):
"""Finalizes the debug session.
If the server is present, sends "disconnect" request with "terminateDebuggee"
set as specified) request to it; waits for it to disconnect, allowing any
remaining messages from it to be handled; and closes the server channel.
If the launcher is present, sends "terminate" request to it, regardless of the
value of terminate; waits for it to disconnect, allowing any remaining messages
from it to be handled; and closes the launcher channel.
If the IDE is present, sends "terminated" event to it.
"""
if self.is_finalizing:
return
self.is_finalizing = True
log.info("{0}; finalizing {1}.", why, self)
try:
self._finalize(why, terminate_debuggee)
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)
os._exit(1)
log.info("{0} finalized.", self)
def inject_server(self, pid, ptvsd_args):
with self.accept_connection_from_server() as (host, port):
cmdline = [
sys.executable,
compat.filename(os.path.dirname(ptvsd.__file__)),
"--client",
"--host",
host,
"--port",
str(port),
]
cmdline += ptvsd_args
cmdline += ["--pid", str(pid)]
log.info("{0} spawning attach-to-PID debugger injector: {1!r}",
self, cmdline)
try:
subprocess.Popen(
cmdline,
bufsize=0,
stdin=subprocess.PIPE,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
)
except Exception as exc:
log.exception("{0} failed to inject debugger", self)
raise messaging.MessageHandlingError(
fmt("Failed to inject debugger: {0}", exc))
def test_wrapper(request, long_tmpdir):
def write_log(filename, data):
filename = os.path.join(log.log_dir, filename)
if not isinstance(data, bytes):
data = data.encode("utf-8")
with open(filename, "wb") as f:
f.write(data)
session.Session.reset_counter()
session.Session.tmpdir = long_tmpdir
original_log_dir = log.log_dir
try:
if log.log_dir is None:
log.log_dir = (long_tmpdir / "ptvsd_logs").strpath
else:
log_subdir = request.node.nodeid
log_subdir = log_subdir.replace("::", "/")
for ch in r":?*|<>":
log_subdir = log_subdir.replace(ch, fmt("&#{0};", ord(ch)))
log.log_dir += "/" + log_subdir
try:
py.path.local(log.log_dir).remove()
except Exception:
pass
print("\n") # make sure on-screen logs start on a new line
with log.to_file(prefix="tests"):
timestamp.reset()
log.info("{0} started.", request.node.nodeid)
try:
yield
finally:
failed = False
for report_attr in ("setup_report", "call_report", "teardown_report"):
try:
report = getattr(request.node, report_attr)
except AttributeError:
continue
failed |= report.failed
log.write_format(
"error" if report.failed else "info",
"pytest {0} phase for {1} {2}.",
report.when,
request.node.nodeid,
report.outcome,
)
write_log(report_attr + ".log", report.longreprtext)
write_log(report_attr + ".stdout.log", report.capstdout)
write_log(report_attr + ".stderr.log", report.capstderr)
if failed:
write_log("FAILED.log", "")
logs.dump()
finally:
log.log_dir = original_log_dir
def attach_by_pid(session, target, cwd=None, wait=True):
if platform.system() != "Windows":
pytest.skip("https://github.com/microsoft/ptvsd/issues/1810")
if sys.version_info < (3, ):
pytest.skip("https://github.com/microsoft/ptvsd/issues/1811")
log.info("Attaching {0} to {1} by PID.", session, target)
config = session.config
try:
config["processId"] = int(target)
except TypeError:
pass
if "processId" not in config:
_attach_common_config(session, target, cwd)
args = target.cli(session.spawn_debuggee.env)
if wait:
debug_me = """
import sys
while not "ptvsd" in sys.modules: pass
import ptvsd
while not ptvsd.is_attached(): pass
"""
else:
debug_me = None
session.spawn_debuggee(args, cwd=cwd, debug_me=debug_me)
config["processId"] = session.debuggee.pid
session.spawn_adapter()
return session.request_attach()
def wait_for_exit():
from ptvsd.launcher import adapter, output
try:
code = process.wait()
if platform.system() != "Windows" and code < 0:
# On POSIX, if the process was terminated by a signal, Popen will use
# a negative returncode to indicate that - but the actual exit code of
# the process is always an unsigned number, and can be determined by
# taking the lowest 8 bits of that negative returncode.
code &= 0xFF
except Exception:
log.exception("Couldn't determine process exit code:")
code = -1
log.info("{0} exited with code {1}", describe(), code)
output.wait_for_remaining_output()
try:
adapter.channel.send_event("exited", {"exitCode": code})
except Exception:
pass
if any(pred(code) for pred in wait_on_exit_predicates):
_wait_for_user_input()
try:
adapter.channel.send_event("terminated")
except Exception:
pass
def _propagate_deferred_events(self):
log.debug("Propagating deferred events to {0}...", self.ide)
for event in self._deferred_events:
log.debug("Propagating deferred {0}", event.describe())
self.ide.channel.propagate(event)
log.info("All deferred events propagated to {0}.", self.ide)
self._deferred_events = None
def __init__(self, method, url, *args, **kwargs):
"""Invokes requests.method(url, *args, **kwargs) on a background thread,
and immediately returns.
If method() raises an exception, it is logged, unless log_errors=False.
"""
self.method = method
self.url = url
self.log_errors = kwargs.pop("log_errors", True)
self.request = None
"""The underlying requests.Request object.
Not set until wait_for_response() returns.
"""
self.exception = None
"""Exception that occurred while performing the request, if any.
Not set until wait_for_response() returns.
"""
log.info("{0}", self)
func = getattr(requests, method)
self._worker_thread = threading.Thread(
target=lambda: self._worker(func, *args, **kwargs),
name=fmt("WebRequest({0})", self),
)
self._worker_thread.daemon = True
self._worker_thread.start()
def wait_for_exit():
try:
code = process.wait()
if sys.platform != "win32" and code < 0:
# On POSIX, if the process was terminated by a signal, Popen will use
# a negative returncode to indicate that - but the actual exit code of
# the process is always an unsigned number, and can be determined by
# taking the lowest 8 bits of that negative returncode.
code &= 0xFF
except Exception:
log.exception("Couldn't determine process exit code:")
code = -1
log.info("{0} exited with code {1}", describe(), code)
output.wait_for_remaining_output()
# Determine whether we should wait or not before sending "exited", so that any
# follow-up "terminate" requests don't affect the predicates.
should_wait = any(pred(code) for pred in wait_on_exit_predicates)
try:
launcher.channel.send_event("exited", {"exitCode": code})
except Exception:
pass
if should_wait:
_wait_for_user_input()
try:
launcher.channel.send_event("terminated")
except Exception:
pass
def wait_for_connection(session, predicate, timeout=None):
"""Waits until there is a server with the specified PID connected to this adapter,
and returns the corresponding Connection.
If there is more than one server connection already available, returns the oldest
one.
"""
def wait_for_timeout():
time.sleep(timeout)
wait_for_timeout.timed_out = True
with _lock:
_connections_changed.set()
wait_for_timeout.timed_out = timeout == 0
if timeout:
thread = threading.Thread(target=wait_for_timeout,
name="servers.wait_for_connection() timeout")
thread.daemon = True
thread.start()
if timeout != 0:
log.info("{0} waiting for connection from debug server...", session)
while True:
with _lock:
_connections_changed.clear()
conns = (conn for conn in _connections if predicate(conn))
conn = next(conns, None)
if conn is not None or wait_for_timeout.timed_out:
return conn
_connections_changed.wait()
def capture_output():
while True:
line = injector.stdout.readline()
if not line:
break
log.info("Injector[PID={0}] output:\n{1}", pid, line.rstrip())
log.info("Injector[PID={0}] exited.", pid)
def debug(address, log_dir=None, multiprocess=True):
if log_dir:
log.log_dir = log_dir
log.to_file(prefix="ptvsd.server")
log.describe_environment("ptvsd.server debug start environment:")
log.debug("{0}{1!r}", func.__name__, (address, log_dir, multiprocess))
if is_attached():
log.info("{0}() ignored - already attached.", func.__name__)
return options.host, options.port
# Ensure port is int
if address is not options:
host, port = address
options.host, options.port = (host, int(port))
if multiprocess is not options:
options.multiprocess = multiprocess
ptvsd_path, _, _ = get_abs_path_real_path_and_base_from_file(ptvsd.__file__)
ptvsd_path = os.path.dirname(ptvsd_path)
start_patterns = (ptvsd_path,)
end_patterns = ("ptvsd_launcher.py",)
log.info(
"Won't trace filenames starting with: {0!j}\n"
"Won't trace filenames ending with: {1!j}",
start_patterns,
end_patterns,
)
try:
return func(start_patterns, end_patterns)
except Exception:
raise log.exception("{0}() failed:", func.__name__, level="info")
def wait_for_remaining_output():
"""Waits for all remaining output to be captured and propagated.
"""
for category, instance in CaptureOutput.instances.items():
log.info("Waiting for remaining {0} of {1}.", category,
debuggee.describe())
instance._worker_thread.join()
def wait_until_port_is_listening(port, interval=1, max_attempts=1000):
"""Blocks until the specified TCP port on localhost is listening, and can be
connected to.
Tries to connect to the port periodically, and repeats until connection succeeds.
Connection is immediately closed before returning.
"""
for i in compat.xrange(1, max_attempts + 1):
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
try:
log.info("Probing localhost:{0} (attempt {1})...", port, i)
sock.connect(("localhost", port))
except socket.error as exc:
# The first attempt will almost always fail, because the port isn't
# open yet. But if it keeps failing after that, we want to know why.
if i > 1:
log.warning("Failed to connect to localhost:{0}:\n{1}", port,
exc)
time.sleep(interval)
else:
log.info("localhost:{0} is listening - server is up!", port)
return
finally:
sock.close()
def _explain_how_realized(self, expectation, reasons):
message = fmt("Realized {0!r}", expectation)
# For the breakdown, we want to skip any expectations that were exact occurrences,
# since there's no point explaining that occurrence was realized by itself.
skip = [exp for exp in reasons.keys() if isinstance(exp, Occurrence)]
for exp in skip:
reasons.pop(exp, None)
if reasons == {expectation: some.object}:
# If there's only one expectation left to explain, and it's the top-level
# one, then we have already printed it, so just add the explanation.
reason = reasons[expectation]
if "\n" in message:
message += fmt(" == {0!r}", reason)
else:
message += fmt("\n == {0!r}", reason)
elif reasons:
# Otherwise, break it down expectation by expectation.
message += ":"
for exp, reason in reasons.items():
message += fmt("\n\n where {0!r}\n == {1!r}", exp,
reason)
else:
message += "."
log.info("{0}", message)
def accept_worker():
log.info(
"Listening for incoming connection from {0} on port {1}...",
self,
self.port,
)
server_socket = self._server_socket
if server_socket is None:
return # concurrent close()
try:
sock, _ = server_socket.accept()
except socket.timeout:
if self._server_socket is None:
return
else:
raise log.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)
sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
log.info("Incoming connection from {0} accepted.", self)
self._socket = sock
self._setup_stream()
def __exit__(self, exc_type, exc_val, exc_tb):
log.info("Ending {0}.", self)
if self.timeline.is_frozen:
self.timeline.unfreeze()
# Only wait for exit if there was no exception in the test - if there was one,
# the debuggee might still be waiting for further requests.
if exc_type is None:
# If expected_exit_code is set to None, the debuggee is not expected to
# exit after this Session is closed (e.g. because another Session will
# attach to it later on).
if self.expected_exit_code is not None:
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))
if exc_type is None:
self.disconnect()
self.timeline.close()
else:
# If there was an exception, don't try to send any more messages to avoid
# spamming log with irrelevant entries - just close the channel and kill
# all the processes immediately. Don't close or finalize the timeline,
# either, since it'll likely have unobserved events in it.
if self.adapter is not None:
log.info("Killing {0}.", self.adapter_id)
try:
self.adapter.kill()
except Exception:
pass
if self.debuggee is not None:
log.info("Killing {0}.", self.debuggee_id)
try:
self.debuggee.kill()
except Exception:
pass
self.disconnect(force=True)
if self.adapter_endpoints is not None and self.expected_exit_code is not None:
log.info("Waiting for {0} to close listener ports ...",
self.adapter_id)
while self.adapter_endpoints.check():
time.sleep(0.1)
if self.adapter is not None:
log.info(
"Waiting for {0} with PID={1} to exit.",
self.adapter_id,
self.adapter.pid,
)
self.adapter.wait()
watchdog.unregister_spawn(self.adapter.pid, self.adapter_id)
self.adapter = None
if self.backchannel is not None:
self.backchannel.close()
self.backchannel = None
def enable_or_disable(enable):
if enable:
log.info("Enabling tracing on thread {0}", tid)
pydb.enable_tracing()
else:
log.info("Disabling tracing on thread {0}", tid)
pydb.disable_tracing()
_tls.is_tracing = enable
def wait_until_realized(self,
expectation,
freeze=None,
explain=True,
observe=True):
if explain:
log.info("Waiting for {0!r}", expectation)
return self._wait_until_realized(expectation, freeze, explain, observe)
def test_docstrings():
for attr in ptvsd.__all__:
log.info("Checking docstring for ptvsd.{0}", attr)
member = getattr(ptvsd, attr)
doc = inspect.getdoc(member)
for lineno, line in enumerate(doc.split("\n")):
assert len(line) <= 72
def delete_listener_file():
log.info("Listener ports closed; deleting {0!r}", listener_file)
try:
os.remove(listener_file)
except Exception:
log.exception("Failed to delete {0!r}",
listener_file,
level="warning")
def _finalize(self, why, terminate_debuggee):
# If the IDE started a session, and then disconnected before issuing "launch"
# or "attach", the main thread will be blocked waiting for the first server
# connection to come in - unblock it, so that we can exit.
servers.dont_wait_for_first_connection()
if self.server:
if self.server.is_connected:
if terminate_debuggee and self.launcher and self.launcher.is_connected:
# If we were specifically asked to terminate the debuggee, and we
# can ask the launcher to kill it, do so instead of disconnecting
# from the server to prevent debuggee from running any more code.
self.launcher.terminate_debuggee()
else:
# Otherwise, let the server handle it the best it can.
try:
self.server.channel.request(
"disconnect",
{"terminateDebuggee": terminate_debuggee})
except Exception:
pass
self.server.detach_from_session()
if self.launcher and self.launcher.is_connected:
# If there was a server, we just disconnected from it above, which should
# cause the debuggee process to exit - so let's wait for that first.
if self.server:
log.info('{0} waiting for "exited" event...', self)
if not self.wait_for(
lambda: self.launcher.exit_code is not None,
timeout=5):
log.warning('{0} timed out waiting for "exited" event.',
self)
# Terminate the debuggee process if it's still alive for any reason -
# whether it's because there was no server to handle graceful shutdown,
# or because the server couldn't handle it for some reason.
self.launcher.terminate_debuggee()
# Wait until the launcher message queue fully drains. There is no timeout
# here, because the final "terminated" event will only come after reading
# user input in wait-on-exit scenarios.
log.info("{0} waiting for {1} to disconnect...", self,
self.launcher)
self.wait_for(lambda: not self.launcher.is_connected)
try:
self.launcher.channel.close()
except Exception:
log.exception()
# Tell the IDE that debugging is over, but don't close the channel until it
# tells us to, via the "disconnect" request.
if self.ide and self.ide.is_connected:
try:
self.ide.channel.send_event("terminated")
except Exception:
pass
def wait_for_next(self,
expectation,
freeze=True,
explain=True,
observe=True):
if explain:
log.info("Waiting for next {0!r}", expectation)
return self._wait_until_realized(self._proceeding_from >> expectation,
freeze, explain, observe)