debugpy is not sending "output" events of category "stdout"

Question

debugpy is not sending "output" events of category "stdout"

Closed this issue 2 months ago · 3 comments

Hello,

I have been using DAP debuggers (lldb-dap, gdb-dap) with the same tool (CodeLite), recently I tried using debugpy which
worked out of the box with one exception:

I could not get the debugger to send events to the IDE of "event":"output","body":{"category":"stdout"...

Environment data

debugpy version: 1.8.7
Windows 10, 64bit
Python 3.11.10
Using VS Code or Visual Studio: No

Actual behavior

Output events are not generated for python print statements

Expected behavior

When stepping over a python print statement, I would expect the debugger to send an event of type output with category set to console with the content to print into the terminal (similar to how other debuggers do)

Other info:

I am using this line to start the debugger:

python.exe -m debugpy --listen 12345 --wait-for-client /Users/me/Documents/PythonTest/test.py

Source file being debugged:

print("hello")
print("world")

See below the complete interaction between the IDE and debugpy.

How to read the log?

After each *** DAP Stopped Event *** in the below log, I hit F5 (Step-Over). I would expect to see a line similar to this:

{"body":{"category":"stdout","output":"hello\n"},"event":"output","seq":0,"type":"event"}

The actual interaction between debugpy and CodeLite:

[08:33:08:985 T:22128 DEBUG] CodeLite> debug-start event is called for debugger: debugpy
[08:33:08:985 T:22128 DEBUG] CodeLite> working directory is: /Users/me/Documents/PythonTest
[08:33:08:990 T:22128 DEBUG] CodeLite> Connecting to dap-server: debugpy
[08:33:08:990 T:22128 DEBUG] CodeLite> exepath: [/clang64/bin/python3.exe, /Users/me/Documents/PythonTest/test.py]
[08:33:08:990 T:22128 DEBUG] CodeLite> working_directory: /Users/me/Documents/PythonTest
[08:33:08:995 T:22128 DEBUG] CodeLite> starting dap with command: /clang64/bin/python.exe -m debugpy --listen 12345 --wait-for-client /Users/me/Documents/PythonTest/test.py
[08:33:10:332 T:22128 DEBUG] CodeLite> --> {"seq":1,"type":"request","command":"initialize","arguments":{"clientID":"CodeLite","clientName":"CodeLite IDE","adapterID":"","locale":"en-US","linesStartAt1":true,"columnsStartAt1":false,"pathFormat":"path","supportsInvalidatedEvent":false}}
[08:33:10:333 T:22128 DEBUG] CodeLite> server output: 0.01s - Debugger warning: It seems that frozen modules are being used, which may
0.00s - make the debugger miss breakpoints. Please pass -Xfrozen_modules=off
0.00s - to python to disable frozen modules.
0.00s - Note: Debugging will proceed. Set PYDEVD_DISABLE_FILE_VALIDATION=1 to disable this validation.
[08:33:10:333 T:22128 DEBUG] CodeLite> server output: Unable to find python module. 
Unable to find python module. 
Unable to find python module. 
Unable to find python module. 
Unable to find python module. 
[08:33:10:333 T:22128 DEBUG] CodeLite> server output: Unable to find python module. 
Unable to find python module. 
[08:33:10:888 T:22128 DEBUG] CodeLite> <-- {"seq":1,"type":"event","event":"output","body":{"category":"telemetry","output":"ptvsd","data":{"packageVersion":"1.8.7"}}}
[08:33:10:888 T:22128 DEBUG] CodeLite> <-- {"seq":2,"type":"event","event":"output","body":{"category":"telemetry","output":"debugpy","data":{"packageVersion":"1.8.7"}}}
[08:33:10:888 T:22128 DEBUG] CodeLite> <-- {"seq":3,"type":"event","event":"debugpySockets","body":{"sockets":[{"host":"127.0.0.1","port":12345,"internal":false},{"host":"127.0.0.1","port":54325,"internal":true}]}}
[08:33:10:889 T:22128 DEBUG] CodeLite> <-- {"seq":4,"type":"response","request_seq":1,"success":true,"command":"initialize","body":{"supportsCompletionsRequest":true,"supportsConditionalBreakpoints":true,"supportsConfigurationDoneRequest":true,"supportsDebuggerProperties":true,"supportsDelayedStackTraceLoading":true,"supportsEvaluateForHovers":true,"supportsExceptionInfoRequest":true,"supportsExceptionOptions":true,"supportsFunctionBreakpoints":true,"supportsHitConditionalBreakpoints":true,"supportsLogPoints":true,"supportsModulesRequest":true,"supportsSetExpression":true,"supportsSetVariable":true,"supportsValueFormattingOptions":true,"supportsTerminateRequest":true,"supportsGotoTargetsRequest":true,"supportsClipboardContext":true,"exceptionBreakpointFilters":[{"filter":"raised","label":"Raised Exceptions","default":false,"description":"Break whenever any exception is raised."},{"filter":"uncaught","label":"Uncaught Exceptions","default":true,"description":"Break when the process is exiting due to unhandled exception."},{"filter":"userUnhandled","label":"User Uncaught Exceptions","default":false,"description":"Break when exception escapes into library code."}],"supportsStepInTargetsRequest":true}}
[08:33:10:889 T:22128 DEBUG] CodeLite> got initialize response
[08:33:10:889 T:22128 DEBUG] CodeLite> Starting debugger for command:
[08:33:10:889 T:22128 DEBUG] CodeLite> [/clang64/bin/python3.exe, /Users/me/Documents/PythonTest/test.py]
[08:33:10:889 T:22128 DEBUG] CodeLite> working directory: /Users/me/Documents/PythonTest
[08:33:10:889 T:22128 DEBUG] CodeLite> Calling Launch() with command: [/clang64/bin/python3.exe, /Users/me/Documents/PythonTest/test.py]
[08:33:10:889 T:22128 DEBUG] CodeLite> --> {"seq":2,"type":"request","command":"attach","arguments":{"arguments":["/Users/me/Documents/PythonTest/test.py"],"pid":-1}}
[08:33:10:891 T:22128 DEBUG] CodeLite> <-- {"seq":5,"type":"event","event":"debugpyWaitingForServer","body":{"host":"127.0.0.1","port":54325}}
[08:33:10:942 T:22128 DEBUG] CodeLite> <-- {"seq":6,"type":"event","event":"initialized"}
[08:33:10:942 T:22128 DEBUG] CodeLite> --> {"seq":3,"type":"request","command":"setFunctionBreakpoints","arguments":{"breakpoints":[{"name":"main","condition":""}]}}
[08:33:10:942 T:22128 DEBUG] CodeLite> Applying breakpoints
[08:33:10:942 T:22128 DEBUG] CodeLite> Applying breakpoints for file: /Users/me/Documents/PythonTest/test.py
[08:33:10:943 T:22128 DEBUG] CodeLite> Line: 1 . Condition:  
[08:33:10:943 T:22128 DEBUG] CodeLite> --> {"seq":4,"type":"request","command":"setBreakpoints","arguments":{"source":{"name":"test.py","path":"/Users/me/Documents/PythonTest/test.py"},"breakpoints":[{"line":1,"condition":""}]}}
[08:33:10:943 T:22128 DEBUG] CodeLite> --> {"seq":5,"type":"request","command":"configurationDone"}
[08:33:10:948 T:22128 DEBUG] CodeLite> <-- {"seq":7,"type":"response","request_seq":3,"success":true,"command":"setFunctionBreakpoints","body":{"breakpoints":[{"verified":true,"id":0,"source":{}}]}}
[08:33:10:956 T:22128 DEBUG] CodeLite> <-- {"seq":8,"type":"response","request_seq":4,"success":true,"command":"setBreakpoints","body":{"breakpoints":[{"verified":true,"id":1,"source":{"name":"test.py","path":"/Users/me/Documents/PythonTest/test.py"},"line":1}]}}
[08:33:10:956 T:22128 DEBUG] CodeLite> Deleting session breakpoints for file: /Users/me/Documents/PythonTest/test.py
[08:33:10:957 T:22128 DEBUG] CodeLite> <-- {"seq":9,"type":"response","request_seq":5,"success":true,"command":"configurationDone"}
[08:33:10:957 T:22128 DEBUG] CodeLite> <-- {"seq":10,"type":"response","request_seq":2,"success":true,"command":"attach"}
[08:33:10:957 T:22128 DEBUG] CodeLite> <-- {"seq":11,"type":"event","event":"process","body":{"name":"/Users/me/Documents/PythonTest/test.py","systemProcessId":21208,"isLocalProcess":true,"startMethod":"attach"}}
[08:33:10:957 T:22128 DEBUG] CodeLite> <-- {"seq":12,"type":"event","event":"thread","body":{"reason":"started","threadId":1}}
[08:33:11:042 T:22128 DEBUG] CodeLite> <-- {"seq":13,"type":"event","event":"stopped","body":{"reason":"breakpoint","threadId":1,"preserveFocusHint":false,"allThreadsStopped":true}}
[08:33:11:049 T:22128 DEBUG] CodeLite> Applying breakpoints
[08:33:11:050 T:22128 DEBUG] CodeLite> Applying breakpoints for file: /Users/me/Documents/PythonTest/test.py
[08:33:11:050 T:22128 DEBUG] CodeLite> Line: 1 . Condition:  
[08:33:11:050 T:22128 DEBUG] CodeLite> --> {"seq":6,"type":"request","command":"setBreakpoints","arguments":{"source":{"name":"test.py","path":"/Users/me/Documents/PythonTest/test.py"},"breakpoints":[{"line":1,"condition":""}]}}
[08:33:11:050 T:22128 DEBUG] CodeLite>  *** DAP Stopped Event *** 
[08:33:11:050 T:22128 DEBUG] CodeLite> --> {"seq":7,"type":"request","command":"threads"}
[08:33:11:067 T:22128 DEBUG] CodeLite> <-- {"seq":14,"type":"response","request_seq":6,"success":true,"command":"setBreakpoints","body":{"breakpoints":[{"verified":true,"id":2,"source":{"name":"test.py","path":"/Users/me/Documents/PythonTest/test.py"},"line":1}]}}
[08:33:11:068 T:22128 DEBUG] CodeLite> Deleting session breakpoints for file: /Users/me/Documents/PythonTest/test.py
[08:33:11:068 T:22128 DEBUG] CodeLite> <-- {"seq":15,"type":"response","request_seq":7,"success":true,"command":"threads","body":{"threads":[{"id":1,"name":"MainThread"}]}}
[08:33:11:069 T:22128 DEBUG] CodeLite> --> {"seq":8,"type":"request","command":"stackTrace","arguments":{"threadId":1}}
[08:33:11:112 T:22128 DEBUG] CodeLite> <-- {"seq":16,"type":"response","request_seq":8,"success":true,"command":"stackTrace","body":{"stackFrames":[{"id":2,"name":"<module>","line":1,"column":1,"source":{"path":"/Users/me/Documents/PythonTest/test.py","sourceReference":0}}],"totalFrames":1}}
[08:33:11:113 T:22128 DEBUG] CodeLite> Loading file.. /Users/me/Documents/PythonTest/test.py
[08:33:11:113 T:22128 DEBUG] CodeLite> Normalised form: /Users/me/Documents/PythonTest/test.py
[08:33:11:124 T:22128 DEBUG] CodeLite> --> {"seq":9,"type":"request","command":"scopes","arguments":{"frameId":2}}
[08:33:11:124 T:22128 DEBUG] CodeLite> <-- {"seq":17,"type":"event","event":"module","body":{"reason":"new","module":{"id":0,"name":"__main__","path":"/Users/me/Documents/PythonTest/test.py"}}}
[08:33:11:145 T:22128 DEBUG] CodeLite> <-- {"seq":18,"type":"response","request_seq":9,"success":true,"command":"scopes","body":{"scopes":[{"name":"Locals","variablesReference":3,"expensive":false,"presentationHint":"locals","source":{}},{"name":"Globals","variablesReference":4,"expensive":false,"source":{}}]}}
[08:33:11:145 T:22128 DEBUG] CodeLite> Current frame id: -1
[08:33:11:145 T:22128 DEBUG] CodeLite> updating scopes for frame: 2
[08:33:11:145 T:22128 DEBUG] CodeLite> --> {"seq":10,"type":"request","command":"variables","arguments":{"variablesReference":3,"count":10,"format":{"hex":false}}}
[08:33:11:147 T:22128 DEBUG] CodeLite> --> {"seq":11,"type":"request","command":"variables","arguments":{"variablesReference":3,"count":10,"format":{"hex":false}}}
[08:33:11:196 T:22128 DEBUG] CodeLite> <-- {"seq":19,"type":"response","request_seq":10,"success":true,"command":"variables","body":{"variables":[{"name":"special variables","value":"","type":"","evaluateName":"special variables","variablesReference":5}]}}
[08:33:11:196 T:22128 DEBUG] CodeLite> <-- {"seq":20,"type":"response","request_seq":11,"success":true,"command":"variables","body":{"variables":[{"name":"special variables","value":"","type":"","evaluateName":"special variables","variablesReference":6}]}}
[08:33:13:586 T:22128 DEBUG] CodeLite> -> Next
[08:33:13:586 T:22128 DEBUG] CodeLite> --> {"seq":12,"type":"request","command":"next","arguments":{"threadId":1,"granularity":"line","singleThread":true}}
[08:33:13:587 T:22128 DEBUG] CodeLite> <-- {"seq":21,"type":"response","request_seq":12,"success":true,"command":"next"}
[08:33:13:588 T:22128 DEBUG] CodeLite> <-- {"seq":22,"type":"event","event":"continued","body":{"threadId":1,"allThreadsContinued":true}}
[08:33:13:588 T:22128 DEBUG] CodeLite> <-- {"seq":23,"type":"event","event":"stopped","body":{"reason":"step","threadId":1,"preserveFocusHint":false,"allThreadsStopped":true}}
[08:33:13:588 T:22128 DEBUG] CodeLite>  *** DAP Stopped Event *** 
[08:33:13:588 T:22128 DEBUG] CodeLite> --> {"seq":13,"type":"request","command":"threads"}
[08:33:13:596 T:22128 DEBUG] CodeLite> <-- {"seq":24,"type":"response","request_seq":13,"success":true,"command":"threads","body":{"threads":[{"id":1,"name":"MainThread"}]}}
[08:33:13:597 T:22128 DEBUG] CodeLite> --> {"seq":14,"type":"request","command":"stackTrace","arguments":{"threadId":1}}
[08:33:13:624 T:22128 DEBUG] CodeLite> <-- {"seq":25,"type":"response","request_seq":14,"success":true,"command":"stackTrace","body":{"stackFrames":[{"id":2,"name":"<module>","line":2,"column":1,"source":{"path":"/Users/me/Documents/PythonTest/test.py","sourceReference":0}}],"totalFrames":1}}
[08:33:13:625 T:22128 DEBUG] CodeLite> Loading file.. /Users/me/Documents/PythonTest/test.py
[08:33:13:625 T:22128 DEBUG] CodeLite> Normalised form: /Users/me/Documents/PythonTest/test.py
[08:33:13:625 T:22128 DEBUG] CodeLite> --> {"seq":15,"type":"request","command":"scopes","arguments":{"frameId":2}}
[08:33:13:651 T:22128 DEBUG] CodeLite> <-- {"seq":26,"type":"response","request_seq":15,"success":true,"command":"scopes","body":{"scopes":[{"name":"Locals","variablesReference":3,"expensive":false,"presentationHint":"locals","source":{}},{"name":"Globals","variablesReference":4,"expensive":false,"source":{}}]}}
[08:33:13:651 T:22128 DEBUG] CodeLite> Current frame id: 2
[08:33:13:651 T:22128 DEBUG] CodeLite> updating scopes for frame: 2
[08:33:13:652 T:22128 DEBUG] CodeLite> --> {"seq":16,"type":"request","command":"variables","arguments":{"variablesReference":3,"count":10,"format":{"hex":false}}}
[08:33:13:691 T:22128 DEBUG] CodeLite> <-- {"seq":27,"type":"response","request_seq":16,"success":true,"command":"variables","body":{"variables":[{"name":"special variables","value":"","type":"","evaluateName":"special variables","variablesReference":7}]}}
[08:33:15:055 T:22128 DEBUG] CodeLite> -> Next
[08:33:15:055 T:22128 DEBUG] CodeLite> --> {"seq":17,"type":"request","command":"next","arguments":{"threadId":1,"granularity":"line","singleThread":true}}
[08:33:15:066 T:22128 DEBUG] CodeLite> <-- {"seq":28,"type":"response","request_seq":17,"success":true,"command":"next"}
[08:33:15:066 T:22128 DEBUG] CodeLite> <-- {"seq":29,"type":"event","event":"continued","body":{"threadId":1,"allThreadsContinued":true}}
[08:33:15:067 T:22128 DEBUG] CodeLite> <-- {"seq":30,"type":"event","event":"stopped","body":{"reason":"step","threadId":1,"preserveFocusHint":false,"allThreadsStopped":true}}
[08:33:15:067 T:22128 DEBUG] CodeLite>  *** DAP Stopped Event *** 
[08:33:15:067 T:22128 DEBUG] CodeLite> --> {"seq":18,"type":"request","command":"threads"}
[08:33:15:082 T:22128 DEBUG] CodeLite> <-- {"seq":31,"type":"response","request_seq":18,"success":true,"command":"threads","body":{"threads":[{"id":1,"name":"MainThread"}]}}
[08:33:15:083 T:22128 DEBUG] CodeLite> --> {"seq":19,"type":"request","command":"stackTrace","arguments":{"threadId":1}}
[08:33:15:139 T:22128 DEBUG] CodeLite> <-- {"seq":32,"type":"response","request_seq":19,"success":true,"command":"stackTrace","body":{"stackFrames":[{"id":8,"name":"_shutdown","line":1550,"column":1,"source":{"path":"/clang64/lib/python3.11/threading.py","sourceReference":0}}],"totalFrames":1}}
[08:33:15:140 T:22128 DEBUG] CodeLite> Loading file.. /clang64/lib/python3.11/threading.py
[08:33:15:140 T:22128 DEBUG] CodeLite> Normalised form: /clang64/lib/python3.11/threading.py
[08:33:15:226 T:22128 DEBUG] CodeLite> --> {"seq":20,"type":"request","command":"scopes","arguments":{"frameId":8}}
[08:33:15:226 T:22128 DEBUG] CodeLite> <-- {"seq":33,"type":"event","event":"module","body":{"reason":"new","module":{"id":1,"name":"threading","path":"/clang64/lib/python3.11/threading.py"}}}
[08:33:15:272 T:22128 DEBUG] CodeLite> <-- {"seq":34,"type":"response","request_seq":20,"success":true,"command":"scopes","body":{"scopes":[{"name":"Locals","variablesReference":9,"expensive":false,"presentationHint":"locals","source":{}},{"name":"Globals","variablesReference":10,"expensive":false,"source":{}}]}}
[08:33:15:273 T:22128 DEBUG] CodeLite> Current frame id: 2
[08:33:15:273 T:22128 DEBUG] CodeLite> updating scopes for frame: 8
[08:33:15:273 T:22128 DEBUG] CodeLite> --> {"seq":21,"type":"request","command":"variables","arguments":{"variablesReference":9,"count":10,"format":{"hex":false}}}
[08:33:15:274 T:22128 DEBUG] CodeLite> --> {"seq":22,"type":"request","command":"variables","arguments":{"variablesReference":9,"count":10,"format":{"hex":false}}}
[08:33:15:275 T:22128 DEBUG] CodeLite> <-- {"seq":35,"type":"response","request_seq":21,"success":true,"command":"variables","body":{"variables":[]}}
[08:33:15:275 T:22128 DEBUG] CodeLite> <-- {"seq":36,"type":"response","request_seq":22,"success":true,"command":"variables","body":{"variables":[]}}
[08:33:16:286 T:22128 DEBUG] CodeLite> -> Stop
[08:33:16:298 T:22128 DEBUG] CodeLite> Terminating dap-server...
[08:33:16:314 T:22128 DEBUG] CodeLite> Restoring breakpoints for file: /Users/me/Documents/PythonTest/test.py  - 1 breakpoints
[08:33:16:316 T:22128 DEBUG] CodeLite> Restoring breakpoints...done
[08:33:16:586 T:22128 DEBUG] CodeLite> dap-server terminated

Answer 1 · 2024-10-31T16:26:15.000Z

Your client needs to send the RedirectOutput option to debugpy when it attaches. This will cause debugpy to redirect output to a message.

VS code does this automatically:

5 Client --> Adapter:
{
    "command": "attach",
    "arguments": {
        "name": "Python Debugger: Attach to listening debugpy",
        "type": "debugpy",
        "request": "attach",
        "connect": {
            "port": 5679
        },
        "redirectOutput": true,
        "logToFile": true,
        "__configurationTarget": 6,
        "clientOS": "windows",
        "debugOptions": [
            "RedirectOutput",
            "ShowReturnValue"
        ],
        "justMyCode": true,
        "showReturnValue": true,
        "workspaceFolder": "c:\\Users\\rchiodo\\source\\testing\\test_pylance",
        "__sessionId": "3de75ddf-d6c5-4821-85bf-1673f104700e"
    },
    "type": "request",
    "seq": 2
}

That causes this event to come back during a print:

5551 Client <-- Adapter:
{
    "seq": 30,
    "type": "event",
    "event": "output",
    "body": {
        "output": "After attach", // I had a print('After attach') in the debuggee
        "category": "stdout",
        "source": {}
    }
}

Answer 2 · 2024-10-31T16:44:37.000Z

I believe if you added it to this case here:

CodeLite> --> {"seq":2,"type":"request","command":"attach","arguments":{"arguments":["/Users/me/Documents/PythonTest/test.py"],"pid":-1,"debugOptions":["RedirectOutput"]}}

Answer 3 · 2024-11-01T12:29:02.000Z

The client now adds it and the problem is solved - thanks!