debuginfo/pretty-std-collections.rs test sometimes fails on macOS

[JohnTitor]

CI on macOS sometimes fails due to this failure:

failures:

---- [debuginfo-lldb] debuginfo/pretty-std-collections.rs stdout ----
NOTE: compiletest thinks it is using LLDB version 1200
NOTE: compiletest thinks it is using LLDB without native rust support

error: Error while running LLDB
stderr:
------------------------------------------
error: need to add support for DW_TAG_base_type '()' encoded with DW_ATE = 0x7, bit_size = 0
clang: CommandLine Error: Option 'h' registered more than once!
LLVM ERROR: inconsistency in registered CommandLine options

------------------------------------------

failures:
    [debuginfo-lldb] debuginfo/pretty-std-collections.rs

You can find the full log here: https://github.com/rust-lang-ci/rust/runs/1340649828
The failure occurs on #78501, #78489, and #78661 (at least).

[JohnTitor]

Oh, I just found the related Zulip topic: https://rust-lang.zulipchat.com/#narrow/stream/242791-t-infra/topic/apple-x86_64.20gha.20checks

[pietroalbini]

Please ping me if another failure happens again.

[wesleywiser]

This just happened in #78448.

[JohnTitor]

Another instance: https://github.com/rust-lang-ci/rust/runs/1356979047

[ssomers]

Not sure if this is useful: I always get the first error about DW_TAG_base_type on my Linux box (Linux debby 4.19.0-11-amd64 #1 SMP Debian 4.19.146-1 (2020-09-17) x86_64 GNU/Linux), just like others reported in #41193. For my purpose, the workaround was to apt uninstall lldb.

[ehuss]

Copying the full log from a recent failure:

thread 'main' panicked at 'Some tests failed', src/tools/compiletest/src/main.rs:354:22
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

failures:

---- [debuginfo-lldb] debuginfo/pretty-std-collections.rs stdout ----
NOTE: compiletest thinks it is using LLDB version 1200
NOTE: compiletest thinks it is using LLDB without native rust support

error: Error while running LLDB
status: exit code: 1
command: "/usr/bin/python3" "/Users/runner/work/rust/rust/src/etc/lldb_batchmode.py" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo/pretty-std-collections.lldb/a" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo/pretty-std-collections.lldb/pretty-std-collections.debugger.script"
stdout:
------------------------------------------
LLDB batch-mode script
----------------------
Debugger commands script is '/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo/pretty-std-collections.lldb/pretty-std-collections.debugger.script'.
Target executable is '/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo/pretty-std-collections.lldb/a'.
Current working directory is '/Users/runner/work/rust/rust'
Creating a target for '/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo/pretty-std-collections.lldb/a'
settings set auto-confirm true

version
lldb-1200.0.32.1 Apple Swift version 5.3 (swiftlang-1200.0.29.2 clang-1200.0.30.1) 
command script import /Users/runner/work/rust/rust/./src/etc/lldb_lookup.py
type synthetic add -l lldb_lookup.synthetic_lookup -x '.*' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)String$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^&str$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^&\[.+\]$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(std::ffi::([a-z_]+::)+)OsString$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)Vec<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)VecDeque<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)BTreeSet<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)BTreeMap<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(std::collections::([a-z_]+::)+)HashMap<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(std::collections::([a-z_]+::)+)HashSet<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)Rc<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(alloc::([a-z_]+::)+)Arc<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(core::([a-z_]+::)+)Cell<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(core::([a-z_]+::)+)Ref<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(core::([a-z_]+::)+)RefMut<.+>$' --category Rust
type summary add -F lldb_lookup.summary_lookup  -e -x -h '^(core::([a-z_]+::)+)RefCell<.+>$' --category Rust
type category enable Rust

breakpoint set --file 'pretty-std-collections.rs' --line 158
DEBUG: breakpoint added, id = 1
Breakpoint 1: where = a`pretty_std_collections::main::h1ef1d7ce5967b6a7 + 1513 at pretty-std-collections.rs:158:5, address = 0x0000000100029399 
DEBUG: registering breakpoint callback, id = 1
Error while trying to register breakpoint callback, id = 1, message = error: could not get num args: can't find callable: breakpoint_callback

run
Process 65589 stopped * thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1 frame #0: 0x0000000100029399 a`pretty_std_collections::main::h1ef1d7ce5967b6a7 at pretty-std-collections.rs:158:5 155 hash_set.insert(i); 156 } 157 -> 158 zzz(); // #break ^ 159 } 160 161 fn zzz() { Target 0: (a) stopped. Process 65589 launched: '/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo/pretty-std-collections.lldb/a' (x86_64) 
print vec_deque
(alloc::collections::vec_deque::VecDeque<int>) $0 = size=3 { [0] = 5 [1] = 3 [2] = 7 } 
print vec_deque2
(alloc::collections::vec_deque::VecDeque<int>) $1 = size=7 { [0] = 2 [1] = 3 [2] = 4 [3] = 5 [4] = 6 [5] = 7 [6] = 8 } 
print hash_map

