LLDB test failures on linux

Subprojects LLDB
1

Using a debug build of llvm, and running ninja check-lldb I get the following results:

********************
Unresolved Tests (13):
  lldb-api :: commands/expression/import-std-module/array/TestArrayFromStdModule.py
  lldb-api :: commands/expression/import-std-module/conflicts/TestStdModuleWithConflicts.py
  lldb-api :: commands/expression/import-std-module/deque-basic/TestDequeFromStdModule.py
  lldb-api :: commands/expression/import-std-module/forward_list-dbg-info-content/TestDbgInfoContentForwardListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/forward_list/TestForwardListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/iterator/TestIteratorFromStdModule.py
  lldb-api :: commands/expression/import-std-module/list/TestListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/non-module-type-separation/TestNonModuleTypeSeparation.py
  lldb-api :: commands/expression/import-std-module/retry-with-std-module/TestRetryWithStdModule.py
  lldb-api :: commands/expression/import-std-module/shared_ptr-dbg-info-content/TestSharedPtrDbgInfoContentFromStdModule.py
  lldb-api :: commands/expression/import-std-module/vector-of-vectors/TestVectorOfVectorsFromStdModule.py
  lldb-api :: commands/expression/import-std-module/weak_ptr-dbg-info-content/TestDbgInfoContentWeakPtrFromStdModule.py
  lldb-api :: commands/expression/import-std-module/weak_ptr/TestWeakPtrFromStdModule.py

********************
Timed Out Tests (4):
  lldb-api :: commands/expression/import-std-module/basic/TestImportStdModule.py
  lldb-api :: commands/expression/import-std-module/shared_ptr/TestSharedPtrFromStdModule.py
  lldb-api :: tools/lldb-server/TestGdbRemoteFork.py
  lldb-api :: tools/lldb-server/TestLldbGdbServer.py

********************
Failed Tests (3):
  lldb-api :: commands/expression/import-std-module/deque-dbg-info-content/TestDbgInfoContentDequeFromStdModule.py
  lldb-api :: commands/expression/import-std-module/list-dbg-info-content/TestDbgInfoContentListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/vector-dbg-info-content/TestDbgInfoContentVectorFromStdModule.py

Anyone else seeing these?

Can we increase the timeout on some of these? (though, also, the lldb tests do seem to take quite a while, perhaps there are ways we could speed them up?)

Hmm, even the tests that aren’t timing out are taking a very long time - I tried the import-std-module/array test, and it would take several minutes.

I tried debugging the dotest, and each expression evaluation paused visibly - maybe a second or two.

but if I run the same lldb on the command line on the test the commands do still fail (the test is testing lldb’s ability to load the std library pcm - and I assume I don’t have one to load on Linux - so I assume the test shouldn’t be enabled, but I was looking at the array test expecting to find it disabled and find a way to disable the deque, etc, /failing/ tests the same way, but now it looks like they’re all running and failing, but not sure why they fail in different ways) but the commands run quite quickly/reasonably.

Anyone have ideas about any of this?

@labath ?

2

What’s your cmake config for the build?

At least for:

  lldb-api :: tools/lldb-server/TestGdbRemoteFork.py
  lldb-api :: tools/lldb-server/TestLldbGdbServer.py

In my experience these end up stuck rather than taking too much time. Though it’s possible high machine load could cause a timeout.

Do you have the log output for the unsupported tests? Though it may be cryptic, quite likely our test for the presence of the pcm is too lax.

3

I’ve been running ‘ninja check-lldb’ a lot over the past year (working on Data Inspection Language), and those tests you show have ALWAYS failed or timed out for me. I have never seen any of them pass. (This is on Linux).

I should mention: They are failing on “vanilla” versions of LLDB, not just my modified version.

4

We tested them on Linux-to-Linux remote testing configuration and had a similar list of fails/unresolveds. Some were fixed after adjusting cmake command and Makefile.rules file, and some required adding additional flags to their own Makefiles. We build lldb together with libcxx.
Currently, we have them green, excepting a couple of tests disabled for remote execution. I’m gonna send at least one PR soon.

