xref: /aosp_15_r20/external/cronet/base/metrics/statistics_recorder_starvation_unittest.cc (revision 6777b5387eb2ff775bb5750e3f5d96f37fb7352b)
1 // Copyright 2023 The Chromium Authors
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #include "base/metrics/statistics_recorder.h"
6 
7 #include <atomic>
8 
9 #include "base/containers/span.h"
10 #include "base/logging.h"
11 #include "base/metrics/histogram_functions.h"
12 #include "base/metrics/persistent_histogram_allocator.h"
13 #include "base/strings/strcat.h"
14 #include "base/strings/string_number_conversions.h"
15 #include "base/strings/string_util.h"
16 #include "base/threading/platform_thread.h"
17 #include "base/threading/simple_thread.h"
18 #include "base/time/time.h"
19 #include "build/build_config.h"
20 #include "testing/gtest/include/gtest/gtest.h"
21 
22 namespace base {
23 
24 namespace {
25 
26 constexpr TimeDelta kTestRunningTime = Seconds(5);
27 constexpr char kHistogramNamePrefix[] = "SRStarvationTest.";
28 
29 class BaseThread : public SimpleThread {
30  public:
BaseThread(const std::string & thread_name)31   explicit BaseThread(const std::string& thread_name)
32       : SimpleThread(thread_name, Options()), thread_name_(thread_name) {}
33 
34   BaseThread(const BaseThread&) = delete;
35   BaseThread& operator=(const BaseThread&) = delete;
36 
37   ~BaseThread() override = default;
38 
thread_name()39   const std::string& thread_name() { return thread_name_; }
SetStartTime()40   void SetStartTime() { start_time_ = Time::Now(); }
ShouldStop()41   bool ShouldStop() { return stop_.load(std::memory_order_relaxed); }
Stop()42   void Stop() {
43     stop_.store(true, std::memory_order_relaxed);
44     end_time_ = Time::Now();
45   }
IncrementIterCount()46   void IncrementIterCount() { ++iter_count_; }
iter_count()47   size_t iter_count() { return iter_count_; }
running_time()48   TimeDelta running_time() { return end_time_ - start_time_; }
average_time_per_iter()49   TimeDelta average_time_per_iter() { return running_time() / iter_count_; }
50 
51  private:
52   std::string thread_name_;
53   std::atomic<bool> stop_ = false;
54   size_t iter_count_ = 0;
55   Time start_time_;
56   Time end_time_;
57 };
58 
59 class ReadThread : public BaseThread {
60  public:
ReadThread(size_t id)61   explicit ReadThread(size_t id)
62       : BaseThread(/*thread_name=*/StrCat({"ReadThread", NumberToString(id)})) {
63   }
64 
Run()65   void Run() override {
66     SetStartTime();
67 
68     const std::string histogram_name =
69         StrCat({kHistogramNamePrefix, "ReadThreadHistogram"});
70     while (!ShouldStop()) {
71       // Continuously emit to the same histogram. Because this histogram should
72       // already exist within the StatisticsRecorder's internal map (except the
73       // first time this is called), it should not cause any modifications to
74       // it, only a lookup. In other words, it will call
75       // StatisticsRecorder::FindHistogram().
76       UmaHistogramBoolean(histogram_name, false);
77       IncrementIterCount();
78     }
79   }
80 };
81 
82 class WriteThread : public BaseThread {
83  public:
WriteThread(size_t id)84   explicit WriteThread(size_t id)
85       : BaseThread(
86             /*thread_name=*/StrCat({"WriteThread", NumberToString(id)})) {}
87 
Run()88   void Run() override {
89     SetStartTime();
90 
91     const std::string base_name =
92         StrCat({kHistogramNamePrefix, thread_name(), ".Iteration"});
93     while (!ShouldStop()) {
94       // Continuously emit to a new histogram. Because this histogram should not
95       // exist within the StatisticsRecorder's internal map, it will cause an
96       // insertion to it every time. In other words, it will call
97       // StatisticsRecorder::RegisterOrDeleteDuplicate().
98       UmaHistogramBoolean(StrCat({base_name, NumberToString(iter_count())}),
99                           false);
100       IncrementIterCount();
101     }
102   }
103 };
104 
105 }  // namespace
106 
107 // Determines the number of reader and writer threads to run in the test.
108 struct StarvationTestParams {
109   size_t num_read_threads;
110   size_t num_write_threads;
111 };
112 
113 // Determines which threads should start running first.
114 enum class FirstThreadsToStart {
115   kReaders,
116   kWriters,
117 };
118 
119 class StatisticsRecorderStarvationTest
120     : public testing::TestWithParam<
121           std::tuple<StarvationTestParams, FirstThreadsToStart>> {
122  public:
123   StatisticsRecorderStarvationTest() = default;
124 
125   StatisticsRecorderStarvationTest(const StatisticsRecorderStarvationTest&) =
126       delete;
127   StatisticsRecorderStarvationTest& operator=(
128       const StatisticsRecorderStarvationTest&) = delete;
129 
130   ~StatisticsRecorderStarvationTest() override = default;
131 
SetUp()132   void SetUp() override {
133     // Create a new StatisticsRecorder so that this test run will not affect
134     // future ones. In particular, this test relies on creating new histograms
135     // and adding them to the SR.
136     sr_ = StatisticsRecorder::CreateTemporaryForTesting();
137 
138     // Emit a bunch of histograms, which will add them to the SR's internal
139     // histogram map. This is so that lookups and insertions (FindHistogram()
140     // and RegisterOrDeleteDuplicate()) during the test don't complete (pretty
141     // much) instantly.
142     for (size_t i = 0; i < 10000; ++i) {
143       UmaHistogramBoolean(
144           StrCat({kHistogramNamePrefix, "Dummy", NumberToString(i)}), false);
145     }
146   }
147 
TearDown()148   void TearDown() override {
149     // Clean up histograms that were allocated during this test. Note that the
150     // histogram objects are deleted after releasing the temporary `sr_`.
151     // Otherwise, for a brief moment, the temporary `sr_` would be holding
152     // dangling pointers.
153     auto histograms = sr_->GetHistograms();
154     sr_.reset();
155     for (auto* histogram : histograms) {
156       if (StartsWith(histogram->histogram_name(), kHistogramNamePrefix)) {
157         delete histogram;
158       }
159     }
160   }
161 
162   // Starts reader and writer threads.
StartThreads()163   void StartThreads() {
164     for (size_t i = 0; i < num_read_threads(); ++i) {
165       read_threads_.emplace_back(std::make_unique<ReadThread>(/*id=*/i));
166     }
167     for (size_t i = 0; i < num_write_threads(); ++i) {
168       write_threads_.emplace_back(std::make_unique<WriteThread>(/*id=*/i));
169     }
170 
171     // Depending on the value of GetFirstThreadsToStart(), either start the
172     // readers or the writers first. Because some implementations will give
173     // priority to whatever managed to get the lock first, do this to have
174     // coverage.
175     span<std::unique_ptr<BaseThread>> start_first_threads;
176     span<std::unique_ptr<BaseThread>> start_second_threads;
177     switch (GetFirstThreadsToStart()) {
178       case FirstThreadsToStart::kReaders:
179         start_first_threads = read_threads_;
180         start_second_threads = write_threads_;
181         break;
182       case FirstThreadsToStart::kWriters:
183         start_first_threads = write_threads_;
184         start_second_threads = read_threads_;
185         break;
186     }
187     for (auto& thread : start_first_threads) {
188       thread->Start();
189     }
190     PlatformThread::Sleep(Milliseconds(100));
191     for (auto& thread : start_second_threads) {
192       thread->Start();
193     }
194   }
195 
196   // Stops reader and writer threads.
StopThreads()197   void StopThreads() {
198     for (auto* thread : GetAllThreads()) {
199       thread->Stop();
200       thread->Join();
201     }
202   }
203 
GetAllThreads()204   std::vector<BaseThread*> GetAllThreads() {
205     std::vector<BaseThread*> threads;
206     threads.reserve(num_read_threads() + num_write_threads());
207     for (auto& read_thread : read_threads_) {
208       threads.push_back(read_thread.get());
209     }
210     for (auto& write_thread : write_threads_) {
211       threads.push_back(write_thread.get());
212     }
213     return threads;
214   }
215 
num_read_threads()216   size_t num_read_threads() { return std::get<0>(GetParam()).num_read_threads; }
217 
num_write_threads()218   size_t num_write_threads() {
219     return std::get<0>(GetParam()).num_write_threads;
220   }
221 
GetFirstThreadsToStart()222   FirstThreadsToStart GetFirstThreadsToStart() {
223     return std::get<1>(GetParam());
224   }
225 
226  protected:
227   std::vector<std::unique_ptr<BaseThread>> read_threads_;
228   std::vector<std::unique_ptr<BaseThread>> write_threads_;
229 
230  private:
231   std::unique_ptr<StatisticsRecorder> sr_;
232 };
233 
234 // Verifies that there are no starvation issues when emitting histograms (since
235 // it may be done from any thread). In particular, emitting a histogram requires
236 // a lock to look up (and sometimes write to) an internal map in the
237 // StatisticsRecorder. When switching to a Read/Write lock (see crbug/1123627),
238 // we encountered such a starvation issue, where a thread trying to write to the
239 // internal map was starved out for 10+ seconds by readers on iOS.
240 // TODO(crbug.com/1516818): StatisticsRecorderNoStarvation continuously emits a
241 // new histogram which can cause the app memory footprint to grow unbounded and
242 // watchdog kill the unit test on iOS devices.
TEST_P(StatisticsRecorderStarvationTest,StatisticsRecorderNoStarvation)243 TEST_P(StatisticsRecorderStarvationTest, StatisticsRecorderNoStarvation) {
244   // Make sure there is no GlobalHistogramAllocator so that histograms emitted
245   // during this test are all allocated on the heap, which makes it a lot easier
246   // to clean them up at the end.
247   ASSERT_FALSE(GlobalHistogramAllocator::Get());
248 
249   // Start reader and writer threads.
250   StartThreads();
251 
252   // Let the test run for |kTestRunningTime|.
253   PlatformThread::Sleep(kTestRunningTime);
254 
255   // Stop reader and writer threads. This waits for them to complete by joining
256   // the threads.
257   StopThreads();
258 
259   // Verify that on average, on each thread, performing a read or write took
260   // less than 1ms. There is no meaning to 50ms -- this is just to ensure that
261   // there is no egregious starvation effect (for example, we've seen crash
262   // reports where readers were starving out writers for >10 seconds). Note that
263   // the average time it took to perform one iteration is:
264   // average_time_per_iteration = running_time / iteration_count.
265   static constexpr TimeDelta kStarvationThreshold = Milliseconds(50);
266   std::vector<BaseThread*> threads = GetAllThreads();
267   for (auto* thread : threads) {
268     EXPECT_LT(thread->average_time_per_iter(), kStarvationThreshold);
269   }
270 
271   // Print some useful information that could come in handy if this test fails
272   // (or for diagnostic purposes).
273   LOG(INFO) << "Params: num_read_threads=" << num_read_threads()
274             << ", num_write_threads=" << num_write_threads()
275             << ", FirstThreadsToStart="
276             << static_cast<int>(GetFirstThreadsToStart());
277   for (auto* thread : threads) {
278     LOG(INFO) << thread->thread_name() << " iter_count=" << thread->iter_count()
279               << ", running_time=" << thread->running_time()
280               << ", average_time_per_iter=" << thread->average_time_per_iter();
281   }
282 }
283 
284 INSTANTIATE_TEST_SUITE_P(
285     All,
286     StatisticsRecorderStarvationTest,
287     testing::Combine(
288         testing::Values(StarvationTestParams{.num_read_threads = 10,
289                                              .num_write_threads = 1},
290                         StarvationTestParams{.num_read_threads = 1,
291                                              .num_write_threads = 10},
292                         StarvationTestParams{.num_read_threads = 1,
293                                              .num_write_threads = 1},
294                         StarvationTestParams{.num_read_threads = 5,
295                                              .num_write_threads = 5}),
296         testing::Values(FirstThreadsToStart::kReaders,
297                         FirstThreadsToStart::kWriters)));
298 
299 }  // namespace base
300