1 // Copyright 2019 The Dawn Authors
2 //
3 // Licensed under the Apache License, Version 2.0 (the "License");
4 // you may not use this file except in compliance with the License.
5 // You may obtain a copy of the License at
6 //
7 // http://www.apache.org/licenses/LICENSE-2.0
8 //
9 // Unless required by applicable law or agreed to in writing, software
10 // distributed under the License is distributed on an "AS IS" BASIS,
11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 // See the License for the specific language governing permissions and
13 // limitations under the License.
14
15 #include "tests/perf_tests/DawnPerfTest.h"
16
17 #include <algorithm>
18 #include <fstream>
19 #include <limits>
20
21 #include "common/Assert.h"
22 #include "common/Log.h"
23 #include "dawn_platform/tracing/TraceEvent.h"
24 #include "tests/perf_tests/DawnPerfTestPlatform.h"
25 #include "utils/Timer.h"
26
27 namespace {
28
29 DawnPerfTestEnvironment* gTestEnv = nullptr;
30
DumpTraceEventsToJSONFile(const std::vector<DawnPerfTestPlatform::TraceEvent> & traceEventBuffer,const char * traceFile)31 void DumpTraceEventsToJSONFile(
32 const std::vector<DawnPerfTestPlatform::TraceEvent>& traceEventBuffer,
33 const char* traceFile) {
34 std::ofstream outFile;
35 outFile.open(traceFile, std::ios_base::app);
36
37 for (const DawnPerfTestPlatform::TraceEvent& traceEvent : traceEventBuffer) {
38 const char* category = nullptr;
39 switch (traceEvent.category) {
40 case dawn_platform::TraceCategory::General:
41 category = "general";
42 break;
43 case dawn_platform::TraceCategory::Validation:
44 category = "validation";
45 break;
46 case dawn_platform::TraceCategory::Recording:
47 category = "recording";
48 break;
49 case dawn_platform::TraceCategory::GPUWork:
50 category = "gpu";
51 break;
52 default:
53 UNREACHABLE();
54 }
55
56 uint64_t microseconds = static_cast<uint64_t>(traceEvent.timestamp * 1000.0 * 1000.0);
57
58 outFile << ", { "
59 << "\"name\": \"" << traceEvent.name << "\", "
60 << "\"cat\": \"" << category << "\", "
61 << "\"ph\": \"" << traceEvent.phase << "\", "
62 << "\"id\": " << traceEvent.id << ", "
63 << "\"tid\": " << traceEvent.threadId << ", "
64 << "\"ts\": " << microseconds << ", "
65 << "\"pid\": \"Dawn\""
66 << " }";
67 }
68 outFile.close();
69 }
70
71 } // namespace
72
InitDawnPerfTestEnvironment(int argc,char ** argv)73 void InitDawnPerfTestEnvironment(int argc, char** argv) {
74 gTestEnv = new DawnPerfTestEnvironment(argc, argv);
75 DawnTestEnvironment::SetEnvironment(gTestEnv);
76 testing::AddGlobalTestEnvironment(gTestEnv);
77 }
78
DawnPerfTestEnvironment(int argc,char ** argv)79 DawnPerfTestEnvironment::DawnPerfTestEnvironment(int argc, char** argv)
80 : DawnTestEnvironment(argc, argv) {
81 size_t argLen = 0; // Set when parsing --arg=X arguments
82 for (int i = 1; i < argc; ++i) {
83 if (strcmp("--calibration", argv[i]) == 0) {
84 mIsCalibrating = true;
85 continue;
86 }
87
88 constexpr const char kOverrideStepsArg[] = "--override-steps=";
89 argLen = sizeof(kOverrideStepsArg) - 1;
90 if (strncmp(argv[i], kOverrideStepsArg, argLen) == 0) {
91 const char* overrideSteps = argv[i] + argLen;
92 if (overrideSteps[0] != '\0') {
93 mOverrideStepsToRun = strtoul(overrideSteps, nullptr, 0);
94 }
95 continue;
96 }
97
98 constexpr const char kTraceFileArg[] = "--trace-file=";
99 argLen = sizeof(kTraceFileArg) - 1;
100 if (strncmp(argv[i], kTraceFileArg, argLen) == 0) {
101 const char* traceFile = argv[i] + argLen;
102 if (traceFile[0] != '\0') {
103 mTraceFile = traceFile;
104 }
105 continue;
106 }
107
108 if (strcmp("-h", argv[i]) == 0 || strcmp("--help", argv[i]) == 0) {
109 dawn::InfoLog()
110 << "Additional flags:"
111 << " [--calibration] [--override-steps=x] [--trace-file=file]\n"
112 << " --calibration: Only run calibration. Calibration allows the perf test"
113 " runner script to save some time.\n"
114 << " --override-steps: Set a fixed number of steps to run for each test\n"
115 << " --trace-file: The file to dump trace results.\n";
116 continue;
117 }
118 }
119 }
120
121 DawnPerfTestEnvironment::~DawnPerfTestEnvironment() = default;
122
SetUp()123 void DawnPerfTestEnvironment::SetUp() {
124 DawnTestEnvironment::SetUp();
125
126 mPlatform = std::make_unique<DawnPerfTestPlatform>();
127 mInstance->SetPlatform(mPlatform.get());
128
129 // Begin writing the trace event array.
130 if (mTraceFile != nullptr) {
131 std::ofstream outFile;
132 outFile.open(mTraceFile);
133 outFile << "{ \"traceEvents\": [";
134 outFile << "{}"; // Dummy object so trace events can always prepend a comma
135 outFile.flush();
136 outFile.close();
137 }
138 }
139
TearDown()140 void DawnPerfTestEnvironment::TearDown() {
141 // End writing the trace event array.
142 if (mTraceFile != nullptr) {
143 std::vector<DawnPerfTestPlatform::TraceEvent> traceEventBuffer =
144 mPlatform->AcquireTraceEventBuffer();
145
146 // Write remaining trace events.
147 DumpTraceEventsToJSONFile(traceEventBuffer, mTraceFile);
148
149 std::ofstream outFile;
150 outFile.open(mTraceFile, std::ios_base::app);
151 outFile << "]}";
152 outFile << std::endl;
153 outFile.close();
154 }
155
156 DawnTestEnvironment::TearDown();
157 }
158
IsCalibrating() const159 bool DawnPerfTestEnvironment::IsCalibrating() const {
160 return mIsCalibrating;
161 }
162
OverrideStepsToRun() const163 unsigned int DawnPerfTestEnvironment::OverrideStepsToRun() const {
164 return mOverrideStepsToRun;
165 }
166
GetTraceFile() const167 const char* DawnPerfTestEnvironment::GetTraceFile() const {
168 return mTraceFile;
169 }
170
GetPlatform() const171 DawnPerfTestPlatform* DawnPerfTestEnvironment::GetPlatform() const {
172 return mPlatform.get();
173 }
174
DawnPerfTestBase(DawnTestBase * test,unsigned int iterationsPerStep,unsigned int maxStepsInFlight)175 DawnPerfTestBase::DawnPerfTestBase(DawnTestBase* test,
176 unsigned int iterationsPerStep,
177 unsigned int maxStepsInFlight)
178 : mTest(test),
179 mIterationsPerStep(iterationsPerStep),
180 mMaxStepsInFlight(maxStepsInFlight),
181 mTimer(utils::CreateTimer()) {
182 }
183
184 DawnPerfTestBase::~DawnPerfTestBase() = default;
185
AbortTest()186 void DawnPerfTestBase::AbortTest() {
187 mRunning = false;
188 }
189
RunTest()190 void DawnPerfTestBase::RunTest() {
191 if (gTestEnv->OverrideStepsToRun() == 0) {
192 // Run to compute the approximate number of steps to perform.
193 mStepsToRun = std::numeric_limits<unsigned int>::max();
194
195 // Do a warmup run for calibration.
196 DoRunLoop(kCalibrationRunTimeSeconds);
197 DoRunLoop(kCalibrationRunTimeSeconds);
198
199 // Scale steps down according to the time that exceeded one second.
200 double scale = kCalibrationRunTimeSeconds / mTimer->GetElapsedTime();
201 mStepsToRun = static_cast<unsigned int>(static_cast<double>(mNumStepsPerformed) * scale);
202
203 // Calibration allows the perf test runner script to save some time.
204 if (gTestEnv->IsCalibrating()) {
205 PrintResult("steps", mStepsToRun, "count", false);
206 return;
207 }
208 } else {
209 mStepsToRun = gTestEnv->OverrideStepsToRun();
210 }
211
212 // Do another warmup run. Seems to consistently improve results.
213 DoRunLoop(kMaximumRunTimeSeconds);
214
215 DawnPerfTestPlatform* platform =
216 reinterpret_cast<DawnPerfTestPlatform*>(gTestEnv->GetPlatform());
217 const char* testName = ::testing::UnitTest::GetInstance()->current_test_info()->name();
218
219 // Only enable trace event recording in this section.
220 // We don't care about trace events during warmup and calibration.
221 platform->EnableTraceEventRecording(true);
222 {
223 TRACE_EVENT0(platform, General, testName);
224 for (unsigned int trial = 0; trial < kNumTrials; ++trial) {
225 TRACE_EVENT0(platform, General, "Trial");
226 DoRunLoop(kMaximumRunTimeSeconds);
227 OutputResults();
228 }
229 }
230 platform->EnableTraceEventRecording(false);
231 }
232
DoRunLoop(double maxRunTime)233 void DawnPerfTestBase::DoRunLoop(double maxRunTime) {
234 dawn_platform::Platform* platform = gTestEnv->GetPlatform();
235
236 mNumStepsPerformed = 0;
237 mCpuTime = 0;
238 mRunning = true;
239
240 uint64_t finishedIterations = 0;
241 uint64_t submittedIterations = 0;
242
243 mTimer->Start();
244
245 // This loop can be canceled by calling AbortTest().
246 while (mRunning) {
247 // Wait if there are too many steps in flight on the GPU.
248 while (submittedIterations - finishedIterations >= mMaxStepsInFlight) {
249 mTest->WaitABit();
250 }
251
252 TRACE_EVENT0(platform, General, "Step");
253 double stepStart = mTimer->GetElapsedTime();
254 Step();
255 mCpuTime += mTimer->GetElapsedTime() - stepStart;
256
257 submittedIterations++;
258 mTest->queue.OnSubmittedWorkDone(
259 0u,
260 [](WGPUQueueWorkDoneStatus, void* userdata) {
261 uint64_t* counter = static_cast<uint64_t*>(userdata);
262 (*counter)++;
263 },
264 &finishedIterations);
265
266 if (mRunning) {
267 ++mNumStepsPerformed;
268 if (mTimer->GetElapsedTime() > maxRunTime) {
269 mRunning = false;
270 } else if (mNumStepsPerformed >= mStepsToRun) {
271 mRunning = false;
272 }
273 }
274 }
275
276 // Wait for all GPU commands to complete.
277 // TODO(enga): When Dawn has multiple backgrounds threads, add a Device::WaitForIdleForTesting()
278 // which waits for all threads to stop doing work. When we output results, there should
279 // be no additional incoming trace events.
280 while (submittedIterations != finishedIterations) {
281 mTest->WaitABit();
282 }
283
284 mTimer->Stop();
285 }
286
OutputResults()287 void DawnPerfTestBase::OutputResults() {
288 // TODO(enga): When Dawn has multiple backgrounds threads, add a Device::WaitForIdleForTesting()
289 // which waits for all threads to stop doing work. When we output results, there should
290 // be no additional incoming trace events.
291 DawnPerfTestPlatform* platform =
292 reinterpret_cast<DawnPerfTestPlatform*>(gTestEnv->GetPlatform());
293
294 std::vector<DawnPerfTestPlatform::TraceEvent> traceEventBuffer =
295 platform->AcquireTraceEventBuffer();
296
297 struct EventTracker {
298 double start = std::numeric_limits<double>::max();
299 double end = 0;
300 uint32_t count = 0;
301 };
302
303 EventTracker validationTracker = {};
304 EventTracker recordingTracker = {};
305
306 double totalValidationTime = 0;
307 double totalRecordingTime = 0;
308
309 // Note: We assume END timestamps always come after their corresponding BEGIN timestamps.
310 // TODO(enga): When Dawn has multiple threads, stratify by thread id.
311 for (const DawnPerfTestPlatform::TraceEvent& traceEvent : traceEventBuffer) {
312 EventTracker* tracker = nullptr;
313 double* totalTime = nullptr;
314
315 switch (traceEvent.category) {
316 case dawn_platform::TraceCategory::Validation:
317 tracker = &validationTracker;
318 totalTime = &totalValidationTime;
319 break;
320 case dawn_platform::TraceCategory::Recording:
321 tracker = &recordingTracker;
322 totalTime = &totalRecordingTime;
323 break;
324 default:
325 break;
326 }
327
328 if (tracker == nullptr) {
329 continue;
330 }
331
332 if (traceEvent.phase == TRACE_EVENT_PHASE_BEGIN) {
333 tracker->start = std::min(tracker->start, traceEvent.timestamp);
334 tracker->count++;
335 }
336
337 if (traceEvent.phase == TRACE_EVENT_PHASE_END) {
338 tracker->end = std::max(tracker->end, traceEvent.timestamp);
339 ASSERT(tracker->count > 0);
340 tracker->count--;
341
342 if (tracker->count == 0) {
343 *totalTime += (tracker->end - tracker->start);
344 *tracker = {};
345 }
346 }
347 }
348
349 PrintPerIterationResultFromSeconds("wall_time", mTimer->GetElapsedTime(), true);
350 PrintPerIterationResultFromSeconds("cpu_time", mCpuTime, true);
351 PrintPerIterationResultFromSeconds("validation_time", totalValidationTime, true);
352 PrintPerIterationResultFromSeconds("recording_time", totalRecordingTime, true);
353
354 const char* traceFile = gTestEnv->GetTraceFile();
355 if (traceFile != nullptr) {
356 DumpTraceEventsToJSONFile(traceEventBuffer, traceFile);
357 }
358 }
359
PrintPerIterationResultFromSeconds(const std::string & trace,double valueInSeconds,bool important) const360 void DawnPerfTestBase::PrintPerIterationResultFromSeconds(const std::string& trace,
361 double valueInSeconds,
362 bool important) const {
363 if (valueInSeconds == 0) {
364 return;
365 }
366
367 double secondsPerIteration =
368 valueInSeconds / static_cast<double>(mNumStepsPerformed * mIterationsPerStep);
369
370 // Give the result a different name to ensure separate graphs if we transition.
371 if (secondsPerIteration > 1) {
372 PrintResult(trace, secondsPerIteration * 1e3, "ms", important);
373 } else if (secondsPerIteration > 1e-3) {
374 PrintResult(trace, secondsPerIteration * 1e6, "us", important);
375 } else {
376 PrintResult(trace, secondsPerIteration * 1e9, "ns", important);
377 }
378 }
379
PrintResult(const std::string & trace,double value,const std::string & units,bool important) const380 void DawnPerfTestBase::PrintResult(const std::string& trace,
381 double value,
382 const std::string& units,
383 bool important) const {
384 PrintResultImpl(trace, std::to_string(value), units, important);
385 }
386
PrintResult(const std::string & trace,unsigned int value,const std::string & units,bool important) const387 void DawnPerfTestBase::PrintResult(const std::string& trace,
388 unsigned int value,
389 const std::string& units,
390 bool important) const {
391 PrintResultImpl(trace, std::to_string(value), units, important);
392 }
393
PrintResultImpl(const std::string & trace,const std::string & value,const std::string & units,bool important) const394 void DawnPerfTestBase::PrintResultImpl(const std::string& trace,
395 const std::string& value,
396 const std::string& units,
397 bool important) const {
398 const ::testing::TestInfo* const testInfo =
399 ::testing::UnitTest::GetInstance()->current_test_info();
400
401 std::string metric = std::string(testInfo->test_suite_name()) + "." + trace;
402
403 std::string story = testInfo->name();
404 std::replace(story.begin(), story.end(), '/', '_');
405
406 // The results are printed according to the format specified at
407 // [chromium]//src/tools/perf/generate_legacy_perf_dashboard_json.py
408 dawn::InfoLog() << (important ? "*" : "") << "RESULT " << metric << ": " << story << "= "
409 << value << " " << units;
410 }
411