Also, if you shared a log with error messages, we could synchronize and figure them out. (I’ve noticed that for some reason we didn’t run tests from libcxx category locally, but I suppose they should pass locally if they pass against remote target)

5

Hmm, I’ll make a follow-up post with more complete repro steps, but for now here’s an odd observation.

I tried timing one particular test:

time /usr/bin/python3 $HOME/dev/llvm/src/lldb/test/API/dotest.py -u CXXFLAGS -u CFLAGS --env ARCHIVER=$HOME/install/bin/llvm-ar --env OBJCOPY=$HOME/install/bin/llvm-objcopy --env LLVM_LIBS_DIR=$HOME/dev/llvm/build/default/./lib --env LLVM_INCLUDE_DIR=$HOME/dev/llvm/build/default/include --env LLVM_TOOLS_DIR=$HOME/dev/llvm/build/default/./bin --libcxx-include-dir $HOME/dev/llvm/build/default/include/c++/v1 --libcxx-include-target-dir $HOME/dev/llvm/build/default/include/x86_64-unknown-linux-gnu/c++/v1 --libcxx-library-dir $HOME/dev/llvm/build/default/./lib/x86_64-unknown-linux-gnu --arch x86_64 --build-dir $HOME/dev/llvm/build/default/lldb-test-build.noindex --lldb-module-cache-dir $HOME/dev/llvm/build/default/lldb-test-build.noindex/module-cache-lldb/lldb-api --clang-module-cache-dir $HOME/dev/llvm/build/default/lldb-test-build.noindex/module-cache-clang/lldb-api --executable $HOME/dev/llvm/build/default/./bin/lldb --compiler $HOME/dev/llvm/build/default/./bin/clang --dsymutil $HOME/dev/llvm/build/default/./bin/dsymutil --llvm-tools-dir $HOME/dev/llvm/build/default/./bin --lldb-obj-root $HOME/dev/llvm/build/default/tools/lldb --lldb-libs-dir $HOME/dev/llvm/build/default/./lib $HOME/dev/llvm/src/lldb/test/API/commands/expression/import-std-module/array -p TestArrayFromStdModule.py

And when I ran this yesterday the timing was:

real    10m34.451s
user    3m49.275s
sys     0m5.809s

But today it was much quicker:

real    1m29.948s
user    1m26.456s
sys     0m4.088s

And tried from ninja and saw the slower time again:

$ time ninja check-lldb-api-commands-expression-import-std-module-array                                                            
[0/6] Performing build step for 'runtimes'                                                                                                                                                   
ninja: no work to do.                                                                                                                                                                        
[2/6] No install step for 'runtimes'                                                                                                                                                         
[5/6] Running lit suite $HOME/dev/llvm/src/lldb/test/API/commands/expression/import-std-module/array                                                                
llvm-lit: $HOME/dev/llvm/src/lldb/test/API/lit.cfg.py:125: note: Deleting module cache at $HOME/dev/llvm/build/default/lldb-test-build.noin
dex/module-cache-lldb/lldb-api.
TIMEOUT: lldb-api :: commands/expression/import-std-module/array/TestArrayFromStdModule.py (1 of 1)
******************** TEST 'lldb-api :: commands/expression/import-std-module/array/TestArrayFromStdModule.py' FAILED ********************
Script:
--
/usr/bin/python3 $HOME/dev/llvm/src/lldb/test/API/dotest.py -u CXXFLAGS -u CFLAGS --env ARCHIVER=$HOME/install/bin/llvm-ar --env OBJCOPY=$HOME/install/bin/llvm-objcopy --env LLVM_LIBS_DIR=$HOME/dev/llvm/build/default/./lib --env LLVM_INCLUDE_DIR=$HOME/dev/llvm/build/default/include --env LLVM_TOOLS_DIR=$HOME/dev/llvm/build/default/./bin --libcxx-include-dir $HOME/dev/llvm/build/default/include/c++/v1 --libcxx-include-target-dir $HOME/dev/llvm/build/default/include/x86_64-unknown-linux-gnu/c++/v1 --libcxx-library-dir $HOME/dev/llvm/build/default/./lib/x86_64-unknown-linux-gnu --arch x86_64 --build-dir $HOME/dev/llvm/build/default/lldb-test-build.noindex --lldb-module-cache-dir $HOME/dev/llvm/build/default/lldb-test-build.noindex/module-cache-lldb/lldb-api --clang-module-cache-dir $HOME/dev/llvm/build/default/lldb-test-build.noindex/module-cache-clang/lldb-api --executable $HOME/dev/llvm/build/default/./bin/lldb --compiler $HOME/dev/llvm/build/default/./bin/clang --dsymutil $HOME/dev/llvm/build/default/./bin/dsymutil --llvm-tools-dir $HOME/dev/llvm/build/default/./bin --lldb-obj-root $HOME/dev/llvm/build/default/tools/lldb --lldb-libs-dir $HOME/dev/llvm/build/default/./lib $HOME/dev/llvm/src/lldb/test/API/commands/expression/import-std-module/array -p TestArrayFromStdModule.py
--
Exit Code: -9
Timeout: Reached timeout of 600 seconds

