Skip to content

Commit fb4cc71

Browse files
koct9ikoct9i
committed
Verify results in internal_threading_test
Run 10 iterations of 50ms busyloop (by thread CPU time) and check resulting times with absolute and relative accuracy ±10%. If system has not enough cpus (1 for each thread + 1 for infrastructure) then check only that measured real time not less than expect. Signed-off-by: Konstantin Khlebnikov <[email protected]>
1 parent c5902a2 commit fb4cc71

File tree

3 files changed

+173
-40
lines changed

3 files changed

+173
-40
lines changed

‎AUTHORS

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,7 @@ Sayan Bhattacharjee <[email protected]>
5151
Shuo Chen <[email protected]>
5252
Steinar H. Gunderson <[email protected]>
5353
Stripe, Inc.
54+
Yandex LLC
5455
Yixuan Qiu <[email protected]>
5556
Yusuke Suzuki <[email protected]>
5657
Zbigniew Skowron <[email protected]>

‎CONTRIBUTORS

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -55,6 +55,7 @@ Jussi Knuuttila <[email protected]>
5555
Kai Wolf <[email protected]>
5656
Kaito Udagawa <[email protected]>
5757
Kishan Kumar <[email protected]>
58+
Konstantin Khlebnikov <[email protected]>
5859
Lei Xu <[email protected]>
5960
Matt Clarkson <[email protected]>
6061
Maxim Vafin <[email protected]>

‎test/internal_threading_test.cc

Lines changed: 171 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -4,20 +4,27 @@
44
#include <chrono>
55
#include <thread>
66
#include "../src/timers.h"
7+
#include "../src/check.h"
78
#include "benchmark/benchmark.h"
8-
#include "output_test.h"
99

1010
static const std::chrono::duration<double, std::milli> time_frame(50);
11+
static const double time_frame_in_ns(
12+
std::chrono::duration_cast<std::chrono::duration<double, std::nano>>(
13+
time_frame)
14+
.count());
1115
static const double time_frame_in_sec(
1216
std::chrono::duration_cast<std::chrono::duration<double, std::ratio<1, 1>>>(
1317
time_frame)
1418
.count());
1519

