[lldb] [test] Improve stability of llgs vCont-threads tests

[mgorny]

Summary

Perform a major refactoring of vCont-threads tests in order to attempt
to improve their stability and performance.

Split test_vCont_run_subset_of_threads() into smaller test cases,
and split the whole suite into two files: one for signal-related tests,
the running-subset-of tests.

Eliminate output_match checks entirely, as they are fragile to
fragmentation of output. Instead, for the initial thread list capture
raise an explicit SIGSTOP from inside the test program, and for
the remaining output let the test program run until exit, and check all
the captured output afterwards.

For resume tests, capture the LLDB's thread view before and after
starting new threads in order to determine the IDs corresponding
to subthreads rather than relying on program output for that.

Add a mutex for output to guarantee serialization. A barrier is used
to guarantee that all threads start before SIGSTOP, and an atomic bool
is used to delay prints from happening until after SIGSTOP.

Call std::this_thread::yield() to reduce the risk of one of the threads
not being run.

This fixes the test hangs on FreeBSD. Hopefully, it will also fix all
the flakiness on buildbots.

Sponsored by: The FreeBSD Foundation

[mgorny]

Remove obsolete <string> include.

[mgorny]

Ok, unsurprisingly it turned out that using exit() when the main thread was potentially suspended was a bad idea (at least it was still fairly unstable on FreeBSD). I've managed to get around that by using _exit() but if you think just raise(SIGSTOP) would be preferred, I can change the tests to use that.

[labath]

Seems like an improvement. I'd like to hear what you make of the inline comment though.

I can also imagine a setup where most of the verification happens inside the inferior. Like, each time a thread gets to run it increments a variable specific to that thread. Once that number crosses some threshold, it check the variables of the other threads, and verifies that one of them has the number zero, and the number of the other thread is reasonably high (> 10% of the threshold or something).

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

45

I am not sure if write is an (atomic) system call on windows. Maybe just put a mutex around the printf call? In this setup, I think it would be sufficient to write this once, and then spend the rest of the time making sure the other suspended thread gets a chance to run (if it is not suspended for whatever reason).

[mgorny]

In D129012#3631985, @labath wrote:

I can also imagine a setup where most of the verification happens inside the inferior. Like, each time a thread gets to run it increments a variable specific to that thread. Once that number crosses some threshold, it check the variables of the other threads, and verifies that one of them has the number zero, and the number of the other thread is reasonably high (> 10% of the threshold or something).

I suppose this would be possible but tbh I think it'd be more complex than the current solution.

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

45

For some reason, I've assumed we're avoiding mutexes. However, this certainly makes sense, as well as removing duplicate writes. I've also noticed we had a race condition between starting prints and SIGSTOP, so I've fixed that too. Now the main thread is always resumed.

[mgorny]

Implement the discussed changes.

[labath]

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

45