------------------------------------------
stderr:
------------------------------------------
error: need to add support for DW_TAG_base_type '()' encoded with DW_ATE = 0x7, bit_size = 0
clang: CommandLine Error: Option 'h' registered more than once!
LLVM ERROR: inconsistency in registered CommandLine options

------------------------------------------



failures:
    [debuginfo-lldb] debuginfo/pretty-std-collections.rs

test result: FAILED. 89 passed; 1 failed; 26 ignored; 0 measured; 0 filtered out



command did not execute successfully: "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/stage0-tools-bin/compiletest" "--compile-lib-path" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/stage2/lib" "--run-lib-path" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/stage2/lib/rustlib/x86_64-apple-darwin/lib" "--rustc-path" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/stage2/bin/rustc" "--src-base" "/Users/runner/work/rust/rust/src/test/debuginfo" "--build-base" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/test/debuginfo" "--stage-id" "stage2-x86_64-apple-darwin" "--mode" "debuginfo" "--target" "x86_64-apple-darwin" "--host" "x86_64-apple-darwin" "--llvm-filecheck" "/Users/runner/work/rust/rust/build/x86_64-apple-darwin/llvm/build/bin/FileCheck" "--nodejs" "/usr/local/bin/node" "--host-rustcflags" "-Crpath -O -Cdebuginfo=0 -Zunstable-options  -Lnative=/Users/runner/work/rust/rust/build/x86_64-apple-darwin/native/rust-test-helpers" "--target-rustcflags" "-Crpath -O -Cdebuginfo=0 -Zunstable-options  -Lnative=/Users/runner/work/rust/rust/build/x86_64-apple-darwin/native/rust-test-helpers" "--docck-python" "/usr/local/opt/python@2.7.17/bin/python2.7" "--lldb-python" "/usr/bin/python3" "--lldb-version" "lldb-1200.0.32.1\nApple Swift version 5.3 (swiftlang-1200.0.29.2 clang-1200.0.30.1)\n" "--lldb-python-dir" "/Applications/Xcode_12.app/Contents/SharedFrameworks/LLDB.framework/Resources/Python3" "--llvm-version" "11.0.0-rust-1.49.0-nightly" "--llvm-components" "aarch64 aarch64asmparser aarch64codegen aarch64desc aarch64disassembler aarch64info aarch64utils aggressiveinstcombine all all-targets analysis arm armasmparser armcodegen armdesc armdisassembler arminfo armutils asmparser asmprinter avr avrasmparser avrcodegen avrdesc avrdisassembler avrinfo binaryformat bitreader bitstreamreader bitwriter cfguard codegen core coroutines coverage debuginfocodeview debuginfodwarf debuginfogsym debuginfomsf debuginfopdb demangle dlltooldriver dwarflinker engine executionengine extensions frontendopenmp fuzzmutate globalisel gtest gtest_main hexagon hexagonasmparser hexagoncodegen hexagondesc hexagondisassembler hexagoninfo instcombine instrumentation interpreter ipo irreader jitlink libdriver lineeditor linker lto mc mca mcdisassembler mcjit mcparser mips mipsasmparser mipscodegen mipsdesc mipsdisassembler mipsinfo mirparser msp430 msp430asmparser msp430codegen msp430desc msp430disassembler msp430info native nativecodegen nvptx nvptxcodegen nvptxdesc nvptxinfo objcarcopts object objectyaml option orcerror orcjit passes powerpc powerpcasmparser powerpccodegen powerpcdesc powerpcdisassembler powerpcinfo profiledata remarks riscv riscvasmparser riscvcodegen riscvdesc riscvdisassembler riscvinfo riscvutils runtimedyld scalaropts selectiondag sparc sparcasmparser sparccodegen sparcdesc sparcdisassembler sparcinfo support symbolize systemz systemzasmparser systemzcodegen systemzdesc systemzdisassembler systemzinfo tablegen target testingsupport textapi transformutils vectorize webassembly webassemblyasmparser webassemblycodegen webassemblydesc webassemblydisassembler webassemblyinfo windowsmanifest x86 x86asmparser x86codegen x86desc x86disassembler x86info xray" "--cc" "" "--cxx" "" "--cflags" "" "--adb-path" "adb" "--adb-test-dir" "/data/tmp/work" "--android-cross-path" "" "--color" "always"
expected success, got: exit code: 101


