• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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