Debugger gets stuck with python code

[spin711]

Issue Type: Bug

While debugging a python script, I cannot continue stepping through the code since MSC debugger is not responding anymore, after a certain number of steps.
Also the debug console is impacted, meaning I do not get any requested content of a variable once the above happens.

At the biginning I thought the number of steps until it gets stuck is constant. Meanwhile, I observe that the number of steps I can perform within the same script, is depending also on the starting position in the code as well as well as the number / type of variables in the watch.

I first issued here: microsoft/vscode#95545, but was now guided to issue the bug directly under the python extension.

As advised, I updated to MSC version 1.4.2, but the error still persists.

So hopefully, someone can help and fix it. Thanks!

VS Code version: Code 1.41.1 (26076a4de974ead31f97692a0d32f90d735645c0, 2019-12-18T14:58:56.166Z)
OS version: Windows_NT x64 6.1.7601

System Info

Item	Value
CPUs	Intel(R) Core(TM) i5-5300U CPU @ 2.30GHz (4 x 2294)
GPU Status	2d_canvas: enabled flash_3d: enabled flash_stage3d: enabled flash_stage3d_baseline: enabled gpu_compositing: enabled metal: disabled_off multiple_raster_threads: enabled_on oop_rasterization: disabled_off protected_video_decode: unavailable_off rasterization: enabled skia_renderer: disabled_off surface_control: disabled_off surface_synchronization: enabled_on video_decode: enabled viz_display_compositor: enabled_on viz_hit_test_surface_layer: disabled_off webgl: enabled webgl2: enabled
Load (avg)	undefined
Memory (System)	7.88GB (0.93GB free)
Process Argv
Screen Reader	no
VM	0%

Extensions (3)

Extension	Author (truncated)	Version
githistory	don	0.6.3
python	ms-	2020.2.64397
team	ms-	1.161.0

e written the needed data into your clipboard because it was too large to send. Please paste.

[int19h]

I'm pretty sure this is #108 - we have a fix for that, but it's only available in the insiders version of the extension. Can you give it a try?

[Pabosik]

Hi, I am unfortunately also affected by this bug. I tried the opt-out solution suggested in #108 but it doesn't fix the issue for me. The debugger randomly stops responding / hangs / freezes at times, which also affects the debug console. I will be happy to provide you with any and all information that may be helpful in fixing this. I love VS code but this debugging issue is really annoying, since the only thing that seems to help is to stop and restart the debugging process entirely....but that only helps temporarily. Please specify which information I can provide to help.

[rickstaa]

@int19h Like @Pabosik, I also still experience the issue after using the fix in #108. Is there already an update on this issue? I tried using the weekly insider as well as adding the following lines to the settings.json file:

  "python.experiments.optOutFrom": [
    "DebugAdapterFactory - experiment",
    "PtvsdWheels37 - experiment"
  ],

I also tried using the following settings:

  "python.insidersChannel": "daily",
  "python.experiments.optInto": [
    "DebugAdapterFactory - experiment",
    "PtvsdWheels37 - experiment"
  ],

[int19h]

Can you please show the output of import debugpy; print(debugpy.__version__) from the app that you're trying to debug?

[rickstaa]

@int19h Thanks a lot for the very fast response. The debugpy version seems to be 1.0.0b9. This is with the following settings:

  "python.insidersChannel": "daily",
  "python.experiments.optInto": [
    "DebugAdapterFactory - experiment",
    "PtvsdWheels37 - experiment"
  ],

[int19h]

Thank you! Since this is definitely the version with the fix for the other issue that caused similar symptoms, this must be something else. Can you please add:

"logToFile": true

to your launch.json config, and try to repro it again, then share the logs it'll create? They are placed in the folder where the extension is installed, and have names matching debugpy*.log.

[rickstaa]

@int19h I again tried to debug a python script with the logToFile bool enabled. The zip containing the log files can be found here:

debug_logs.zip

While I was debugging, I also noticed the freeze only happens when I try to interact with the variables using the debug console or variable browser. Secondly, the debugger always gives a timeout after 1000ms error when I shut it down during a freeze.

[int19h]

Looking at the larger log, I'm seeing three expression evaluations being submitted in rapid succession for these expressions:

self._compute_reward(obs, done)
test = 1
print(test)

Could the first one just be very long-running? It would block basically everything else in the debugger if so. The debug server log seems to indicate that it was still working on that when it got the request to stop debugging.

(Unfortunately, VSCode Debug Console UX for long-running evals is confusing - it shows the prompt for the next expression as soon as it submits the previous one to the debugger; it does not wait for evaluation to complete.)

[rickstaa]

@int19h Thanks a lot for the explanation. The self._compute_reward(obs, done) function is a tiny function that should not take more than a few ms. Since I'm using ROS service calls in my script, maybe a package could get lost, causing the debugger to wait till infinity. I check the ROS logs and do some debugging to see the behaviour is also present while using the debugger on a similar script.