Command Output (stdout):
--
lldb version 19.0.0git (git@github.com:llvm/llvm-project.git revision 6f04f46927cf54d19cc2a1470f47d5db4b3b96bb)
  clang revision 6f04f46927cf54d19cc2a1470f47d5db4b3b96bb
  llvm revision 6f04f46927cf54d19cc2a1470f47d5db4b3b96bb

--
Command Output (stderr):
--
UNSUPPORTED: LLDB ($HOME/dev/llvm/build/default/bin/clang-x86_64) :: test_dsym (TestArrayFromStdModule.TestCase.test_dsym) (test case does not fall in any category of interest for this run) 

--

********************
********************
Timed Out Tests (1):
  lldb-api :: commands/expression/import-std-module/array/TestArrayFromStdModule.py


Testing Time: 600.15s

Total Discovered Tests: 1
  Timed Out: 1 (100.00%)
FAILED: tools/lldb/test/API/CMakeFiles/check-lldb-api-commands-expression-import-std-module-array $HOME/dev/llvm/build/default/tools/lldb/test/API/CMakeFiles/check-lldb-api-commands-expression-import-std-module-array 
cd $HOME/dev/llvm/build/default/tools/lldb/test/API && /usr/bin/python3 $HOME/dev/llvm/build/default/./bin/llvm-lit -sv $HOME/dev/llvm/src/lldb/test/API/commands/expression/import-std-module/array
ninja: build stopped: subcommand failed.

real    10m2.493s
user    9m52.241s
sys     0m8.826s

OK, so I think I can isolate some of that cost - the long runs are when the module cache has been deleted.

This is probably partly due to testing with a debug/unoptimized clang - I’m under the impression that most folks developing lldb do it in a separate build (if they’re using a debug/unoptimized lldb, that is) pointing to a pre-built optimized clang?

But also, perhaps the module cache shouldn’t be deleted on every run? It could be a cached build artifact same as any other… ?