failed to run: /Users/runner/work/rust/rust/build/bootstrap/debug/bootstrap --stage 2 test
Build completed unsuccessfully in 1:23:21

The error: need to add support for DW_TAG_base_type is normal, this happens on Linux, too (not sure why).

The error can't find callable: breakpoint_callback is also normal, this happens on Linux. The issue here is that the function isn't imported. The lldb script interpreter has a "session" dictionary, and functions need to be specifically added to it to be called. I'm not sure how it worked previously (maybe older versions of lldb worked differently). Regardless, I suspect it is unrelated (this error is ignored).

I've tried running the test in a loop locally, but have been unable to get it to fail. It looks like it is failing while trying to print out hash_map, which normally should display something like this:

print hash_map
(std::collections::hash::map::HashMap<unsigned long, unsigned long, core::hash::BuildHasherDefault<pretty_std_collections::SimpleHasher> >) $2 = size=4 { [0] = { 0 = 1 1 = 10 } [1] = { 0 = 2 1 = 20 } [2] = { 0 = 3 1 = 30 } [3] = { 0 = 4 1 = 40 } }

[est31]

Another instance: #78804 (comment)

[ehuss]

I'm not sure if anyone else is looking into this issue. I've tried many experiments with little success. I've never been able to reproduce locally, but I can pretty reliably reproduce on GitHub Actions.

The only change that seems to reliably avoid the error is to remove -C prefer-dynamic when building the test. I don't have any theories as to why that is.

If you search for the error messages on Google, you can find many other people running into similar situations. It seems like most of them are related to somehow dynamically linking the wrong LLVM. I'm not sure how that fits for this situation. I'm also unsure if lldb is somehow linking the wrong LLVM, why it doesn't fail 100% of the time. I'm also uncertain exactly how the error is originating (does lldb launch clang somehow?).

[petrochenkov]

Failed again and again in #78782 and #78826.

[pietroalbini]

I should get an actual macOS device to investigate this more productively early next week.

[varkor]

Failed in #78590.

[ehuss]

Minor update of other clues I've discovered:

• Downgrading to Xcode 11.7 makes the problem go away (Xcode 12.0, 12.1, and 12.2 all seem to fail)
• Removing type synthetic add from the debugger script makes the problem go away (or just changing it to return None). That involves a fairly large amount of Python code, but none of it seems particularly fishy to me. What's really strange is that when it fails, none of my debug print statements appear (even though all buffering should be disabled).

@ortem as the author of the lldb_providers, do you have much experience with debugging lldb issues? Do you think you could provide any insight or help here? Just to summarize, there is a test (pretty-std-collections.rs) which is periodically failing on the macOS builders with this error:

clang: CommandLine Error: Option 'h' registered more than once!
LLVM ERROR: inconsistency in registered CommandLine options

This happens when calling print hash_map which launches the StdHashMapSyntheticProvider. I haven't been able to reproduce it locally, only on GitHub Actions. I'm at a loss as to what could be different about their environment.

[ssomers]

Failed in #78631.

failing on the macOS builders with this error:

clang: CommandLine Error: Option 'h' registered more than once!
LLVM ERROR: inconsistency in registered CommandLine options

Are you sure that is the problem, other than it is the only from the 3 errors displayed not yet debunked here? In my experience - with gdb, not lldb! - stderr is suppressed if the test succeeds, so you need to explicitly fail the test to see whether this error is also normal on that platform. What is displayed in the report is the contents of a file, that earlier in the test execution contains other messages - at least rustc warnings about the test case code compiled. I had the impression there were 5 stages, each of which might be overwriting useful diagnostics from an earlier stage.

[artemmukhin]

@ehuss Looks like the problem occurs only when using LLDB without native Rust support, isn't it? If so, it may be helpful to disable this specific test from pretty-std-collections.rs for such LLDB by deleting // lldbg-check: ... line right after // lldb-command:print hash_map command. If this doesn't help, you can also try to disable all the pretty-std-collections.rs tests on macOS by adding // ignore-macos line.