We have tests like that, but I think they're all related to the situations where we want to ensure some things happen as concurrently as possible. This is not one of those cases, and I don't see any problem with using mutexes here (and it definitely won't be the first such test).

[mgorny]

Ok, so the previous version was fundamentally botched wrt synchronization.

Here's a new that:

1. Uses a barrier to ensure that all threads actually start before we SIGSTOP. Otherwise, the debugger would sometimes not get all threads on FreeBSD.
2. Uses a std::atomic<bool> to ensure that threads don't start printing until we're past SIGSTOP. Originally, I wanted to abuse print_mutex for that but this caused deadlocks on FreeBSD (I guess a suspended thread got in line for the mutex and blocked others from getting it).
3. Marks can_exit_now as a thread_local variable.

[labath]

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

18

I guess this should technically be a volatile sig_atomic_t

[mgorny]

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

18

But with thread_local, correct?

[labath]

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

18

Yes. If that's not enough qualifiers, you can even throw in static, for good measure. :)

[mgorny]

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

18

Better overqualified than underqualified!

[mgorny]

@labath, any clue why it'd be broken on Debian?

https://lab.llvm.org/buildbot/#/builders/68/builds/35396

AssertionError: '$T0athread:1ddf55;name:a.out;00:0000000000000000;01:0000000000000000;02:e1bf0b8 [truncated]... != '$W00'
- $T0athread:1ddf55;name:a.out;00:0000000000000000;01:0000000000000000;02:e1bf0b8d067f0000;03:0000000000000000;04:0200000000000000;05:e0272245fc7f0000;06:90292245fc7f0000;07:e0272245fc7f0000;08:0000000000000000;09:e0272245fc7f0000;0a:0800000000000000;0b:4602000000000000;0c:c091997f07560000;0d:0000000000000000;0e:0000000000000000;0f:0000000000000000;10:e1bf0b8d067f0000;11:4602000000000000;12:3300000000000000;13:0000000000000000;14:0000000000000000;15:2b00000000000000;16:0000000000000000;17:0000000000000000;reason:signal;+ $W00

I mean, this makes no sense to me. Why is it stopping due to a signal LLDB was supposed to send to it? And why can't I reproduce it on Gentoo or FreeBSD?

[labath]

Well... I'm as puzzled as you are. Whatever the problem is, it seems to be limited to debian (kernel). I've filed a bug about that: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1014754.

One good thing I learned is that this problem seems to be limited to SIGSTOPs, so it should be possible to work around it by using some other signal. That's probably a good idea anyway, since SIGSTOP has the unpleasant property of leaving around a stopped zombie if something goes wrong (that's what killed the bot over the weekend).

[mgorny]

Heh, and I actually thought using SIGSTOP was a good idea because it's unlikely to have any unexpected side effects ;-).

[mgorny]

Also, big, big thanks for helping out with this!

lldb/test/API/tools/lldb-server/vCont-threads/TestPartialResume.py