And maybe some of this is related to the fine-grained modules for libc++? There’s some ongoing debate/discussion about fine-grained modules V monolithic module for the standard library. ( [libc++] Per-header header modules · Issue #86193 · llvm/llvm-project · GitHub )

6

The 1m30s time is still quite slow, and when stepping through the test with pdb there’s still a noticable delay (second or so, at a very rough guess) for every expression evaluation…

Anyone know anything about that?

7

I’m seeing these same 3 failures in our release build configuration:

8

We do make sure they run on the macOS bots cleanly. But yea, would be great to speed these up. In a fresh session, we’d rebuild the std module using implicit modules, so that’s why it’s taking so long. But subsequent evaluations shouldnt be expensive because we cached the pcms (the module cache gets purged when running check-lldb though). Have never tried running these on Linux, but will try to run these locally and see

9

Here’s my configuration:

cmake -G Ninja -
DCMAKE_C_COMPILER=clang \
-DCMAKE_CXX_COMPILER=clang++ \
-DLLVM_ENABLE_WERROR=true \
-DLIBCXX_ENABLE_WERROR=true \
-DLLVM_BUILD_EXAMPLES=true \
-DCMAKE_BUILD_TYPE=Debug \
-DLLVM_ENABLE_ASSERTIONS=true \
-DLLVM_OPTIMIZED_TABLEGEN=true \
-DLLVM_USE_LINKER=lld \
-DLLVM_ENABLE_PROJECTS='llvm;clang;clang-tools-extra;lld;lldb;cross-project-tests;compiler-rt' \
-DLLVM_ENABLE_RUNTIMES='libcxxabi;libcxx;libunwind' \
-DLLVM_ENABLE_BINDINGS=Off \
-DLLDB_ENABLE_PYTHON=On \
-DLLVM_USE_SPLIT_DWARF=true \
~/dev/llvm/src/llvm
time ninja check-lldb

cmake stdout
cmake stderr
ninja stdout
ninja stderr

10

What do you mean by “subsequent evaluations” compared to “module cache gets purged when running check-lldb”?

If it’s purged every time - then that probably explains the timeouts - it gets purged, then ninja runs lots of parallel threads to test all the different things - but they all block waiting for the pcms to be rebuilt, and timeout.

Why does it get purged? (but also, it is kinda slow - and even when it’s present the tests are kinda slow - would love to know how to debug through the expression evaluation calls from the python into the SBAPI to see what it’s spending a whole second on for relatively small expression evaluations)

11

Hmm, comment says “this is necessary whenever clang changes underneath” - but wouldn’t the module cache hashes include the compiler hash to avoid this sort of problem?

12

But I guess even if we did change things to not always purge the cache - on actual clang changes (more frequent than lldb changes anyway) it’d become invalidate/slow/have the same problems…

13

Yeah, so if I remove the cache deleting, I don’t get all the timeouts.

At least we could/should probably bump the timeouts to handle an unoptimized build running from a cold/empty cache?

(still, 10 minutes is a fair while:

real    10m3.966s
user    313m19.797s
sys     21m15.431s

(on the second run of time check-lldb with the cache deleting disabled))

Compared to check-llvm:

real    4m40.741s
user    497m37.806s
sys     55m32.028s

And check-clang:

real    8m32.833s
user    836m23.942s
sys     49m23.462s

(not that any of these are /great/ FWIW, but anyway)

14

Thank you!
Could you take a look if this fixes the failures [lldb][test] Enable static linking with libcxx for import-std-module tests by dzhidzhoev ¡ Pull Request #98701 ¡ llvm/llvm-project ¡ GitHub with your config by chance? (Warning: a single test takes up to 10 minutes to execute as well as the rest of the tests in question)

15

Thanks for checking
@adrian.prantl might know why the module cache deletion was necessary at the beginning of the test-suite.

FWIW, I’ve seen the module-cache deletion not quite work occasionally (i.e., concurrent import-std-module tests corrupting each others module cache). Just never got around to investigating this deeper (particularly the ...-dbg-info-content tests are prone to this IIRC).

But would definitely like to know if we can speed this up. Currently the expression evaluator just sticks a @import std in the expression source of your expression. Since we have finer grained std modules now, maybe we can be cleverer about this? Haven’t thought this through much though

16

The LLDB testsuite doesn’t use the global clang module cache because bugs in ToT clang can result in a corrupt cache, which is something that is very hard to diagnose on a bot. To avoid any potential side-effects of a warmed-up module cache produced by an older version of clang, check-lldb deletes the cache before running the tests.

17

Isn’t the compiler version in the cache key? So it’d be pretty unlikely they’d get reused and cause problems? (I guess there’s a risk of using up storage space on a bot - nothing to clear out old caches, so they’d accumulate indefinitely - could have some fancier step that deletes all but the most recently modified cache? (Would hurt local use when switching between branches, but at least ongoing work on one branch wouldn’t incur the heavy rebuild cost))

18

You’re correct that the version should be part of the cache key. This is about maximizing the reliability of bots running 24/7 with potentially very broken revisions of clang. Accumulating a clang module cache over time adds nondeterminism and reproducability problems to the bot. The LLDB test suite is not about testing Clang’s implicit module cache, so eliminating this variable seemed like the right choice at the time.
For local development, you’re usually not running the entire test suite, but are iterating on a at most a handful of tests using lldb-dotest directly (which doesn’t clear the cache). If you’re running the entire test suite, compiling the std and Foundation module should be <15s of lost parallelism and not add too much overhead to a full run.

1 Like
19

You’re correct that the version should be part of the cache key.

Seems like the sort of thing we could verify, and /probably/ rely on going forward? Or is the risk of regression large enough that it’s worth the cost to test execution time?

I guess by “very broken versions of clang” you’re concerned about that property regressing?

For bots, perhaps we could have a separate option that’s more conservative? & developers could not have to incur that cost?

For local development, you’re usually not running the entire test suite, but are iterating on a at most a handful of tests using lldb-dotest directly (which doesn’t clear the cache).

Hmm - that’s not usually been the way I deal with this sort of thing. CMake does provide sub-targets (eg: ninja check-lldb-api-commands-expression) which can be convenient to run a subset of the tests but does still trigger the cache clearing.

And the cost to do a full check-lldb should still be important to validating changes overall, etc.

If you’re running the entire test suite, compiling the std and Foundation module should be <15s of lost parallelism and not add too much overhead to a full run.

So that’s perhaps some of the problem here - as that’s not my experience. I have problems both with targeted execution of one test (if done via the build system, rather than invoking dotest directly) and when running check-lldb overall.

When running one test - a 1m30s test becomes 10m40s (but times out at 10m)

And when running all the tests, these tests timeout:

  lldb-api :: commands/expression/import-std-module/basic/TestImportStdModule.py
  lldb-api :: commands/expression/import-std-module/deque-basic/TestDequeFromStdModule.py
  lldb-api :: commands/expression/import-std-module/forward_list-dbg-info-content/TestDbgInfoContentForwardListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/forward_list/TestForwardListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/iterator/TestIteratorFromStdModule.py
  lldb-api :: commands/expression/import-std-module/list/TestListFromStdModule.py
  lldb-api :: commands/expression/import-std-module/non-module-type-separation/TestNonModuleTypeSeparation.py
  lldb-api :: commands/expression/import-std-module/retry-with-std-module/TestRetryWithStdModule.py
  lldb-api :: commands/expression/import-std-module/vector-of-vectors/TestVectorOfVectorsFromStdModule.py
  lldb-api :: commands/expression/import-std-module/weak_ptr-dbg-info-content/TestDbgInfoContentWeakPtrFromStdModule.py

(& total “check-lldb” time is 10m25s)

Without module cache clearing, all those tests pass.

Removing those other two timing out tests, test execution comes down to 7m30s.

So this is more than 15s - about 2.5m difference in execution time without timing out (but also, those 1m30s execution times for the modules/expression tests still seem problematic too, so perhaps we can get this down further)

20

When running one test - a 1m30s test becomes 10m40s (but times out at 10m)

Am I understanding correctly that you’re running one of these import-std-module tests and it takes 1m30s but when run as part of check-lldb it takes 10m40s? Was trying to reproduce this locally but these tests consistently take ~60s (which is approximately the time it would take to run expr @import std, which is expected as that’s pretty much the meat of each of these tests…though I do agree, that feels like a bit too much for a single test). Maybe finer grained modules can help to bring the 1m30s number down for each individual test? (since we know which modules are needed by each test, though I think this will require some changes to the import-std-module infra since I don’t think one can just import a module and expect the expression evaluator to use it, or at least I haven’t gotten it to work with std)