NameError: name 'x' not defined even though it should be

[Emily-OBrien-NHS]

Type: Bug

I have been writing/debugging code line by line, using F9 or writing a line in the debug console, however recently it has stopped defining my variables. I set a breakpoint, debugging until that point works and variables show in the debug panel, and sometimes I can continue running lines for a time before it stops working. See example of screenshot of what I mean:

(the i variable was defined when running in debug mode until breakpoint, but the value doesn't update like it should have).

Extension version: 2024.8.0 VS Code version: 1.91.1 (user setup) OS version: Windows_NT x64 10.0.19045 Python version (& distribution if applicable, e.g. Anaconda): 3.12.3 Type of virtual environment used (e.g. conda, venv, virtualenv, etc.): Venv

Not sure if it's something I've changed, but it used to work fine coding/debugging like this, but this issue started just under a week ago, and now I can't run any extra lines of code before getting the variable not defined issues. I think it's something to do with moving the breakpoint further into the code as I go? If I place the breakpoint a few lines in, then select the rest and hit f9, then I seem to be able to keep debugging line by line for a bit, wondering if there is some issues with setting the first breakpoint a long way into a piece of code?

[Weijiang-Xiong]

This issue also happens to me in some of my code peices when I load a npz file, but when I copy this file loading things to a separate new script, I can set new variables in the debugging console normally, so I don't know what's the cause.

In some cases I'm able to update or set a new variable for only once from the debug console, but from the second attempt on, the modifications won't take effect.

this is similar to the issue here https://github.com/microsoft/vscode/issues/216579.

my version info

Version: 1.91.1 (Universal) Commit: f1e16e1e6214d7c44d078b1f0607b2388f29d729 Date: 2024-07-09T22:07:54.982Z Electron: 29.4.0 ElectronBuildId: 9728852 Chromium: 122.0.6261.156 Node.js: 20.9.0 V8: 12.2.281.27-electron.0 OS: Darwin arm64 23.1.0

[rchiodo]

This really depends upon the context. If you step, the value can go out of scope. Do you have a code example that shows the problem?

For example in this scenario, if I create i in bar, and then run till the breakpoint in foo, i will no longer be defined. It's only in scope inside of bar

[Emily-OBrien-NHS]

@rchiodo I understand that about variables in functions, but the code I'm running is mostly not using them at all, and the variables that I'm trying to define which are causing the error aren't the variables in the few user defined functions in my code. It's a really long script (3000 lines) that I'm trying to tidy up, and as I tidy bits and set a new breakpoint after what I've already tidied, it becomes worse. At ~600 lines I can no longer define anything without getting the error, making it impossible to tidy and debug any further. In my example I'm trying to define a new variable within the debug console, away from the main code or functions etc, to test out new bits of code. Those new variables, which include a simple x=5 in the debug console as seen in my example, when called are saying that it's not defined, even though I defined it in the previous line.

A work around I've found is to place the breakpoint at an early point in the code, run to there, then select all the other lines I want to run up to the point I'm working at, press f9 and then continue debugging from there. So far this seems to be allowing me to define and use new variables, so from that I guess if you place the first breakpoint a long way into the code, it causes the issue?

[rchiodo]

Can you share an example piece of code? Breakpoints shouldn't have any bearing on whether or not variables are defined, only scopes should affect the result.

It could be your early breakpoint is at a more global scope so the variables survive into the later parts of the script.

[Emily-OBrien-NHS]

Unfortunately I'm unable to share my code as it's work related. I am trying to create another example of the problem to share, but as has been commented, others have had the same issue on varying pieces of code. I'm using the libraries: pandas, sqlalchemy create_engine, textweap, matplotlib.pyplot, seaborn, numpy, scipy.stats, matplotlib.ticker, matplotlib.dates, scipy.stats.distributions, os

All the variables in my code up to hitting the break point when debugging are defined correctly as expected, that is not the issue. The issue is trying to change or define completely new variables within the debug console after the code has run to that breakpoint. It occurs when trying to define completely new variables that are unrelated to the code I'm running, as shown in my example with the x variable. There is no x in my code, regardless of the scope, this should be a completely new and unrelated variable defined in the debug console after having run the code to the breakpoint, but it throws the error.

[Weijiang-Xiong]

hi @rchiodo, thanks for the reply. It's normal that if one steps to another function, the local variables defined in the previous function is lost. But at least in my case, I don't step into another function, I just pause the program at one line, define my new variable like a=1 (or try to update an existing variable). If I'm lucky I can define 1 new variable, but not a second one. During all these operations the program is paused at exactly the same line, no skipping, no stepping in or out.

I also tried to write a simple script to reproduce this problem, but havn't got a successful try. However, this problem happens to me EVERY SINGLE TIME I try to debug my own project where I need to load a bunch of saved numpy array and import some libraries. I'm not sure if importing and loading files will affect the debugger, but that's my guess. Do you have any idea that how we could provide more information on this issue? like enable verbose logging of the debugger extension to see what's happening under the hood?

[rchiodo]

Debugging in VS code supports this setting in your launch.json:

        {
            "name": "Launch: program",
            "type": "python",
            "request": "launch",
            "console": "integratedTerminal",
            "program": "${file}",
            "logToFile": true, <-- This setting here
        },

That logs everything the debugger does when stepping. It should log the request for the variable value too. The logs usually end up in the ms-python.debugpy extension folder. Like here for me:

C:\Users\rchiodo\.vscode\extensions\ms-python.debugpy-2024.11.2024080201-win32-x64

I don't believe there's much logging around eval failures though.

[rchiodo]

@Weijiang-Xiong your other issue looked like you had defined a lot of variables. Maybe there's some limit on the number of variables that the console allows. I'll try that to see if I can reproduce the problem.

[rchiodo]

No, that seems to have no effect. I also tried creating a bunch of numpy arrays to see if numpy had anything to do with it, no such luck.

In your screenshot in the dupe issue, it looks like the eval of line28b=1 never worked because it doesn't show up in the variable list. I would expect some sort of error in the debugger logs for that step. That might point out what the problem is.

[Emily-OBrien-NHS]

I've added that line to my launch.json, mine is slightly different to yours, hopefully that shouldn't make a difference?

{
    // Use IntelliSense to learn about possible attributes.
    // Hover to view descriptions of existing attributes.
    // For more information, visit: https://go.microsoft.com/fwlink/?linkid=830387
    "version": "0.2.0",
    "configurations": [
        {
            "name": "Python Debugger: Current File",
            "type": "debugpy",
            "request": "launch",
            "program": "${file}",
            "console": "integratedTerminal",
            "cwd": "${fileDirname}",
            "logToFile": true
        }
    ]
}

It outputted several log files: debugger.vscode_..., debugpy.adapter-..., debugpy.launcher-..., debugpy.pydevd... and debugpy.server-... I'm not sure which one would have the most useful logs, I can't see anything obviously linked to the error messages. I can copy and paste the last few entries in one of those which would match getting the error again:

Note: the first definition of x=5 happened at an earlier breakpoint, then I clicked to continue running and got the error at the next breakpoint/couldn't update the x value.

[rchiodo]

If you can zip up all of the logs I can take a look. There should be a message from the client to adapter asking to eval x=10 somewhere. Then a result should be returned. Then a request for eval of just x.

[Emily-OBrien-NHS]

debug logs.zip I can't share the full log files as they contain extracts of the data I'm using, which is sensitive. I've gone through and taken out the bits relevant to the errors, hopefully this is helpful? I re-ran it, so the commands are in a slightly different order, and all after one breakpoint at line 2213:

[rchiodo]

It looks like you removed all of the variable responses so it's hard to tell what's going on. You can e-mail them to me instead if you want. My e-mail is my user name at microsoft.com.

[rchiodo]

I logged my own version (where everything works) and it looks identical to the output you had, so the logs aren't going to be much help.

The code in question that actually updates locals after your expression eval is here: https://github.com/microsoft/debugpy/blob/a68a804f7a4a4b0d39cb1fc96ca54648f465583e/src/debugpy/_vendored/pydevd/_pydevd_bundle/pydevd_save_locals.py#L91

You might try adding extra logging there to see if the updated_globals has your new x value. Like on line 92 you'd add something like:

info("Global val" + key + val)

[Emily-OBrien-NHS]

I've added that piece of code in at line 92 and have attached the log files. I removed the variables again as the data is sensitive and I cannot share it, but have written OTHER VARIABLES REMOVED where I have done this, and left the x variable part (y never shows up in the variable list).
debug logs (2).zip

[rchiodo]

I don't think the log worked. Or you put it in the wrong pydevd bundle. Somethin like this should be in the pydevd log output:

0.01s - processing internal command: InternalThreadCommands(<function internal_evaluate_expression_json at 0x000001EF45D62160>, (<_pydevd_bundle._debug_adapter.pydevd_schema.EvaluateRequest object at 0x000001EF47191850>, 'pid_36176_id_2127164850768'), {})
0.00s - Globals in list __name__:__main__
0.00s - Globals in list __doc__:None
0.00s - Globals in list __package__:
0.00s - Globals in list __loader__:None
0.00s - Globals in list __spec__:None
0.00s - Globals in list __file__:C:\Users\rchiodo\source\testing\test_pylance\test_debugging.py
0.00s - Globals in list __cached__:None
0.00s - Globals in list __builtins__: // truncated this one
0.00s - Globals in list foo:<function foo at 0x000001EF47148B80>
0.00s - Globals in list bar:<function bar at 0x000001EF471482C0>
0.00s - Globals in list globals:<function evaluate_expression.<locals>.<lambda> at 0x000001EF47124900>
0.00s - Globals in list x:4 <-- This is the actual thing I eval'd in the debug console. We want to make sure this is always printed.

Maybe try this instead. That would force the log:

At the top of pydevd_save_locals.py:

from _pydev_bundle.pydev_log import _pydevd_log

Then add something like so:

    for key, val in updated_globals.items():
        _pydevd_log(0, f"Globals in list {key}:{val}") # Add this line here
        if val is not initial_globals.get(key, _SENTINEL):
            if f_locals is None:
                # Note: we call f_locals only once because each time
                # we call it the values may be reset.
                f_locals = frame.f_locals

            f_locals[key] = val

That should at least tell us if the eval is working or not. If it is, then the saving of the locals to the frame pointer must be the problem. That happens after this point.

[Emily-OBrien-NHS]

I've added that and run it, but it doesn't show in my log files either. I've searched my PC and it only comes up with one pydevd_save_locals.py file, so if there is another instance of it that vscode is using instead, I'm not sure how to find it.

In vscode, I do get a warning on the import line of Import _pydev_bundle.pydev_log" could not be resolved Pylance (reportMissingImports), but it doesn't throw any errors while running the code, so either it's because I'm editing in a different working directory or something, or it's using another version of the pydev bundle that I don't know about

[Weijiang-Xiong]

@rchiodo Thanks for the reply, maybe in my case the data is not that private, and I attached my logs here. vscode_logs.zip

I'm sshing to a linux machine from MAC OS, and what I did is I pause at line 28 as the code pieces in this issue https://github.com/microsoft/debugpy/issues/1642, then in the debug console I do a=1 b=1 c=1 d=1 and print(c).

I can see a pops up in the variable window, but not b, c and d. In the log file of pydevd, CMD_RETURN of c=1 has "success": true, but print(c) has false. After the success of c=1, there is a VariablesRequest at line 2059. I suppose this is to fetch the latest variables, the response also have a success state, but in the body of the response, there is only a, and I don't see b and c despite their return states are also success.

In debugpy.adapter log line 2016 (I guess this corresponds to the VariableRequest), I find a is assigned to variableRefence 0, which coincide with another variable f. This doesn't look normal to me cuz all other variables have unique reference numbers. The way I use f is exactly as the following code block, where sample_files is a list of file path raw strings. I learned from numpy doc that the underlying file descriptor will be closed if I load file using a with clause, is that related to this problem? https://numpy.org/doc/stable/reference/generated/numpy.load.html

sample_data = []
for f in sample_files:
    with np.load(f) as npz_data:
        data = {k: npz_data[k] for k in npz_data.keys()}
    sample_data.append(data)

I'm sorry that I can't find more useful information because I don't understand how the other logs are made. Please have a look and I will be grateful if you could identify the cause.

[rchiodo]

@Emily-OBrien-NHS you might try adding more logging elsewhere then. update_globals_and_locals is what is supposed to move the evaluated values into the current stack frame object. If it's not getting called, maybe something else is going wrong.

@Weijiang-Xiong I'll look at your logs today to see if there's anything that stands out. You'll likely need to add more logging too.

[rchiodo]

The variablesReference being zero is a red herring, but interesting to investigate.

In the eval response, the variablesReference is always zero. This code here:

def _evaluate_response(py_db, request, result, error_message=''):
    is_error = isinstance(result, ExceptionOnEvaluate)
    if is_error:
        result = result.result
    if not error_message:
        body = pydevd_schema.EvaluateResponseBody(result=result, variablesReference=0)
        variables_response = pydevd_base_schema.build_response(request, kwargs={'body':body})
        py_db.writer.add_command(NetCommand(CMD_RETURN, 0, variables_response, is_json=True))
    else:
        body = pydevd_schema.EvaluateResponseBody(result=result, variablesReference=0)
        variables_response = pydevd_base_schema.build_response(request, kwargs={
            'body':body, 'success':False, 'message': error_message})
        py_db.writer.add_command(NetCommand(CMD_RETURN, 0, variables_response, is_json=True))

VariablesReference is used to indicate that there are children for a value. For an eval it means there's no need for expansion on the result. It always returns nothing or a string.

VariablesReference in a variables response is similar. Here's an example of the variables response for my local machine with a bunch of integers:

D+00026.360: Server[1] --> {
                 "pydevd_cmd_id": 502,
                 "seq": 92,
                 "type": "response",
                 "request_seq": 40,
                 "success": true,
                 "command": "variables",
                 "body": {
                     "variables": [
                         {
                             "name": "x",
                             "value": "4",
                             "type": "int",
                             "evaluateName": "x",
                             "variablesReference": 0
                         },
                         {
                             "name": "y",
                             "value": "5",
                             "type": "int",
                             "evaluateName": "y",
                             "variablesReference": 0
                         },
                         {
                             "name": "z",
                             "value": "10",
                             "type": "int",
                             "evaluateName": "z",
                             "variablesReference": 0
                         }
                     ]
                 }
             }

They all have a 'variablesReference' of zero. This just means there's no children to fetch. Using zero is actually defined in the specification for debuggers here

https://microsoft.github.io/debug-adapter-protocol/specification#Types_Variable

@Weijiang-Xiong I think we need to add the same logging that I asked @Emily-OBrien-NHS to add. In the pydevd_save_locals, add logging around where it updates the globals/locals. My only guess is that there's in error in the python runtime when doing the eval for some reason.

[Weijiang-Xiong]

Hi @rchiodo, I added the codes to print global variables in the save locals file, and then did the same thing (set a, b, c, d to 1), and I find b is saved in updated_globals, but perhaps something went wrong after this.

Btw, it's just a speculation, do you think this may be related to the instability issue of intel 13th 14th CPU? I'm using an I9-13900KF CPU, and I heard people can get really weird behaviors if the CPU is not right.

vscode_logs_with_globals_in_list.zip

[rchiodo]

I don't think weird behaviors with the CPU would be this consistent, but I suppose it's possible. I haven't read what the symptoms of that are.

It looks like then the exec we execute for say b=1 is not saving the result in the actual frame. It doesn't survive the next execute. You can see if you search for a:1. It gets printed out in your dumping of the globals 4 times, but b:1 only gets printed once. Meaning on the next exec, it's been lost.

I think that means the code we use to update the locals in the frame is failing. We'll probably need more logging there.

That would be in the same function to make sure save_locals gets called and then perhaps in the save_locals implementation itself.

Oh wait it looks like you're on 3.12. I wonder if that's the problem. Debugpy hasn't been fully updated to 3.12. We might have to wait on this: https://github.com/microsoft/debugpy/issues/1419 or at least this: https://github.com/microsoft/debugpy/issues/1640

Can you also try the same thing with 3.11?

[Emily-OBrien-NHS]

I think you might be right on the python version, I just ran the same code to the breakpoint using a virtual environment using python v3.11.7 and the variables got defined as expected:

It's weird that I don't get the same issues on some of my other pieces of code/setting the breakpoint earlier in the code using v3.12.3, but hopefully those debug changes for 3.12 will resolve this issue.

[Weijiang-Xiong]

I don't think weird behaviors with the CPU would be this consistent, but I suppose it's possible. I haven't read what the symptoms of that are.

It looks like then the exec we execute for say b=1 is not saving the result in the actual frame. It doesn't survive the next execute. You can see if you search for a:1. It gets printed out in your dumping of the globals 4 times, but b:1 only gets printed once. Meaning on the next exec, it's been lost.

I think that means the code we use to update the locals in the frame is failing. We'll probably need more logging there.

That would be in the same function to make sure save_locals gets called and then perhaps in the save_locals implementation itself.

Oh wait it looks like you're on 3.12. I wonder if that's the problem. Debugpy hasn't been fully updated to 3.12. We might have to wait on this: #1419 or at least this: #1640

Can you also try the same thing with 3.11?

Ohhhhh man, I didn't know the python version could be a problem, I switched to python 3.11.0 and everything is fine. I hope python 3.12 can be supported some day. Thank you for the checking up!

[Emily-OBrien-NHS]

I think we can close this now and wait for 3.12 support. Thank you @rchiodo for all your help with this, I know I haven't made it easy to get to the bottom of, and thank you @Weijiang-Xiong for backing me up and sharing your log files :) good to know why this is happening as I couldn't find any answers on it