+import re
+
+import gdbremote_testcase
+from lldbsuite.test.decorators import *
+from lldbsuite.test.lldbtest import *
+
+
+class TestPartialResume(gdbremote_testcase.GdbRemoteTestCaseBase):
+    THREAD_MATCH_RE = re.compile(r"thread ([0-9a-f]+) running")
+
+    def start_vCont_run_subset_of_threads_test(self):
+        self.build()
+        self.set_inferior_startup_launch()
+
+        procs = self.prep_debug_monitor_and_inferior(inferior_args=["3"])
+        # grab the main thread id
+        self.add_threadinfo_collection_packets()
+        main_thread = self.parse_threadinfo_packets(
+            self.expect_gdbremote_sequence())
+        self.assertEqual(len(main_thread), 1)
+        self.reset_test_sequence()
+
+        # run until threads start, then grab full thread list
+        self.test_sequence.add_log_lines([
+            "read packet: $c#63",
+            {"direction": "send", "regex": "[$]T.*;reason:signal.*"},
+        ], True)
+        self.add_threadinfo_collection_packets()
+
+        all_threads = self.parse_threadinfo_packets(
+            self.expect_gdbremote_sequence())
+        self.assertEqual(len(all_threads), 4)
+        self.assertIn(main_thread[0], all_threads)
+        self.reset_test_sequence()
+
+        all_subthreads = set(all_threads) - set(main_thread)
+        self.assertEqual(len(all_subthreads), 3)
+
+        return (main_thread[0], list(all_subthreads))
+
+    def continue_and_get_threads_running(self, main_thread, vCont_req):
+        self.test_sequence.add_log_lines(
+            ["read packet: $vCont;c:{:x};{}#00".format(main_thread, vCont_req),
+             "send packet: $W00#00",
+             ], True)
+        exp = self.expect_gdbremote_sequence()
+        self.reset_test_sequence()
+        found = set()
+        for line in exp["O_content"].decode().splitlines():
+            m = self.THREAD_MATCH_RE.match(line)
+            if m is not None:
+                found.add(int(m.group(1), 16))
+        return found
+
+    @skipIfWindows
+    @add_test_categories(["llgs"])
+    def test_vCont_cxcx(self):
+        main_thread, all_subthreads_list = (
+            self.start_vCont_run_subset_of_threads_test())
+        # resume two threads explicitly, stop the third one implicitly
+        self.assertEqual(
+            self.continue_and_get_threads_running(
+                main_thread,
+                "c:{:x};c:{:x}".format(*all_subthreads_list[:2])),
+            set(all_subthreads_list[:2]))
+
+    @skipIfWindows
+    @add_test_categories(["llgs"])
+    def test_vCont_cxcxt(self):
+        main_thread, all_subthreads_list = (
+            self.start_vCont_run_subset_of_threads_test())
+        # resume two threads explicitly, stop others explicitly
+        self.assertEqual(
+            self.continue_and_get_threads_running(
+                main_thread,
+                "c:{:x};c:{:x};t".format(*all_subthreads_list[:2])),
+            set(all_subthreads_list[:2]))
+
+    @skipIfWindows
+    @add_test_categories(["llgs"])
+    def test_vCont_txc(self):
+        main_thread, all_subthreads_list = (
+            self.start_vCont_run_subset_of_threads_test())
+        # stop one thread explicitly, resume others
+        self.assertEqual(
+            self.continue_and_get_threads_running(
+                main_thread,
+                "t:{:x};c".format(all_subthreads_list[-1])),
+            set(all_subthreads_list[:2]))
+
+    @skipIfWindows
+    @add_test_categories(["llgs"])
+    def test_vCont_cxtxc(self):
+        main_thread, all_subthreads_list = (
+            self.start_vCont_run_subset_of_threads_test())
+        # resume one thread explicitly, stop one explicitly,
+        # resume others
+        self.assertEqual(
+            self.continue_and_get_threads_running(
+                main_thread,
+                "c:{:x};t:{:x};c".format(*all_subthreads_list[-2:])),
+            set(all_subthreads_list[:2]))
+
+    @skipIfWindows
+    @add_test_categories(["llgs"])
+    def test_vCont_txcx(self):
+        main_thread, all_subthreads_list = (
+            self.start_vCont_run_subset_of_threads_test())
+        # resume one thread explicitly, stop one explicitly,
+        # stop others implicitly
+        self.assertEqual(
+            self.continue_and_get_threads_running(
+                main_thread,
+                "t:{:x};c:{:x}".format(*all_subthreads_list[:2])),
+            set(all_subthreads_list[1:2]))
+
+    @skipIfWindows
+    @add_test_categories(["llgs"])
+    def test_vCont_txcxt(self):
+        main_thread, all_subthreads_list = (
+            self.start_vCont_run_subset_of_threads_test())
+        # resume one thread explicitly, stop one explicitly,
+        # stop others explicitly
+        self.assertEqual(
+            self.continue_and_get_threads_running(
+                main_thread,
+                "t:{:x};c:{:x};t".format(*all_subthreads_list[:2])),
+            set(all_subthreads_list[1:2]))

lldb/test/API/tools/lldb-server/vCont-threads/TestSignal.py

-import json
 import re
-import time
 
 import gdbremote_testcase
 from lldbsuite.test.decorators import *
 from lldbsuite.test.lldbtest import *
 from lldbsuite.test import lldbutil
 
-class TestGdbRemote_vContThreads(gdbremote_testcase.GdbRemoteTestCaseBase):
 
+class TestSignal(gdbremote_testcase.GdbRemoteTestCaseBase):
     def start_threads(self, num):
         procs = self.prep_debug_monitor_and_inferior(inferior_args=[str(num)])
-        # start the process and wait for output
         self.test_sequence.add_log_lines([
             "read packet: $c#63",
-            {"type": "output_match", "regex": r".*@started\r\n.*"},
+            {"direction": "send", "regex": "[$]T.*;reason:signal.*"},
         ], True)
