[lldb-vscode] Restart tests always time out on ARM

[luporl]

These tests were added by https://reviews.llvm.org/D147831 and since then the Arm bots are failing:
https://lab.llvm.org/buildbot/#/builders/17/builds/37531

TIMEOUT: lldb-api :: tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.py (2554 of 2554)
******************** TEST 'lldb-api :: tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.py' FAILED ********************
Script:
--
/usr/bin/python3.10 /home/tcwg-buildbot/worker/lldb-arm-ubuntu/llvm-project/lldb/test/API/dotest.py -u CXXFLAGS -u CFLAGS --env ARCHIVER=/usr/bin/llvm-ar --env OBJCOPY=/usr/bin/llvm-objcopy --env LLVM_LIBS_DIR=/home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./lib --env LLVM_INCLUDE_DIR=/home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/include --env LLVM_TOOLS_DIR=/home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./bin --arch armv8l --build-dir /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/lldb-test-build.noindex --lldb-module-cache-dir /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/lldb-test-build.noindex/module-cache-lldb/lldb-api --clang-module-cache-dir /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/lldb-test-build.noindex/module-cache-clang/lldb-api --executable /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./bin/lldb --compiler /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./bin/clang --dsymutil /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./bin/dsymutil --llvm-tools-dir /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./bin --lldb-libs-dir /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/./lib /home/tcwg-buildbot/worker/lldb-arm-ubuntu/llvm-project/lldb/test/API/tools/lldb-vscode/restart -p TestVSCode_restart_runInTerminal.py
--
Exit Code: -9
Timeout: Reached timeout of 600 seconds
Command Output (stdout):
--
lldb version 17.0.0git (https://github.com/llvm/llvm-project.git revision 80c643c46422e2af165aacf5d556604b118598b8)
  clang revision 80c643c46422e2af165aacf5d556604b118598b8
  llvm revision 80c643c46422e2af165aacf5d556604b118598b8
--
Command Output (stderr):
--
Timed out trying to get messages from the debug adaptor
--
********************
********************
Timed Out Tests (1):
  lldb-api :: tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.py
Testing Time: 1034.95s
  Unsupported      :  469
  Passed           : 2294
  Expectedly Failed:   26
  Timed Out        :    1
FAILED: tools/lldb/test/CMakeFiles/check-lldb /home/tcwg-buildbot/worker/lldb-arm-ubuntu/build/tools/lldb/test/CMakeFiles/check-lldb 

[llvmbot]

@llvm/issue-subscribers-lldb

[rupprecht]

@walter-erquinigo @slackito

50337fb disabled lldb/test/API/tools/lldb-vscode/runInTerminal/TestVSCode_runInTerminal.py for Arm as well (actually anything non-x86). Disabling these too for consistency SGTM -- I see you've done that just now. That commit just mentions that this feature is not needed on Arm, it doesn't say if it's expected that it doesn't work on Arm. If this is WAI, we might just close this bug now that the test is skipped.

I wonder why is it timing out? Any way to find out what it's waiting for? Adding -t should increase the log verbosity, and might give a hint.

[luporl]

Do you mean adding -t to dotest.py? If so, the result is below.

I guess it would be ok to disable this feature on Arm, but it would really be nice to know why it doesn't work.

/usr/bin/python3.10 /home/tcwg-buildbot/debug/llvm-project/lldb/test/API/dotest.py -u CXXFLAGS -u CFLAGS --env ARCHIVER=/usr/bin/llvm-ar --env OBJCOPY=/usr/bin/llvm-objcopy --env LLVM_LIBS_DIR=/home/tcwg-buildbot/debug/build/./lib --env LLVM_INCLUDE_DIR=/home/tcwg-buildbot/debug/build/include --env LLVM_TOOLS_DIR=/home/tcwg-buildbot/debug/build/./bin --arch armv8l --build-dir /home/tcwg-buildbot/debug/build/lldb-test-build.noindex --lldb-module-cache-dir /home/tcwg-buildbot/debug/build/lldb-test-build.noindex/module-cache-lldb/lldb-api --clang-module-cache-dir /home/tcwg-buildbot/debug/build/lldb-test-build.noindex/module-cache-clang/lldb-api --executable /home/tcwg-buildbot/debug/build/./bin/lldb --compiler /home/tcwg-buildbot/debug/build/./bin/clang --dsymutil /home/tcwg-buildbot/debug/build/./bin/dsymutil --llvm-tools-dir /home/tcwg-buildbot/debug/build/./bin --lldb-libs-dir /home/tcwg-buildbot/debug/build/./lib /home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart -p TestVSCode_restart_runInTerminal.py -t
lldb version 17.0.0git (https://github.com/llvm/llvm-project.git revision 60d9010aaf0f09c6ccc4ae130be10f360f93612b)
  clang revision 60d9010aaf0f09c6ccc4ae130be10f360f93612b
  llvm revision 60d9010aaf0f09c6ccc4ae130be10f360f93612b
Skipping the following test categories: ['libc++', 'dsym', 'gmodules', 'debugserver', 'objc']
Change dir to: /home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart
runCmd: settings clear -all
output:

runCmd: settings set symbols.enable-external-lookup false
output:

runCmd: settings set target.inherit-tcc true
output:

runCmd: settings set target.detach-on-error false
output:

runCmd: settings set target.auto-apply-fixits false
output:

runCmd: settings set plugin.process.gdb-remote.packet-timeout 60
output:

runCmd: settings set symbols.clang-modules-cache-path "/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/module-cache-lldb/lldb-api"
output:

runCmd: settings set use-color false
output:

make VPATH=/home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart -C /home/tcwg-buildbot/debug/build/lldb-test-build.noindex/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.test_basic_functionality -I /home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart -I /home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make -f /home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart/Makefile all ARCH=armv8l 'CC="/home/tcwg-buildbot/debug/build/bin/clang"' CLANG_MODULE_CACHE_DIR=/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/module-cache-clang/lldb-api

make: Entering directory '/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.test_basic_functionality'
"/home/tcwg-buildbot/debug/build/bin/clang" -g -O0   -I/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make/../../../../../include -I/home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart -I/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make -include /home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make/test_common.h -fno-limit-debug-info   -MT main.o -MD -MP -MF main.d -c -o main.o /home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart/main.c
"/home/tcwg-buildbot/debug/build/bin/clang" main.o -g -O0   -I/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make/../../../../../include -I/home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart -I/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make -include /home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/make/test_common.h -fno-limit-debug-info     --driver-mode=g++ -o "a.out"
make: Leaving directory '/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.test_basic_functionality'


Adding tearDown hook:         def cleanup():
            if disconnectAutomatically:
                self.vscode.request_disconnect(terminateDebuggee=True)
            self.vscode.terminate()


Timed out trying to get messages from the debug adaptor

[luporl]

There is more info, when the test is interrupted:

========= DEBUG ADAPTER PROTOCOL LOGS =========
-->
Content-Length: 307

{"command":"initialize","type":"request","arguments":{"adapterID":"lldb-native","clientID":"vscode","columnsStartAt1":true,"linesStartAt1":true,"locale":"en-us","pathFormat":"path","supportsRunInTerminalRequest":true,"supportsVariablePaging":true,"supportsVariableType":true,"sourceInitFile":false},"seq":1}
<--
Content-Length: 1245

{"body":{"exceptionBreakpointFilters":[{"default":false,"filter":"cpp_catch","label":"C++ Catch"},{"default":false,"filter":"cpp_throw","label":"C++ Throw"},{"default":false,"filter":"objc_catch","label":"Objective-C Catch"},{"default":false,"filter":"objc_throw","label":"Objective-C Throw"},{"default":false,"filter":"swift_catch","label":"Swift Catch"},{"default":false,"filter":"swift_throw","label":"Swift Throw"}],"supportTerminateDebuggee":true,"supportsCompletionsRequest":false,"supportsConditionalBreakpoints":true,"supportsConfigurationDoneRequest":true,"supportsDelayedStackTraceLoading":true,"supportsEvaluateForHovers":true,"supportsExceptionInfoRequest":true,"supportsExceptionOptions":true,"supportsFunctionBreakpoints":true,"supportsGotoTargetsRequest":false,"supportsHitConditionalBreakpoints":true,"supportsLoadedSourcesRequest":false,"supportsLogPoints":true,"supportsModulesRequest":true,"supportsProgressReporting":true,"supportsRestartFrame":false,"supportsRestartRequest":true,"supportsRunInTerminalRequest":true,"supportsSetVariable":true,"supportsStepBack":false,"supportsStepInTargetsRequest":false,"supportsValueFormattingOptions":true},"command":"initialize","request_seq":1,"seq":0,"success":true,"type":"response"}
-->
Content-Length: 702

{"command":"launch","type":"request","arguments":{"program":"/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.test_basic_functionality/a.out","disableASLR":true,"initCommands":["settings clear -all","settings set symbols.enable-external-lookup false","settings set target.inherit-tcc true","settings set target.detach-on-error false","settings set target.auto-apply-fixits false","settings set plugin.process.gdb-remote.packet-timeout 60","settings set symbols.clang-modules-cache-path \"/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/module-cache-lldb/lldb-api\"","settings set use-color false"],"runInTerminal":true},"seq":2}
<--
Content-Length: 582

{"body":{"category":"console","output":"Running initCommands:\n(lldb) settings clear -all\n(lldb) settings set symbols.enable-external-lookup false\n(lldb) settings set target.inherit-tcc true\n(lldb) settings set target.detach-on-error false\n(lldb) settings set target.auto-apply-fixits false\n(lldb) settings set plugin.process.gdb-remote.packet-timeout 60\n(lldb) settings set symbols.clang-modules-cache-path \"/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/module-cache-lldb/lldb-api\"\n(lldb) settings set use-color false\n"},"event":"output","seq":0,"type":"event"}
<--
Content-Length: 408

{"arguments":{"args":["/home/tcwg-buildbot/debug/build/bin/lldb-vscode","--comm-file","/tmp/lldb-vscode-run-in-terminal-comm-efd476","--debugger-pid","3396853","--launch-target","/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.test_basic_functionality/a.out"],"env":{},"kind":"integrated"},"command":"runInTerminal","seq":1,"type":"request"}
-->
Content-Length: 95

{"type":"response","seq":-1,"request_seq":1,"success":true,"command":"runInTerminal","body":{}}
<--
Content-Length: 195

{"command":"launch","message":"Failed to attach to the target process. Timed out trying to get messages from the runInTerminal launcher","request_seq":2,"seq":0,"success":false,"type":"response"}
<--
Content-Length: 46

{"event":"initialized","seq":0,"type":"event"}

========= END =========
FAIL: LLDB (/home/tcwg-buildbot/debug/build/bin/clang-arm) :: test_basic_functionality (TestVSCode_restart_runInTerminal.TestVSCode_restart_runInTerminal)
Executing tearDown hook:         def cleanup():
            if disconnectAutomatically:
                self.vscode.request_disconnect(terminateDebuggee=True)
            self.vscode.terminate()


CLEANUP ERROR: LLDB (/home/tcwg-buildbot/debug/build/bin/clang-arm) :: test_basic_functionality (TestVSCode_restart_runInTerminal.TestVSCode_restart_runInTerminal)
Traceback (most recent call last):
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/third_party/Python/module/unittest2/unittest2/case.py", line 381, in run
    self.tearDown()
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/lldbtest.py", line 1964, in tearDown
    Base.tearDown(self)
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/lldbtest.py", line 1013, in tearDown
    hook()  # try the plain call and hope it works
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py", line 297, in cleanup
    self.vscode.request_disconnect(terminateDebuggee=True)
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/vscode.py", line 615, in request_disconnect
    return self.send_recv(command_dict)
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/vscode.py", line 315, in send_recv
    self.send_packet(command)
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/vscode.py", line 271, in send_packet
    self.send.flush()
BrokenPipeError: [Errno 32] Broken pipe

Restore dir to: /home/tcwg-buildbot/debug/llvm-project
======================================================================
FAIL: test_basic_functionality (TestVSCode_restart_runInTerminal.TestVSCode_restart_runInTerminal)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/test/API/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.py", line 38, in test_basic_functionality
    self.build_and_launch(program, runInTerminal=True)
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py", line 352, in build_and_launch
    return self.launch(program, args, cwd, env, stopOnEntry, disableASLR,
  File "/home/tcwg-buildbot/debug/llvm-project/lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py", line 332, in launch
    self.assertTrue(response['success'],
AssertionError: False is not True : launch failed (Failed to attach to the target process. Timed out trying to get messages from the runInTerminal launcher)

[slackito]

@tedwoodward messaged me earlier today about tests hanging in what looks like the same way. He pointed me towards this piece of code in vscode.py (part of the lldb-vscode test harness), that I believe is buggy:

    if not expectFailure:
        # Wait for a 'process' and 'initialized' event in any order
        self.wait_for_event(filter=['process', 'initialized'])
        self.wait_for_event(filter=['process', 'initialized'])
    return response

If the test is expecting a launch failure, it won't wait for these events. However, in the case of an unexpected launch failure, it will hang while waiting for these events.

I think we should skip these wait_for_event calls in the case of launch failure, expected or not:

    if response['success']:
        # Wait for a 'process' and 'initialized' event in any order
        self.wait_for_event(filter=['process', 'initialized'])
        self.wait_for_event(filter=['process', 'initialized'])
    return response

then the launch method in vscode_testcase.py will take care of failing the test if the launch failed and expectedFailure was not True. I'll prepare a patch.

[slackito]

Sent https://reviews.llvm.org/D150470 for review.

[luporl]

FWIW, this is the launch error on ARM:

(lldb) r
Process 4052207 launched: '/home/tcwg-buildbot/debug/build/lldb-test-build.noindex/tools/lldb-vscode/restart/TestVSCode_restart_runInTerminal.test_basic_functionality/a.out' (arm)
Process 4052207 stopped
* thread #1, name = 'a.out', stop reason = signal SIGILL: illegal opcode
    frame #0: 0xf7fc0bfa ld-linux-armhf.so.3`_dl_close(_map=0xf7fef984) at dl-close.c:815:7

(lldb) x/i $pc
->  0xf7fc0bfa: 0xe184e99c   unknown     .long  0xe184e99c                ; unknown opcode
(lldb) disas -b -s $pc-6 -c 5
ld-linux-armhf.so.3`_dl_close:
    0xf7fc0bf4 <+84>:  0x4630447b   .long  0x4630447b                ; unknown opcode
    0xf7fc0bf8 <+88>:  0xe99cf7ff   ldmib  r12, {r0, r1, r2, r3, r4, r5, r6, r7, r8, r9, r10, r12, sp, lr, pc}
    0xf7fc0bfc <+92>:  0x0002e184   andeq  lr, r2, r4, lsl #3
    0xf7fc0c00 <+96>:  0x0002e4aa   andeq  lr, r2, r10, lsr #9
    0xf7fc0c04 <+100>: 0x0002e164   andeq  lr, r2, r4, ror #2
(lldb) disas -b -s $pc-6 -c 5 -A thumbv7
ld-linux-armhf.so.3`_dl_close:
    0xf7fc0bf4 <+84>: 0x447b       add    r3, pc
    0xf7fc0bf6 <+86>: 0x4630       mov    r0, r6
    0xf7fc0bf8 <+88>: 0xf7ffe99c   blx    0xf7fbff34                ; symbol stub for: __tls_get_addr + 8
    0xf7fc0bfc <+92>: 0xe184       b      0xf7fc0f08                ; _dl_map_object_deps + 372 at dl-deps.c:226:40
    0xf7fc0bfe <+94>: 0x0002       movs   r2, r0

The buildbot is actually a container running an armhf userspace on an AArch64 host.
It looks similar to #39634.

Running the a.out binary directly or with gdb works fine.

[luporl]

The time out issue was fixed by https://reviews.llvm.org/D150470.