1 /*
2  * Copyright (C) 2018 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  * http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 package com.android.game.qualification.reporter;
17 
18 import com.android.ddmlib.Log;
19 import com.android.ddmlib.Log.LogLevel;
20 import com.android.ddmlib.testrunner.TestResult.TestStatus;
21 import com.android.game.qualification.CertificationRequirements;
22 import com.android.game.qualification.metric.GameQualificationFpsCollector;
23 import com.android.game.qualification.metric.LoopSummary;
24 import com.android.game.qualification.metric.MetricSummary;
25 import com.android.tradefed.config.Option;
26 import com.android.tradefed.metrics.proto.MetricMeasurement.Metric;
27 import com.android.tradefed.result.CollectingTestListener;
28 import com.android.tradefed.result.ILogSaver;
29 import com.android.tradefed.result.ILogSaverListener;
30 import com.android.tradefed.result.InputStreamSource;
31 import com.android.tradefed.result.LogDataType;
32 import com.android.tradefed.result.LogFile;
33 import com.android.tradefed.result.TestDescription;
34 import com.android.tradefed.result.TestResult;
35 import com.android.tradefed.result.TestRunResult;
36 
37 import java.io.ByteArrayInputStream;
38 import java.io.IOException;
39 import java.util.ArrayList;
40 import java.util.HashMap;
41 import java.util.List;
42 import java.util.Map;
43 import java.util.concurrent.ConcurrentHashMap;
44 
45 /**
46  * Result reporter for game core certification.
47  */
48 public class GameQualificationResultReporter extends CollectingTestListener implements ILogSaverListener {
49     private static final String TAG = GameQualificationResultReporter.class.getSimpleName();
50 
51     @Option(name = "suppress-passed-tests", description = "For functional tests, omit summary for "
52             + "passing tests, only print failed and ignored ones")
53     private boolean mSuppressPassedTest = false;
54 
55     private Map<TestDescription, MetricSummary> summaries = new ConcurrentHashMap<>();
56     private Map<TestDescription, CertificationRequirements> mRequirements = new ConcurrentHashMap<>();
57     private List<Throwable> invocationFailures = new ArrayList<>();
58     private List<LogFile> mLogFiles = new ArrayList<>();
59     private ILogSaver mLogSaver;
60     private int mTotalAllocated = 0;
61 
putRequirements(TestDescription testId, CertificationRequirements requirements)62     public void putRequirements(TestDescription testId, CertificationRequirements requirements) {
63         mRequirements.put(testId, requirements);
64     }
65 
66     @Override
invocationFailed(Throwable cause)67     public void invocationFailed(Throwable cause) {
68         super.invocationFailed(cause);
69         invocationFailures.add(cause);
70     }
71     /**
72      * Collect metrics produces by
73      * {@link GameQualificationFpsCollector}.
74      */
75     @Override
testEnded(TestDescription testId, long elapsedTime, HashMap<String, Metric> metrics)76     public void testEnded(TestDescription testId, long elapsedTime, HashMap<String, Metric> metrics) {
77         super.testEnded(testId, elapsedTime, metrics);
78         if (!metrics.isEmpty()) {
79                 MetricSummary summary = MetricSummary.parseRunMetrics(getInvocationContext(), metrics);
80                 if (summary != null) {
81                     summaries.put(testId, summary);
82                 } else if (metrics.containsKey("memory_allocated")) {
83                     mTotalAllocated = (int) metrics.get("memory_allocated").getMeasurements().getSingleInt();
84                 }
85         }
86     }
87 
88     /**
89      * {@inheritDoc}
90      */
91     @Override
testLogSaved(String dataName, LogDataType dataType, InputStreamSource dataStream, LogFile logFile)92     public void testLogSaved(String dataName, LogDataType dataType, InputStreamSource dataStream,
93             LogFile logFile) {
94         super.testLogSaved(dataName, dataType, dataStream, logFile);
95         mLogFiles.add(logFile);
96     }
97 
98     /**
99      * {@inheritDoc}
100      */
101     @Override
setLogSaver(ILogSaver logSaver)102     public void setLogSaver(ILogSaver logSaver) {
103         mLogSaver = logSaver;
104     }
105 
106     @Override
invocationEnded(long elapsedTime)107     public void invocationEnded(long elapsedTime) {
108         super.invocationEnded(elapsedTime);
109         String summary = getInvocationSummary();
110 
111         Log.logAndDisplay(LogLevel.INFO, TAG, summary);
112         try {
113             mLogSaver.saveLogData(
114                     "GameQualification-summary",
115                     LogDataType.TEXT,
116                     new ByteArrayInputStream(summary.getBytes()));
117         } catch (IOException e) {
118             Log.logAndDisplay(
119                     LogLevel.ERROR, TAG, "Failed writing summary to file: " + e.getMessage());
120         }
121     }
122 
123     /**
124      * Get the invocation summary as a string.
125      */
getInvocationSummary()126     private String getInvocationSummary() {
127         if (getMergedTestRunResults().isEmpty() && mLogFiles.isEmpty()) {
128             return "No test results\n";
129         }
130         StringBuilder sb = new StringBuilder();
131 
132         // Print location of log files.
133         if (!mLogFiles.isEmpty()) {
134             sb.append("Log Files:\n");
135             for (LogFile logFile : mLogFiles) {
136                 final String url = logFile.getUrl();
137                 sb.append(String.format("  %s\n", url != null ? url : logFile.getPath()));
138             }
139             sb.append("\n");
140         }
141 
142         // Print invocation failures.
143         if (!invocationFailures.isEmpty()) {
144             sb.append("Unable to certify device.  Invocation failed:\n");
145             for (Throwable t : invocationFailures) {
146                 sb.append("  ");
147                 sb.append(t.getMessage());
148                 sb.append("\n");
149             }
150             return sb.toString();
151         }
152 
153         // Print out device test results.
154         sb.append("Test Results:\n");
155         for (TestRunResult testRunResult : getMergedTestRunResults()) {
156             sb.append(getTestRunSummary(testRunResult));
157         }
158 
159         // Print workload run metrics.
160         for (Map.Entry<TestDescription, MetricSummary> entry : summaries.entrySet()) {
161             sb.append(String.format("\n%s Metrics:\n%s\n", entry.getKey(), entry.getValue()));
162         }
163 
164         // Print memory allocation metrics
165         sb.append("Total Memory Allocated During Allocation Stress Test: ");
166         sb.append(mTotalAllocated);
167         sb.append("\n\n");
168 
169         // Determine certification level.
170         sb.append("Certification:\n");
171 
172         boolean certified = true;
173 
174         sb.append("Functional tests [");
175         sb.append(hasFailedTests() ? "FAILED" : "PASSED");
176         sb.append("]\n");
177         int testCount = 1;
178         for (TestRunResult testRunResult : getMergedTestRunResults()) {
179             for (Map.Entry<TestDescription, TestResult> entry
180                     : testRunResult.getTestResults().entrySet()) {
181                 sb.append("\t[");
182                 sb.append(testCount);
183                 sb.append("/");
184                 sb.append(getNumTotalTests());
185                 sb.append("] ");
186                 sb.append(entry.getKey().toString());
187                 sb.append(": ");
188                 sb.append(entry.getValue().getStatus().name());
189                 sb.append("\n");
190                 testCount++;
191             }
192         }
193         if (hasFailedTests()) {
194             certified = false;
195             sb.append("Certification failed because the following tests failed:\n");
196             for (TestRunResult testRunResult : getMergedTestRunResults()) {
197                 for (TestDescription test : testRunResult.getFailedTests()) {
198                     sb.append('\t');
199                     sb.append(test.toString());
200 
201                     // Prints the first line of the stacktrace.
202                     TestResult result = testRunResult.getTestResults().get(test);
203                     String stacktrace = result.getStackTrace();
204                     if (!stacktrace.isEmpty()) {
205                         sb.append("\n\t\t");
206                         sb.append(
207                                 stacktrace.contains("\n")
208                                         ? stacktrace.split("\n", 2)[0]
209                                         : stacktrace);
210                     }
211                     sb.append('\n');
212                 }
213             }
214             try {
215                 LogFile logFile = createFunctionalTestFailureReport();
216                 sb.append("Details can be found in ");
217                 sb.append(logFile.getPath());
218                 sb.append('\n');
219             } catch (IOException e) {
220                 sb.append("Error generating test failures report: ");
221                 sb.append(e.getMessage());
222             }
223         }
224 
225         Report performanceReport = createPerformanceReport();
226         sb.append("Performance tests [");
227         sb.append(performanceReport.success ? "PASSED" : "FAILED");
228         sb.append("]\n");
229         sb.append(performanceReport.text);
230         if (!performanceReport.success) {
231             certified = false;
232         }
233 
234         sb.append("\nGame Core Certification: ");
235         sb.append(certified ? "PASSED" : "FAILED");
236         return "Test results:\n" + sb.toString().trim() + "\n";
237     }
238 
createFunctionalTestFailureReport()239     private LogFile createFunctionalTestFailureReport() throws IOException {
240         StringBuilder sb = new StringBuilder();
241         for (TestRunResult testRunResult : getMergedTestRunResults()) {
242             for (TestDescription test : testRunResult.getFailedTests()) {
243                 sb.append("Test:\n");
244                 sb.append(test.toString());
245                 sb.append('\n');
246                 sb.append("Error:\n");
247                 TestResult result = testRunResult.getTestResults().get(test);
248                 sb.append(result.getStackTrace());
249                 sb.append("\n\n");
250             }
251         }
252         return mLogSaver.saveLogData(
253                 "failure-report",
254                 LogDataType.TEXT,
255                 new ByteArrayInputStream(sb.toString().getBytes()));
256     }
257 
258     /**
259      * Get the test run summary as a string including run metrics.
260      */
getTestRunSummary(TestRunResult testRunResult)261     private String getTestRunSummary(TestRunResult testRunResult) {
262         StringBuilder sb = new StringBuilder();
263         sb.append(String.format("%s:", testRunResult.getName()));
264         if (testRunResult.getNumTests() > 0) {
265             sb.append(String.format(" %d Test%s, %d Passed, %d Failed, %d Ignored",
266                     testRunResult.getNumCompleteTests(),
267                     testRunResult.getNumCompleteTests() == 1 ? "" : "s", // Pluralize Test
268                     testRunResult.getNumTestsInState(TestStatus.PASSED),
269                     testRunResult.getNumAllFailedTests(),
270                     testRunResult.getNumTestsInState(TestStatus.IGNORED)));
271         } else if (testRunResult.getRunMetrics().size() == 0) {
272             sb.append(" No results");
273         }
274         sb.append("\n");
275         Map<TestDescription, TestResult> testResults = testRunResult.getTestResults();
276         for (Map.Entry<TestDescription, TestResult> entry : testResults.entrySet()) {
277             if (mSuppressPassedTest && TestStatus.PASSED.equals(entry.getValue().getStatus())) {
278                 continue;
279             }
280             sb.append(getTestSummary(entry.getKey(), entry.getValue()));
281         }
282         sb.append("\n");
283         return sb.toString();
284     }
285 
286     private static class Report {
287         boolean success;
288         String text;
289 
Report(boolean success, String text)290         public Report(boolean success, String text) {
291             this.success = success;
292             this.text = text;
293         }
294     }
295 
296     /**
297      * Create a report on the performance metrics against certification requirements.
298      *
299      * Returns an empty String if all metrics passes certification.
300      */
createPerformanceReport()301     private Report createPerformanceReport() {
302         StringBuilder text = new StringBuilder();
303         boolean success = true;
304         for (Map.Entry<TestDescription, MetricSummary> entry : summaries.entrySet()) {
305             TestDescription testId = entry.getKey();
306             MetricSummary metrics =  entry.getValue();
307             CertificationRequirements requirements = mRequirements.get(entry.getKey());
308             if (requirements == null) {
309                 text.append("Warning: ");
310                 text.append(testId.getTestName());
311                 text.append(" was executed, but performance metrics was ignored because "
312                         + "certification requirements was not found.\n");
313             } else {
314                 List<LoopSummary> loopSummaries = metrics.getLoopSummaries();
315                 // Fail if any loop fails the jank rate test.  If there are 3 or more loops, ignore
316                 // the first and last loop.  Otherwise, check only the first loop.
317                 int begin = loopSummaries.size() > 2 ? 1 : 0;
318                 int end = loopSummaries.size() > 2 ? loopSummaries.size() - 1 : 1;
319                 for (int i = begin; i < end; i++) {
320                     LoopSummary summary = loopSummaries.get(i);
321                     if (summary.getJankRate() > requirements.getJankRate()) {
322                         success = false;
323                         text.append(
324                                 String.format(
325                                         "Jank rate for %s in loop %d is too high, actual: "
326                                                 + "%f, target: %f\n",
327                                         testId.getTestName(),
328                                         i,
329                                         summary.getJankRate(),
330                                         requirements.getJankRate()));
331                         break;
332                     }
333                 }
334 
335                 if (loopSummaries.size() == 2) {
336                     text.append("Warning: runtime specification allowed for exactly 2 loops to be "
337                             + "ran for ");
338                     text.append(testId.getTestName());
339                     text.append(".  Extending the runtime is recommended.");
340 
341                 }
342 
343                 if (requirements.getLoadTime() >= 0) {
344                     if (metrics.getLoadTimeMs() == -1) {
345                         success = false;
346                         text.append("Unable to determine load time for ");
347                         text.append(testId.getTestName());
348                         text.append(".  Expected START_LOOP Intent was not received.\n");
349                     } else if (metrics.getLoadTimeMs() > requirements.getLoadTime()) {
350                         success = false;
351                         text.append("Load time for ");
352                         text.append(testId.getTestName());
353                         text.append(" is too high, actual: ");
354                         text.append(metrics.getLoadTimeMs());
355                         text.append(" ms, target: ");
356                         text.append(requirements.getLoadTime());
357                         text.append(" ms\n");
358                     }
359                 }
360             }
361         }
362         return new Report(success, text.toString());
363     }
364 
365     /**
366      * Get the test summary as string including test metrics.
367      */
getTestSummary(TestDescription testId, TestResult testResult)368     private String getTestSummary(TestDescription testId, TestResult testResult) {
369         StringBuilder sb = new StringBuilder();
370         sb.append(String.format("  %s: %s (%dms)\n", testId.toString(), testResult.getStatus(),
371                 testResult.getEndTime() - testResult.getStartTime()));
372         String stack = testResult.getStackTrace();
373         if (stack != null && !stack.isEmpty()) {
374             sb.append("  stack=\n");
375             String lines[] = stack.split("\\r?\\n");
376             for (String line : lines) {
377                 sb.append(String.format("    %s\n", line));
378             }
379         }
380         return sb.toString();
381     }
382 }
383