Regarding removing type synthetic add, it just disables all the LLDB pretty-printers responsible for children formatting (like vector or map elements), and so the HashMap elements will not be printed by the debugger. I think the problem is probably related to LLDB itself, but not to Python pretty-printers implementation. But it might be helpful to debug the pretty-printers code using logging: just insert logging like that to lldb_providers.py and add something like this to lldb_lookup.py

lldb.formatters.Logger._lldb_formatters_debug_level = 2
lldb.formatters.Logger._lldb_formatters_debug_filename = "~/lldb.py.log"

[ehuss]

Thanks for the tip on the logger, I was assuming setting PYTHONUNBUFFERED would allow stderr to print, but I guess not.

I'm concerned about just disabling the test, as it feels like sweeping the problem under the rug without understanding what is wrong. It does seem likely it is an issue with lldb, but I think it would be good to at least have some vague understanding of what is wrong, and why it only affects this test.

Sorry, I'm not too familiar with lldb or the Rust integration. What do you mean by "LLDB without native Rust support"? What little information I can find at https://rustc-dev-guide.rust-lang.org/debugging-support-in-rustc.html#lldb seems to point to a repository that is archived and hasn't been updated in 3 years. AFAIK, building a custom lldb was removed over a year ago (#62592). I can see a small amount of rust support in upstream LLDB, but it seems to be just a stub.

It is a bit difficult to compare, but the lldb in rust-lang/llvm-project is a fair bit different from apple/llvm-project.

With logging, the last line printed is consistently just before this line. Looking through the LLDB source, if I'm reading it correctly, this triggers creating a TypeSystem which I believe for Rust is TypeSystemClang. Unfortunately that is a pretty large amount of code.

[ehuss]

@shepmaster added a new data point that they were able to reproduce on the Apple DTK (aarch64-apple-darwin), which helps rule out anything special about GitHub's environment.

I'm going to be away for a week or two, so I won't be able to look at this anymore. I would recommend that if nobody wants to investigate this further, that someone should add // ignore-macos just to avoid the CI errors. I suspect that doing that means it will likely never get fixed, but I suspect it's an issue deep inside lldb and a bit out of our control anyways.

[pietroalbini]

This also reproduced locally on a pratically clean macOS 10.15 installation by running ./x.py test --stage 2 src/test/debuginfo (before I was running it with --stage 1).

[est31]

The test file already has ignore-windows, ignore-freebsd, ignore-android... I think an ignore-macos won't be much of an issue.

[est31]

→ #79094

[artemmukhin]

@ehuss

Sorry, I'm not too familiar with lldb or the Rust integration. What do you mean by "LLDB without native Rust support"?
...building a custom lldb was removed over a year ago

You're right, seems like "LLDB with native Rust support" (which is basically LLDB with Rust support patches) is not used in rustc anymore. However, it is used in IntelliJ Rust and CodeLLDB AFAIK.

BTW, probably @tromey could tell something about error: need to add support for DW_TAG_base_type '()' encoded with DW_ATE = 0x7, bit_size = 0 error regarding LLDB? Was this problem fixed in the Rust-enabled LLDB?

@est31 There are really lots of ignored debugging tests, so I agree with you that disabling these tests on macOS won't make it much worse.

[tromey]

BTW, probably @tromey could tell something about error: need to add support for DW_TAG_base_type '()' encoded with DW_ATE = 0x7, bit_size = 0 error regarding LLDB? Was this problem fixed in the Rust-enabled LLDB?

Yes, but maybe not in the way you may be thinking. In LLDB, each language provides its own code to analyze DWARF. So, the Rust-specific DWARF analysis handles this case without issuing an error. See DWARFASTParserRust::ParseSimpleType for the DWARF-reading bit. Offhand I would expect it to use DW_ATE_void, and digging through the LLDB patches a bit supports this, but I'm not sure. This kind of difference is trivial to handle though.

[ehuss]

I think an unintended consequence of #79094 is that pretty-std-collections is no longer tested on any platform, and it has been broken over time (#81814).

[est31]

@ehuss my PR only ignored the test on Mac OS. It should still be tested on Linux, no?

[ehuss]

@est31 See #81813.

[est31]

@ehuss oh that's unfortunate. It was definitely not my intent when doing that. The gdb tests should still be run. At least when I change something in the gdb related text on my local Linux machine I get a test failure (otherwise a success). For some reason I don't get such a reaction when altering the lldb related text tho.

[est31]

(To make it clear, the premise of #79094 was that it does still run all the tests on linux, but apparently the lldb ones were only run on mac OS.... I installed lldb locally on my Linux and it's broken.... maybe the solution is really to make the Linux box do sudo apt install lldb somewhere)