-        # then interrupt it
-        self.add_interrupt_packets()
         self.add_threadinfo_collection_packets()
 
         context = self.expect_gdbremote_sequence()
         self.assertIsNotNone(context)
         threads = self.parse_threadinfo_packets(context)
         self.assertIsNotNone(threads)
         self.assertEqual(len(threads), num + 1)
 
         self.reset_test_sequence()
         return threads
 
+    SIGNAL_MATCH_RE = re.compile(r"received SIGUSR1 on thread id: ([0-9a-f]+)")
+
     def send_and_check_signal(self, vCont_data, threads):
         self.test_sequence.add_log_lines([
             "read packet: $vCont;{0}#00".format(vCont_data),
-            {"type": "output_match",
-             "regex": len(threads) *
-                      r".*received SIGUSR1 on thread id: ([0-9a-f]+)\r\n.*",
-             "capture": dict((i, "tid{0}".format(i)) for i
-                             in range(1, len(threads)+1)),
-             },
+            "send packet: $W00#00",
         ], True)
-
-        context = self.expect_gdbremote_sequence()
-        self.assertIsNotNone(context)
-        tids = sorted(int(context["tid{0}".format(x)], 16)
-                      for x in range(1, len(threads)+1))
-        self.assertEqual(tids, sorted(threads))
+        exp = self.expect_gdbremote_sequence()
+        self.reset_test_sequence()
+        tids = []
+        for line in exp["O_content"].decode().splitlines():
+            m = self.SIGNAL_MATCH_RE.match(line)
+            if m is not None:
+                tids.append(int(m.group(1), 16))
+        self.assertEqual(sorted(tids), sorted(threads))
 
     def get_pid(self):
         self.add_process_info_collection_packets()
         context = self.expect_gdbremote_sequence()
         self.assertIsNotNone(context)
         procinfo = self.parse_process_info_response(context)
         return int(procinfo['pid'], 16)
 
def test_signal_two_signals(self):
             "read packet: $vCont;C{0:x}:{1:x};C{2:x}:{3:x}#00".format(
                 lldbutil.get_signal_number('SIGUSR1'), threads[0],
                 lldbutil.get_signal_number('SIGUSR2'), threads[1]),
             {"direction": "send", "regex": r"^\$E1e#db$"},
         ], True)
 
         context = self.expect_gdbremote_sequence()
         self.assertIsNotNone(context)
-
-    THREAD_MATCH_RE = re.compile(r"thread ([0-9a-f]+) running")
-
-    def continue_and_get_threads_running(self, continue_packet):
-        self.test_sequence.add_log_lines(
-            ["read packet: ${}#00".format(continue_packet),
-             ], True)
-        self.expect_gdbremote_sequence()
-        self.reset_test_sequence()
-        time.sleep(1)
-        self.add_interrupt_packets()
-        exp = self.expect_gdbremote_sequence()
-        found = set()
-        for line in exp["O_content"].decode().splitlines():
-            m = self.THREAD_MATCH_RE.match(line)
-            if m is not None:
-                found.add(int(m.group(1), 16))
-        return found
-
-    @skipIfWindows
-    @add_test_categories(["llgs"])
-    def test_vCont_run_subset_of_threads(self):
-        self.build()
-        self.set_inferior_startup_launch()
-
-        threads = set(self.start_threads(3))
-        all_subthreads = self.continue_and_get_threads_running("c")
-        all_subthreads_list = list(all_subthreads)
-        self.assertEqual(len(all_subthreads), 3)
-        self.assertEqual(threads & all_subthreads, all_subthreads)
-
-        # resume two threads explicitly, stop the third one implicitly
-        self.assertEqual(
-            self.continue_and_get_threads_running(
-                "vCont;c:{:x};c:{:x}".format(*all_subthreads_list[:2])),
-            set(all_subthreads_list[:2]))
-
-        # resume two threads explicitly, stop others explicitly
-        self.assertEqual(
-            self.continue_and_get_threads_running(
-                "vCont;c:{:x};c:{:x};t".format(*all_subthreads_list[:2])),
-            set(all_subthreads_list[:2]))
-
-        # stop one thread explicitly, resume others
-        self.assertEqual(
-            self.continue_and_get_threads_running(
-                "vCont;t:{:x};c".format(all_subthreads_list[-1])),
-            set(all_subthreads_list[:2]))
-
-        # resume one thread explicitly, stop one explicitly,
-        # resume others
-        self.assertEqual(
-            self.continue_and_get_threads_running(
-                "vCont;c:{:x};t:{:x};c".format(*all_subthreads_list[-2:])),
-            set(all_subthreads_list[:2]))
-
-        # resume one thread explicitly, stop one explicitly,
-        # stop others implicitly
-        self.assertEqual(
-            self.continue_and_get_threads_running(
-                "vCont;t:{:x};c:{:x}".format(*all_subthreads_list[:2])),
-            set(all_subthreads_list[1:2]))
-
-        # resume one thread explicitly, stop one explicitly,
-        # stop others explicitly
-        self.assertEqual(
-            self.continue_and_get_threads_running(
-                "vCont;t:{:x};c:{:x};t".format(*all_subthreads_list[:2])),
-            set(all_subthreads_list[1:2]))

