From e8d62eef5f079a0b5a7c8ec970e2d3e3c73618a9 Mon Sep 17 00:00:00 2001 From: Fabio Zadrozny Date: Fri, 14 Oct 2022 16:29:34 -0300 Subject: [PATCH] Provide feedback/information in the debug console if attach to PID is slow. Fixes #1003 --- .../add_code_to_python_process.py | 7 +- src/debugpy/adapter/clients.py | 25 +++- src/debugpy/adapter/servers.py | 127 +++++++++++++++--- 3 files changed, 139 insertions(+), 20 deletions(-) diff --git a/src/debugpy/_vendored/pydevd/pydevd_attach_to_process/add_code_to_python_process.py b/src/debugpy/_vendored/pydevd/pydevd_attach_to_process/add_code_to_python_process.py index 462feae9b..03fe50c65 100644 --- a/src/debugpy/_vendored/pydevd/pydevd_attach_to_process/add_code_to_python_process.py +++ b/src/debugpy/_vendored/pydevd/pydevd_attach_to_process/add_code_to_python_process.py @@ -278,6 +278,7 @@ def run_python_code_windows(pid, python_code, connect_debugger_tracing=False, sh with _acquire_mutex('_pydevd_pid_attach_mutex_%s' % (pid,), 10): print('--- Connecting to %s bits target (current process is: %s) ---' % (bits, 64 if is_python_64bit() else 32)) + sys.stdout.flush() with _win_write_to_shared_named_memory(python_code, pid): @@ -290,6 +291,7 @@ def run_python_code_windows(pid, python_code, connect_debugger_tracing=False, sh raise RuntimeError('Could not find expected .dll file in attach to process.') print('\n--- Injecting attach dll: %s into pid: %s ---' % (os.path.basename(target_dll), pid)) + sys.stdout.flush() args = [target_executable, str(pid), target_dll] subprocess.check_call(args) @@ -301,12 +303,15 @@ def run_python_code_windows(pid, python_code, connect_debugger_tracing=False, sh with _create_win_event('_pydevd_pid_event_%s' % (pid,)) as event: print('\n--- Injecting run code dll: %s into pid: %s ---' % (os.path.basename(target_dll_run_on_dllmain), pid)) + sys.stdout.flush() args = [target_executable, str(pid), target_dll_run_on_dllmain] subprocess.check_call(args) - if not event.wait_for_event_set(10): + if not event.wait_for_event_set(15): print('Timeout error: the attach may not have completed.') + sys.stdout.flush() print('--- Finished dll injection ---\n') + sys.stdout.flush() return 0 diff --git a/src/debugpy/adapter/clients.py b/src/debugpy/adapter/clients.py index c335e0bc2..cc088f1f2 100644 --- a/src/debugpy/adapter/clients.py +++ b/src/debugpy/adapter/clients.py @@ -194,7 +194,6 @@ def initialize_request(self, request): # See https://github.com/microsoft/vscode/issues/4902#issuecomment-368583522 # for the sequence of request and events necessary to orchestrate the start. def _start_message_handler(f): - @components.Component.message_handler def handle(self, request): assert request.is_request("launch", "attach") @@ -465,7 +464,9 @@ def attach_request(self, request): if listen != (): if servers.is_serving(): - raise request.isnt_valid('Multiple concurrent "listen" sessions are not supported') + raise request.isnt_valid( + 'Multiple concurrent "listen" sessions are not supported' + ) host = listen("host", "127.0.0.1") port = listen("port", int) adapter.access_token = None @@ -507,7 +508,25 @@ def attach_request(self, request): except Exception: raise request.isnt_valid('"processId" must be parseable as int') debugpy_args = request("debugpyArgs", json.array(str)) - servers.inject(pid, debugpy_args) + + def on_output(category, output): + self.channel.send_event( + "output", + { + "category": category, + "output": output, + }, + ) + + try: + servers.inject(pid, debugpy_args, on_output) + except Exception as e: + log.swallow_exception() + self.session.finalize( + "Error when trying to attach to PID:\n%s" % (str(e),) + ) + return + timeout = common.PROCESS_SPAWN_TIMEOUT pred = lambda conn: conn.pid == pid else: diff --git a/src/debugpy/adapter/servers.py b/src/debugpy/adapter/servers.py index d41f241e9..47f684a04 100644 --- a/src/debugpy/adapter/servers.py +++ b/src/debugpy/adapter/servers.py @@ -14,7 +14,8 @@ from debugpy import adapter from debugpy.common import json, log, messaging, sockets from debugpy.adapter import components - +import traceback +import io access_token = None """Access token used to authenticate with the servers.""" @@ -471,7 +472,7 @@ def dont_wait_for_first_connection(): _connections_changed.set() -def inject(pid, debugpy_args): +def inject(pid, debugpy_args, on_output): host, port = listener.getsockname() cmdline = [ @@ -504,20 +505,114 @@ def inject(pid, debugpy_args): ) ) - # We need to capture the output of the injector - otherwise it can get blocked - # on a write() syscall when it tries to print something. + # We need to capture the output of the injector - needed so that it doesn't + # get blocked on a write() syscall (besides showing it to the user if it + # is taking longer than expected). + + output_collected = [] + output_collected.append("--- Starting attach to pid: {0} ---\n".format(pid)) - def capture_output(): + def capture(stream): + nonlocal output_collected + try: + while True: + line = stream.readline() + if not line: + break + line = line.decode("utf-8", "replace") + output_collected.append(line) + log.info("Injector[PID={0}] output: {1}", pid, line.rstrip()) + log.info("Injector[PID={0}] exited.", pid) + except Exception: + s = io.StringIO() + traceback.print_exc(file=s) + on_output("stderr", s.getvalue()) + + threading.Thread( + target=capture, + name=f"Injector[PID={pid}] stdout", + args=(injector.stdout,), + daemon=True, + ).start() + + def info_on_timeout(): + nonlocal output_collected + taking_longer_than_expected = False + initial_time = time.time() while True: - line = injector.stdout.readline() - if not line: + time.sleep(1) + returncode = injector.poll() + if returncode is not None: + if returncode != 0: + # Something didn't work out. Let's print more info to the user. + on_output( + "stderr", + "Attach to PID failed.\n\n", + ) + + old = output_collected + output_collected = [] + contents = "".join(old) + on_output("stderr", "".join(contents)) break - log.info("Injector[PID={0}] output:\n{1}", pid, line.rstrip()) - log.info("Injector[PID={0}] exited.", pid) - - thread = threading.Thread( - target=capture_output, - name=f"Injector[PID={pid}] output", - ) - thread.daemon = True - thread.start() + + elapsed = time.time() - initial_time + on_output( + "stdout", "Attaching to PID: %s (elapsed: %.2fs).\n" % (pid, elapsed) + ) + + if not taking_longer_than_expected: + if elapsed > 10: + taking_longer_than_expected = True + if sys.platform in ("linux", "linux2"): + on_output( + "stdout", + "\nThe attach to PID is taking longer than expected.\n", + ) + on_output( + "stdout", + "On Linux it's possible to customize the value of\n", + ) + on_output( + "stdout", + "`PYDEVD_GDB_SCAN_SHARED_LIBRARIES` so that fewer libraries.\n", + ) + on_output( + "stdout", + "are scanned when searching for the needed symbols.\n\n", + ) + on_output( + "stdout", + "i.e.: set in your environment variables (and restart your editor/client\n", + ) + on_output( + "stdout", + "so that it picks up the updated environment variable value):\n\n", + ) + on_output( + "stdout", + "PYDEVD_GDB_SCAN_SHARED_LIBRARIES=libdl, libltdl, libc, libfreebl3\n\n", + ) + on_output( + "stdout", + "-- the actual library may be different (the gdb output typically\n", + ) + on_output( + "stdout", + "-- writes the libraries that will be used, so, it should be possible\n", + ) + on_output( + "stdout", + "-- to test other libraries if the above doesn't work).\n\n", + ) + if taking_longer_than_expected: + # If taking longer than expected, start showing the actual output to the user. + old = output_collected + output_collected = [] + contents = "".join(old) + if contents: + on_output("stderr", contents) + + threading.Thread( + target=info_on_timeout, name=f"Injector[PID={pid}] info on timeout", daemon=True + ).start()