def _compute_reward(self, observations, done):
        """Compute the reward.

        Parameters
        ----------
        observations : dict
            Dictionary containing the observations
        done : bool
            Boolean specifying whether an episode is terminated.

        Returns
        -------
        :obj:`numpy.float32`
            Reward that is received by the agent.
        """

        # Calculate the rewards based on the distance from the goal
        d = self._goal_distance(observations["achieved_goal"], self.goal)
        if self._reward_type == "sparse":

            # Print Debug info
            rospy.logdebug("=Reward info=")
            rospy.logdebug("Reward type: Non sparse")
            rospy.logdebug("Goal: %s", self.goal)
            rospy.logdebug("Achieved goal: %s", observations["achieved_goal"])
            rospy.logdebug("Perpendicular distance: %s", d)
            rospy.logdebug("Threshold: %s", self._distance_threshold)
            rospy.logdebug(
                "Received reward: %s",
                -(d > self._distance_threshold).astype(np.float32),
            )

            # Return result
            return -(d > self._distance_threshold).astype(np.float32)
        else:

            # Print Debug info
            rospy.logdebug("=Reward info=")
            rospy.logdebug("Reward type: Sparse")
            rospy.logdebug("Goal: %s", self.goal)
            rospy.logdebug("Achieved goal: %s", observations["achieved_goal"])
            rospy.logdebug("Perpendicular distance: %s", d)
            rospy.logdebug("Threshold: %s", self._distance_threshold)
            rospy.logdebug("Received reward: %s", -d)

            # Return result
            return -d

    def _goal_distance(self, goal_a, goal_b):
        """Calculates the perpendicular distance to the goal.

        Parameters
        ----------
        goal_a : numpy.ndarray
            List containing a gripper and object pose.
        goal_b : numpy.ndarray
            List containing a gripper and object pose.

        Returns
        -------
        numpyp.float32
            Perpendicular distance to the goal.
        """
        assert goal_a.shape == goal_b.shape
        return np.linalg.norm(goal_a - goal_b, axis=-1)

[int19h]

If the library you're using requires multiple threads running concurrently to operate - e.g. if any of those rospy calls submit some data for processing by a background thread, and then do a blocking wait for said background thread to signal completion - then you might be running into the same problem as #157.

[rickstaa]

@int19h Thanks for point me to that issue. I will look into it.

[fabioz]

As it seems that the issue is during the evaluate, so, I think the changes done in: #157 may enable to shed more info in this issue... there still isn't a release with that version, but if you'd like to check it with the master, it'd be nice to know if it does actually improve the situation in your use case.

To use the master do the following:

Clone this repo:

git clone https://github.com/microsoft/debugpy.git
cd debugpy
pwd

Then, in your launch config add:

"debugAdapterPath": "<pwd path>/src/debugpy/adapter"

and debug your app... if things turn out as I expect, it should print a message to the Debug Console with more information. It may also be interesting to set an environment variable such as "PYDEVD_THREAD_DUMP_ON_WARN_EVALUATION_TIMEOUT":"true" in the launch environment so that a thread dump is also provided when a slow evaluation is detected.

[rickstaa]

@fabioz Thanks for your response. I will check your it when I am working again on the project discussed in this issue (in about 2 weeks).

[rickstaa]

@fabloz I was able to perform the steps you proposed and with the new version of debugpy, the debugger now crashes instead of freezing. I created a very simple python setup for you in order to validate whether the problem is fixed. If you require more information let me know.

Example python scripts

is_scalar.py module

import torch
import numpy as np


def is_scalar(obj):
    """Recursive function that checks whether a input

    Args:
        obj (object): Object for which you want to check if it is a scalar.

    Returns:
        boole: Boolean specifying whether the object is a scalar.
    """

    # Check if obj is scalar
    if type(obj) in [int, float]:
        return True
    elif type(obj) == np.ndarray:
        if obj.__len__() > 1:
            return is_scalar(obj)
        else:
            return False
    elif type(obj) == torch.Tensor:
        if obj.__len__() > 1:
            return is_scalar(obj)
        else:
            return False
    elif type(obj) == str:
        return obj.isnumeric()
    else:
        return False

test_debugger.py script

import numpy as np

from is_scalar import is_scalar

print(is_scalar(1), "True")
print(is_scalar([1]), "False")
print(is_scalar(np.array(2)), "True")  # I'm here
pass

Steps to reproduce (Also see gif)

1. Put both the test_debugger.py and is_scalar.py script in the same folder.
2. Run the test_debugger script while placing a breakpoint on the pass statement.
3. Create a new np array in the debugger console test_array = np.array(2).
4. Try to inspect this new test_array and see the debugger hanging in the old debugpy version.
5. In the new pulled version of debugpy the debugger crashes while giving the following error:

IndexError: too many indices for array

Gif

Full Error message

To see the full error message go to this gist.

Debugpy (old version) logs

The logs for when I'm using the old version can be found in this gist.

Debugpy (new version) logs

The logs for when I'm using the new version can be found in this gist.

[fabioz]

@rickstaa this is a different issue. I've created #378 to tackle it.

[int19h]

Closing this one, since there are other issues tracking the remaining problems.