20+
static const int nr_iterations = 10;
21+
22+
// Waste exact amount of CPU time in busy-loop
1623
void MyBusySpinwait() {
17-
const auto start = benchmark::ChronoClockNow();
24+
const auto start = benchmark::ThreadCPUUsage();
1825

1926
while (true) {
20-
const auto now = benchmark::ChronoClockNow();
27+
const auto now = benchmark::ThreadCPUUsage();
2128
const auto elapsed = now - start;
2229

2330
if (std::chrono::duration<double, std::chrono::seconds::period>(elapsed) >=
@@ -26,6 +33,77 @@ void MyBusySpinwait() {
2633
}
2734
}
2835

36+
class TestReporter : public benchmark::ConsoleReporter {
37+
int num_cpus = 0;
38+
public:
39+
virtual bool ReportContext(const Context& context) {
40+
num_cpus = context.cpu_info.num_cpus;
41+
return ConsoleReporter::ReportContext(context);
42+
};
43+
44+
virtual void ReportRuns(const std::vector<Run>& report) {
45+
ConsoleReporter::ReportRuns(report);
46+
47+
for (auto &run: report) {
48+
double expected_cpus = 1;
49+
int64_t min_cpus = run.threads;
50+
51+
if (run.run_name.function_name == "BM_WorkerThread") {
52+
if (run.run_name.time_type == "" ||
53+
run.run_name.time_type == "real_time" ||
54+
run.run_name.time_type == "manual_time") {
55+
expected_cpus = 0;
56+
}
57+
}
58+
59+
if (run.run_name.function_name == "BM_MainThreadAndWorkerThread") {
60+
min_cpus *= 2;
61+
if (run.run_name.time_type == "process_time" ||
62+
run.run_name.time_type == "process_time/real_time" ||
63+
run.run_name.time_type == "process_time/manual_time") {
64+
expected_cpus = 2;
65+
}
66+
}
67+
68+
if (run.run_name.time_type == "manual_time" ||
69+
run.run_name.time_type == "process_time/manual_time") {
70+
min_cpus = 0;
71+
}
72+
73+
double cpus = run.GetAdjustedCPUTime() / time_frame_in_ns;
74+
double real = run.GetAdjustedRealTime() / time_frame_in_ns;
75+
76+
// Check that result >= expected (accuracy: relative=0.1, absolute=0.1)
77+
CHECK_FLOAT_GE(cpus, expected_cpus, expected_cpus * 0.1 + 0.1);
78+
CHECK_FLOAT_GE(real, 1.0, 0.2);
79+
80+
// Warn if cpu time is bigger than expected.
81+
if (cpus > expected_cpus * 1.1 + 0.1) {
82+
VLOG(0) << "CPU time bigger than expected, might be cpu overload\n";
83+
}
84+
85+
// Warn if real time is bigger than expected.
86+
if (real > 1.2) {
87+
VLOG(0) << "Real time bigger than expected, might be cpu overload\n";
88+
}
89+
90+
// Check that cpu time <= expected * 2 + 20%
91+
CHECK_FLOAT_LE(cpus, expected_cpus, expected_cpus + 0.2);
92+
93+
// For checking real time require one more CPU for infrastructure
94+
if (num_cpus < min_cpus + 1) {
95+
VLOG(0) << "Not enough cpus to get valid real time\n";
96+
} else {
97+
// Measurements in CI are noisy, check real time <= expected * 4 + 20%
98+
CHECK_FLOAT_LE(real, 4.0, 0.2);
99+
}
100+
}
101+
}
102+
103+
TestReporter() {}
104+
virtual ~TestReporter() {}
105+
};
106+
29107
// ========================================================================= //
30108
// --------------------------- TEST CASES BEGIN ---------------------------- //
31109
// ========================================================================= //
@@ -42,32 +120,54 @@ void BM_MainThread(benchmark::State& state) {
42120
benchmark::Counter{1, benchmark::Counter::kIsRate};
43121
}
44122

45-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(1);
46-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(1)->UseRealTime();
47-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(1)->UseManualTime();
48-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(1)->MeasureProcessCPUTime();
49123
BENCHMARK(BM_MainThread)
50-
->Iterations(1)
124+
->Iterations(nr_iterations)
125+
->Threads(1);
126+
BENCHMARK(BM_MainThread)
127+
->Iterations(nr_iterations)
128+
->Threads(1)
129+
->UseRealTime();
130+
BENCHMARK(BM_MainThread)
131+
->Iterations(nr_iterations)
132+
->Threads(1)
133+
->UseManualTime();
134+
BENCHMARK(BM_MainThread)
135+
->Iterations(nr_iterations)
136+
->Threads(1)
137+
->MeasureProcessCPUTime();
138+
BENCHMARK(BM_MainThread)
139+
->Iterations(nr_iterations)
51140
->Threads(1)
52141
->MeasureProcessCPUTime()
53142
->UseRealTime();
54143
BENCHMARK(BM_MainThread)
55-
->Iterations(1)
144+
->Iterations(nr_iterations)
56145
->Threads(1)
57146
->MeasureProcessCPUTime()
58147
->UseManualTime();
59148

60-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(2);
61-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(2)->UseRealTime();
62-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(2)->UseManualTime();
63-
BENCHMARK(BM_MainThread)->Iterations(1)->Threads(2)->MeasureProcessCPUTime();
64149
BENCHMARK(BM_MainThread)
65-
->Iterations(1)
150+
->Iterations(nr_iterations)
151+
->Threads(2);
152+
BENCHMARK(BM_MainThread)
153+
->Iterations(nr_iterations)
154+
->Threads(2)
155+
->UseRealTime();
156+
BENCHMARK(BM_MainThread)
157+
->Iterations(nr_iterations)
158+
->Threads(2)
159+
->UseManualTime();
160+
BENCHMARK(BM_MainThread)
161+
->Iterations(nr_iterations)
162+
->Threads(2)
163+
->MeasureProcessCPUTime();
164+
BENCHMARK(BM_MainThread)
165+
->Iterations(nr_iterations)
66166
->Threads(2)
67167
->MeasureProcessCPUTime()
68168
->UseRealTime();
69169
BENCHMARK(BM_MainThread)
70-
->Iterations(1)
170+
->Iterations(nr_iterations)
71171
->Threads(2)
72172
->MeasureProcessCPUTime()
73173
->UseManualTime();
@@ -85,32 +185,54 @@ void BM_WorkerThread(benchmark::State& state) {
85185
benchmark::Counter{1, benchmark::Counter::kIsRate};
86186
}
87187

88-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(1);
89-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(1)->UseRealTime();
90-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(1)->UseManualTime();
91-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(1)->MeasureProcessCPUTime();
92188
BENCHMARK(BM_WorkerThread)
93-
->Iterations(1)
189+
->Iterations(nr_iterations)
190+
->Threads(1);
191+
BENCHMARK(BM_WorkerThread)
192+
->Iterations(nr_iterations)
193+
->Threads(1)
194+
->UseRealTime();
195+
BENCHMARK(BM_WorkerThread)
196+
->Iterations(nr_iterations)
197+
->Threads(1)
198+
->UseManualTime();
199+
BENCHMARK(BM_WorkerThread)
200+
->Iterations(nr_iterations)
201+
->Threads(1)
202+
->MeasureProcessCPUTime();
203+
BENCHMARK(BM_WorkerThread)
204+
->Iterations(nr_iterations)
94205
->Threads(1)
95206
->MeasureProcessCPUTime()
96207
->UseRealTime();
97208
BENCHMARK(BM_WorkerThread)
98-
->Iterations(1)
209+
->Iterations(nr_iterations)
99210
->Threads(1)
100211
->MeasureProcessCPUTime()
101212
->UseManualTime();
102213

103-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(2);
104-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(2)->UseRealTime();
105-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(2)->UseManualTime();
106-
BENCHMARK(BM_WorkerThread)->Iterations(1)->Threads(2)->MeasureProcessCPUTime();
107214
BENCHMARK(BM_WorkerThread)
108-
->Iterations(1)
215+
->Iterations(nr_iterations)
216+
->Threads(2);
217+
BENCHMARK(BM_WorkerThread)
218+
->Iterations(nr_iterations)
219+
->Threads(2)
220+
->UseRealTime();
221+
BENCHMARK(BM_WorkerThread)
222+
->Iterations(nr_iterations)
223+
->Threads(2)
224+
->UseManualTime();
225+
BENCHMARK(BM_WorkerThread)
226+
->Iterations(nr_iterations)
227+
->Threads(2)
228+
->MeasureProcessCPUTime();
229+
BENCHMARK(BM_WorkerThread)
230+
->Iterations(nr_iterations)
109231
->Threads(2)
110232
->MeasureProcessCPUTime()
111233
->UseRealTime();
112234
BENCHMARK(BM_WorkerThread)
113-
->Iterations(1)
235+
->Iterations(nr_iterations)
114236
->Threads(2)
115237
->MeasureProcessCPUTime()
116238
->UseManualTime();
@@ -129,50 +251,54 @@ void BM_MainThreadAndWorkerThread(benchmark::State& state) {
129251
benchmark::Counter{1, benchmark::Counter::kIsRate};
130252
}
131253

132-
BENCHMARK(BM_MainThreadAndWorkerThread)->Iterations(1)->Threads(1);
133254
BENCHMARK(BM_MainThreadAndWorkerThread)
134-
->Iterations(1)
255+
->Iterations(nr_iterations)
256+
->Threads(1);
257+
BENCHMARK(BM_MainThreadAndWorkerThread)
258+
->Iterations(nr_iterations)
135259
->Threads(1)
136260
->UseRealTime();
137261
BENCHMARK(BM_MainThreadAndWorkerThread)
138-
->Iterations(1)
262+
->Iterations(nr_iterations)
139263
->Threads(1)
140264
->UseManualTime();
141265
BENCHMARK(BM_MainThreadAndWorkerThread)
142-
->Iterations(1)
266+
->Iterations(nr_iterations)
143267
->Threads(1)
144268
->MeasureProcessCPUTime();
145269
BENCHMARK(BM_MainThreadAndWorkerThread)
146-
->Iterations(1)
270+
->Iterations(nr_iterations)
147271
->Threads(1)
148272
->MeasureProcessCPUTime()
149273
->UseRealTime();
150274
BENCHMARK(BM_MainThreadAndWorkerThread)
151-
->Iterations(1)
275+
->Iterations(nr_iterations)
152276
->Threads(1)
153277
->MeasureProcessCPUTime()
154278
->UseManualTime();
155279

156-
BENCHMARK(BM_MainThreadAndWorkerThread)->Iterations(1)->Threads(2);
157280
BENCHMARK(BM_MainThreadAndWorkerThread)
158-
->Iterations(1)
281+
->Iterations(nr_iterations)
282+
->Threads(2);
283+
BENCHMARK(BM_MainThreadAndWorkerThread)
284+
->Iterations(nr_iterations)
159285
->Threads(2)
160286
->UseRealTime();
161287
BENCHMARK(BM_MainThreadAndWorkerThread)
162-
->Iterations(1)
288+
->Iterations(nr_iterations)
163289
->Threads(2)
164290
->UseManualTime();
165291
BENCHMARK(BM_MainThreadAndWorkerThread)
166-
->Iterations(1)
292+
->Iterations(nr_iterations)
167293
->Threads(2)
168294
->MeasureProcessCPUTime();
169295
BENCHMARK(BM_MainThreadAndWorkerThread)
170-
->Iterations(1)
296+
->Iterations(nr_iterations)
171297
->Threads(2)
172298
->MeasureProcessCPUTime()
173299
->UseRealTime();
174300
BENCHMARK(BM_MainThreadAndWorkerThread)
175-
->Iterations(1)
301+
->Iterations(nr_iterations)
176302
->Threads(2)
177303
->MeasureProcessCPUTime()
178304
->UseManualTime();
@@ -181,4 +307,9 @@ BENCHMARK(BM_MainThreadAndWorkerThread)
181307
// ---------------------------- TEST CASES END ----------------------------- //
182308
// ========================================================================= //
183309

184-
int main(int argc, char* argv[]) { RunOutputTests(argc, argv); }
310+
int main(int argc, char* argv[]) {
311+
benchmark::Initialize(&argc, argv);
312+
TestReporter test_reporter;
313+
benchmark::RunSpecifiedBenchmarks(&test_reporter);
314+
return 0;
315+
}

0 commit comments

Comments
 (0)