codelldb icon indicating copy to clipboard operation
codelldb copied to clipboard

Windows debugging fails to redirect stdio sometimes

Open CAD97 opened this issue 4 years ago • 6 comments

OS: Microsoft Windows Version 2004 (OS Build 19041.685) VSCode version: Visual Studio Code Version 1.52.1 (system setup) Extension version: v1.6.0 Compiler: rustc 1.50.0-nightly (b32e6e6ac 2020-12-16) Build target: x86_64-pc-windows-msvc

When debugging Bevy games, stdio is failing to be redirected (terminal agent did not respond within the allotted time). (Side note: because of #380, the debug console says "Debugee output will appear here", but it doesn't, as debugee output is going to the LLDB log exclusively.) Interestingly, the LLDB log says Listening on port 55372, and command history in the terminal shows that it was attaching to --port=55375?

Debug Log
Failed to redirect stdio to a terminal. (Terminal agent did not respond within the allotted time.)
Debuggee output will appear here.
Launching: D:\.rust\target\debug\examples\breakout.exe
Launched process 25308
Output (LLDB)
Running `cargo build --example=breakout --package=bevy --message-format=json`...
    Finished dev [unoptimized + debuginfo] target(s) in 0.48s
Raw artifacts:
{
  fileName: 'D:\\.rust\\target\\debug\\examples\\breakout.exe',
  name: 'breakout',
  kind: 'example'
}
Filtered artifacts: 
{
  fileName: 'D:\\.rust\\target\\debug\\examples\\breakout.exe',
  name: 'breakout',
  kind: 'example'
}
configuration: {
  type: 'lldb',
  request: 'launch',
  name: "Debug example 'breakout'",
  args: [],
  cwd: '${workspaceFolder}',
  __configurationTarget: 5,
  sourceMap: {
    '/rustc/b32e6e6ac8921035177256ab6806e6ab0d4b9b94': 'D:/.rust/rustup/toolchains/nightly-x86_64-pc-windows-msvc/lib/rustlib/src/rust'
  },
  relativePathBase: 'd:\\repos\\bevyengine\\bevy',
  program: 'D:\\.rust\\target\\debug\\examples\\breakout.exe',
  sourceLanguages: [ 'rust' ]
}
liblldb: c:\Users\CAD\.vscode\extensions\vadimcn.vscode-lldb-1.6.0\lldb\bin\liblldb.dll
environment: {}
params: { sourceLanguages: [ 'rust' ] }
Listening on port 55372
[2020-12-18T00:35:35Z DEBUG codelldb] New debug session
INFO(Python) 19:35:36 formatters: Initializing
INFO(Python) 19:35:36 formatters.rust: Initializing
[2020-12-18T00:35:36Z DEBUG codelldb::dap_codec] --> {"command":"initialize","arguments":{"clientID":"vscode","clientName":"Visual Studio Code","adapterID":"lldb","pathFormat":"path","linesStartAt1":true,"columnsStartAt1":true,"supportsVariableType":true,"supportsVariablePaging":true,"supportsRunInTerminalRequest":true,"locale":"en-us","supportsProgressReporting":true,"supportsInvalidatedEvent":true},"type":"request","seq":1}
[2020-12-18T00:35:36Z DEBUG codelldb::dap_codec]  {"command":"launch","arguments":{"type":"lldb","request":"launch","name":"Debug example 'breakout'","args":[],"cwd":"D:\\repos\\bevyengine\\bevy","__configurationTarget":5,"sourceMap":{"/rustc/b32e6e6ac8921035177256ab6806e6ab0d4b9b94":"D:/.rust/rustup/toolchains/nightly-x86_64-pc-windows-msvc/lib/rustlib/src/rust"},"relativePathBase":"d:\\repos\\bevyengine\\bevy","program":"D:\\.rust\\target\\debug\\examples\\breakout.exe","sourceLanguages":["rust"],"_adapterSettings":{"displayFormat":"auto","showDisassembly":"auto","dereferencePointers":true,"suppressMissingSourceFiles":true,"evaluationTimeout":5,"consoleMode":"commands","sourceLanguages":null,"terminalPromptClear":null},"__sessionId":"b03e8c29-1777-429d-8d5f-365847f17d13"},"type":"request","seq":2}
[2020-12-18T00:35:36Z INFO  codelldb::debug_session] Set target.source-map args: "/rustc/b32e6e6ac8921035177256ab6806e6ab0d4b9b94" "D:/.rust/rustup/toolchains/nightly-x86_64-pc-windows-msvc/lib/rustlib/src/rust" 
[2020-12-18T00:35:40Z DEBUG codelldb::dap_codec]  {"command":"setFunctionBreakpoints","arguments":{"breakpoints":[]},"type":"request","seq":3}
[2020-12-18T00:35:40Z DEBUG codelldb::dap_codec]  {"command":"setDataBreakpoints","arguments":{"breakpoints":[]},"type":"request","seq":4}
[2020-12-18T00:35:40Z DEBUG codelldb::dap_codec]  {"command":"setExceptionBreakpoints","arguments":{"filters":["rust_panic"]},"type":"request","seq":5}
[2020-12-18T00:35:41Z DEBUG codelldb::dap_codec] --> {"type":"response","seq":6,"command":"runInTerminal","request_seq":2,"success":true,"body":{"shellProcessId":12564}}
[2020-12-18T00:35:46Z DEBUG codelldb::dap_codec]  {"command":"configurationDone","type":"request","seq":7}
[2020-12-18T00:35:46Z DEBUG codelldb::dap_codec]  {"command":"threads","type":"request","seq":8}
[2020-12-18T00:35:46Z DEBUG codelldb::dap_codec] >' has a member 'next' of type 'core::sync::atomic::AtomicPtr<:unbounded::block>>>' which does not have a complete definition.
error: breakout.exe :: Class 'std::sync::mpsc::oneshot::MyUpgrade<:host::wasapi::stream::command>' has a member 'RUST$ENCODED$ENUM$0$NothingSent' of type 'std::sync::mpsc::oneshot::GoUp' which does not have a complete definition.
error: breakout.exe :: Class 'core::sync::atomic::AtomicPtr<:sync::mpsc::spsc_queue::node>>>' has a member 'p' of type 'core::cell::UnsafeCell>*>' which does not have a complete definition.
error: breakout.exe :: Class 'std::sync::mpsc::mpsc_queue::Node<:host::wasapi::stream::command>' has a member 'next' of type 'core::sync::atomic::AtomicPtr<:sync::mpsc::mpsc_queue::node>>' which does not have a complete definition.
error: breakout.exe :: Class 'core::sync::atomic::AtomicPtr<:sync::mpsc::spsc_queue::node>>>' has a member 'p' of type 'core::cell::UnsafeCell>*>' which does not have a complete definition.
error: breakout.exe :: Class 'std::sync::mpsc::mpsc_queue::Node<:event>' has a member 'next' of type 'core::sync::atomic::AtomicPtr<:sync::mpsc::mpsc_queue::node>>' which does not have a complete definition.
error: breakout.exe :: Class 'core::sync::atomic::AtomicPtr<:sync::mpsc::spsc_queue::node>>>' has a member 'p' of type 'core::cell::UnsafeCell>*>' which does not have a complete definition.
error: breakout.exe :: Class 'std::sync::mpsc::mpsc_queue::Node<:ff::server::message>' has a member 'next' of type 'core::sync::atomic::AtomicPtr<:sync::mpsc::mpsc_queue::node>>' which does not have a complete definition.
[2020-12-18T00:35:58Z DEBUG codelldb::debug_session] Debug event: 000001FD61AA3CF0 Event: broadcaster = 000001FD61D3FAB8 (lldb.process), type = 0x00000001 (state-changed), data = { process = 000001FD61D3FA90 (pid = 1420), state = stopped}
[2020-12-18T00:35:58Z DEBUG codelldb::dap_codec]  {"command":"threads","type":"request","seq":9}
[2020-12-18T00:35:58Z DEBUG codelldb::dap_codec]  {"command":"stackTrace","arguments":{"threadId":7384,"startFrame":0,"levels":1},"type":"request","seq":10}
error: breakout.exe :: Class 'concurrent_queue::unbounded::Block<:runnable::runnable>' has a member 'next' of type 'core::sync::atomic::AtomicPtr<:unbounded::block>>' which does not have a complete definition.
error: breakout.exe :: Class 'async_executor::{{impl}}::tick::generator-0' has a member 'pinned' of type 'core::future::from_generator::GenFuture' which does not have a complete definition.
[2020-12-18T00:36:19Z DEBUG codelldb::dap_codec]  {"command":"stackTrace","arguments":{"threadId":7384,"startFrame":1,"levels":19},"type":"request","seq":11}
[2020-12-18T00:36:19Z DEBUG codelldb::dap_codec] ()","source":{"name":"backtrace.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\std\\src\\sys_common\\backtrace.rs"}},{"column":0,"id":1005,"line":493,"name":"void std::panicking::begin_panic_handler()","source":{"name":"panicking.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\std\\src\\panicking.rs"}},{"column":0,"id":1006,"line":92,"name":"void core::panicking::panic_fmt()","source":{"name":"panicking.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\panicking.rs"}},{"column":0,"id":1007,"line":1268,"name":"void core::option::expect_none_failed()","source":{"name":"option.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\option.rs"}},{"column":0,"id":1008,"line":973,"name":"struct bevy_asset::path::AssetPathId core::result::Result<:path::assetpathid bevy_asset::asset_server::assetservererror>::unwrap<:path::assetpathid>(union core::result::Result<:path::assetpathid bevy_asset::asset_server::assetservererror>, struct core::panic::Location *)","source":{"name":"result.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\result.rs"}},{"column":0,"id":1009,"line":294,"name":"core::ops::generator::GeneratorState bevy_asset::asset_server::{{impl}}::load_untracked::{{closure}}(struct core::pin::Pin, struct core::future::ResumeTy)","source":{"name":"asset_server.rs","path":"D:\\repos\\bevyengine\\bevy\\crates\\bevy_asset\\src\\asset_server.rs"}},{"column":0,"id":1010,"line":80,"name":"core::task::poll::Poll core::future::from_generator::{{impl}}::poll(struct core::pin::Pin*>, struct core::task::wake::Context *)","source":{"name":"mod.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\future\\mod.rs"}},{"column":0,"id":1011,"line":138,"name":"core::ops::generator::GeneratorState async_executor::{{impl}}::spawn::{{closure}},core::future::from_generator::GenFuture>(struct core::pin::Pin, struct core::future::ResumeTy)","source":{"name":"lib.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\async-executor-1.4.0\\src\\lib.rs"}},{"column":0,"id":1012,"line":80,"name":"core::task::poll::Poll core::future::from_generator::{{impl}}::poll(struct core::pin::Pin*>, struct core::task::wake::Context *)","source":{"name":"mod.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\future\\mod.rs"}},{"column":0,"id":1013,"line":489,"name":"static bool async_task::raw::RawTask<:future::from_generator::genfuture>, tuple, closure-0>::run<:future::from_generator::genfuture>,tuple,closure-0>()","source":{"name":"raw.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\async-task-4.0.3\\src\\raw.rs"}},{"column":0,"id":1014,"line":309,"name":"bool async_task::runnable::Runnable::run(struct async_task::runnable::Runnable)","source":{"name":"runnable.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\async-task-4.0.3\\src\\runnable.rs"}},{"column":0,"id":1015,"line":229,"name":"union core::ops::generator::GeneratorState, core::result::Result, async_channel::RecvError>> async_executor::{{impl}}::run::{{closure}}::{{closure}}<:result::result>, async_channel::RecvError>,core::future::from_generator::GenFuture>(struct core::pin::Pin, struct core::future::ResumeTy)","source":{"name":"lib.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\async-executor-1.4.0\\src\\lib.rs"}},{"column":0,"id":1016,"line":80,"name":"union core::task::poll::Poll<:result::result>, async_channel::RecvError>> core::future::from_generator::{{impl}}::poll(struct core::pin::Pin*>, struct core::task::wake::Context *)","source":{"name":"mod.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\future\\mod.rs"}},{"column":0,"id":1017,"line":529,"name":"union core::task::poll::Poll<:result::result>, async_channel::RecvError>> futures_lite::future::{{impl}}::poll<:result::result>, async_channel::RecvError>,core::future::from_generator::GenFuture,core::future::from_generator::GenFuture>(struct core::pin::Pin, core::future::from_generator::GenFuture>*>, struct core::task::wake::Context *)","source":{"name":"future.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\futures-lite-1.11.2\\src\\future.rs"}},{"column":0,"id":1018,"line":236,"name":"union core::ops::generator::GeneratorState, core::result::Result, async_channel::RecvError>> async_executor::{{impl}}::run::{{closure}}<:result::result>, async_channel::RecvError>,core::future::from_generator::GenFuture>(struct core::pin::Pin, struct core::future::ResumeTy)","source":{"name":"lib.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\async-executor-1.4.0\\src\\lib.rs"}},{"column":0,"id":1019,"line":80,"name":"union core::task::poll::Poll<:result::result>, async_channel::RecvError>> core::future::from_generator::{{impl}}::poll(struct core::pin::Pin*>, struct core::task::wake::Context *)","source":{"name":"mod.rs","path":"D:\\.rust\\rustup\\toolchains\\nightly-x86_64-pc-windows-msvc\\lib\\rustlib\\src\\rust\\library\\core\\src\\future\\mod.rs"}},{"column":0,"id":1020,"line":89,"name":"core::result::Result futures_lite::future::block_on::{{closure}}<:result::result>, async_channel::RecvError>,core::future::from_generator::GenFuture>(struct futures_lite::future::block_on::closure-0, struct core::cell::RefCell> *)","source":{"name":"future.rs","path":"D:\\.rust\\cargo\\registry\\src\\github.com-1ecc6299db9ec823\\futures-lite-1.11.2\\src\\future.rs"}}],"totalFrames":36}}
[2020-12-18T00:36:19Z DEBUG codelldb::dap_codec] --> {"command":"scopes","arguments":{"frameId":1001},"type":"request","seq":12}
[2020-12-18T00:36:19Z DEBUG codelldb::dap_codec]  {"command":"variables","arguments":{"variablesReference":1021},"type":"request","seq":13}
[2020-12-18T00:36:20Z DEBUG codelldb::dap_codec] 

This can be most easily reproduced by cloning the bevy repo and running the breakout example via the debugger.

        {
            "type": "lldb",
            "request": "launch",
            "name": "Debug example 'breakout'",
            "cargo": {
                "args": [
                    "build",
                    "--example=breakout",
                    "--package=bevy"
                ],
                "filter": {
                    "name": "breakout",
                    "kind": "example"
                }
            },
            "args": [],
            "cwd": "${workspaceFolder}",
        }

This does not seem to be an issue for smaller projects, so perhaps this is related to startup time? My trivial playground works just fine (there Listening on port 55492 and --port=55494 it seems, so that's not the issue, I suppose.)

Debugging itself seems to work fine, it's just the stdio redirection that is not working.

(Panic in bevy example is due to working directory shenanigans, and is more likely a bevy issue.)

CAD97 avatar Dec 18 '20 00:12 CAD97

CodeLLDB runs a copy of itself in the terminal to figure out which console to attach stdio to. This information is then communicated back to the main instance via that second port you are seeing (the first port is where VSCode attaches to control the debug session). Do you see this "terminal agent" instance starting in the terminal? Does it report any errors?

I've seen reports of this behavior before, but was never able to reproduce locally. I was not able to compile the breakout example because of some errors about missing "__GSHandlerCheck_EH4" symbol, but I doubt it's related to a specific debuggee, and more likely something to do with debugger startup timing.

vadimcn avatar Dec 28 '20 07:12 vadimcn

Failure is inconsistent on my machine as well. It almost certainly has to do with startup timing, and something timing out. It definitely fails more often when something is multitasking, and less often when starting up the debug is the only thing going on.

By launching with "terminal": "external", I see exactly nothing in the external terminal; just "Press any key to continue...". image

Using the integrated terminal, command history shows the command run as & 'c:\Users\CAD\.vscode\extensions\vadimcn.vscode-lldb-1.6.1\adapter\codelldb.exe' 'terminal-agent' '--port=64721' and a $LASTEXITCODE of 0 (unfortunately). Attempting to manually run the command from command history gives "connection actively refused".

CAD97 avatar Dec 29 '20 21:12 CAD97

I'm experiencing this exact issue with a bevy project too. The odd thing is that in two of my projects this does not happen but in other projects it does. I've tried switching between nightly and stable rust, recompiling, reloading, all terminal settings, nothing seems to be able to fix this it just... happens to some projects and not others. I could not tell you the difference other than that they're different projects in different locations configured exactly the same

Edit: I tried creating a completely fresh project and this seems to happen only when I add the DefaultPlugins, but I also add those in the projects where it works correctly, so I'm pretty stumped at what could cause this to happen

Edit 2: It started randomly working after I commented out some code, got a panic on run, added the code back in, and now it works. Seems like this might be a really convoluted edge case

Sheepyhead avatar Aug 22 '21 20:08 Sheepyhead

Just fixed something while investigating another bug, wondering if it was the root cause of this one as well. Can you try this build?

vadimcn avatar Sep 11 '21 06:09 vadimcn

Can confirm it's happening with MSYS Clang 13.0.1 and CodeLLDB 1.7.0. Having a working cout is almost impossible.

amyspark avatar Apr 06 '22 15:04 amyspark