lldb/test/API/tools/lldb-server/vCont-threads/main.cpp

 #include "pseudo_barrier.h"
 #include "thread.h"
+#include <atomic>
 #include <chrono>
 #include <cinttypes>
 #include <csignal>
 #include <cstdio>
 #include <cstdlib>
 #include <cstring>
+#include <mutex>
 #include <thread>
 #include <unistd.h>
 #include <vector>
 
 pseudo_barrier_t barrier;
+std::mutex print_mutex;
+std::atomic<bool> can_work = ATOMIC_VAR_INIT(false);
+thread_local volatile sig_atomic_t can_exit_now = false;
+
+static void sigint_handler(int signo) {}
 
 static void sigusr1_handler(int signo) {
-  char buf[100];
-  std::snprintf(buf, sizeof(buf),
-                "received SIGUSR1 on thread id: %" PRIx64 "\n",
-                get_thread_id());
-  write(STDOUT_FILENO, buf, strlen(buf));
+  std::lock_guard<std::mutex> lock{print_mutex};
+  std::printf("received SIGUSR1 on thread id: %" PRIx64 "\n", get_thread_id());
+  can_exit_now = true;
 }
 
 static void thread_func() {
+  // this ensures that all threads start before we stop
   pseudo_barrier_wait(barrier);
-  for (int i = 0; i < 300; ++i) {
+
+  // wait till the main thread indicates that we can go
+  // (note: using a mutex here causes hang on FreeBSD when another thread
+  // is suspended)
+  while (!can_work.load())
+    std::this_thread::sleep_for(std::chrono::milliseconds(50));
+
+  // the mutex guarantees that two writes don't get interspersed
+  {
+    std::lock_guard<std::mutex> lock{print_mutex};
     std::printf("thread %" PRIx64 " running\n", get_thread_id());
+  }
+
+  // give other threads a fair chance to run
+  for (int i = 0; i < 5; ++i) {
+    std::this_thread::yield();
     std::this_thread::sleep_for(std::chrono::milliseconds(200));
+    if (can_exit_now)
+      return;
   }
+
+  // if we didn't get signaled, terminate the program explicitly.
+  _exit(0);
 }
 
 int main(int argc, char **argv) {
   int num = atoi(argv[1]);
 
   pseudo_barrier_init(barrier, num + 1);
 
+  signal(SIGINT, sigint_handler);
   signal(SIGUSR1, sigusr1_handler);
 
   std::vector<std::thread> threads;
-  for(int i = 0; i < num; ++i)
+  for (int i = 0; i < num; ++i)
     threads.emplace_back(thread_func);
 
+  // use the barrier to make sure all threads start before we stop
   pseudo_barrier_wait(barrier);
+  std::raise(SIGINT);
 
-  std::puts("@started");
+  // allow the threads to work
+  can_work.store(true);
 
   for (std::thread &thread : threads)
     thread.join();
   return 0;
 }