1 /*
<lambda>null2 * Copyright 2018 Google Inc.
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 * https://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
17 /*
18 * Notes
19 *
20 * TODO (chriswailes): Build a unified error reporting mechanism.
21 * TODO (chriswailes): Support CSV output
22 */
23
24 /*
25 * Imports
26 */
27
28 import java.io.File
29
30 import kotlin.math.pow
31 import kotlin.math.sqrt
32 import kotlin.system.exitProcess
33
34 import trebuchet.extras.parseTrace
35 import trebuchet.model.SchedulingState
36 import trebuchet.util.slices.*
37 import trebuchet.util.time.*
38
39 /*
40 * Constants
41 */
42
43 val FILENAME_PATTERN = Regex("launch-(\\w+)-(\\w+)-(quicken|speed|speed-profile)-(cold|warm)-\\d")
44
45 val INTERESTING_SLICES = arrayOf(
46 SLICE_NAME_ACTIVITY_START,
47 SLICE_NAME_ACTIVITY_THREAD_MAIN,
48 SLICE_NAME_APP_IMAGE_INTERN_STRING,
49 SLICE_NAME_APP_IMAGE_LOADING,
50 SLICE_NAME_BIND_APPLICATION,
51 SLICE_NAME_INFLATE,
52 SLICE_NAME_POST_FORK,
53 SLICE_NAME_ZYGOTE_INIT)
54
55 const val SAMPLE_THRESHOLD_APPLICATION = 5
56 const val SAMPLE_THRESHOLD_COMPILER = 5
57 const val SAMPLE_THRESHOLD_TEMPERATURE = 5
58
59 /*
60 * Class Definition
61 */
62
63 enum class CompilerFilter {
64 QUICKEN,
65 SPEED,
66 SPEED_PROFILE
67 }
68
69 enum class Temperature {
70 COLD,
71 WARM
72 }
73
74 class CompilerRecord(val cold : MutableList<StartupEvent> = mutableListOf(),
75 val warm : MutableList<StartupEvent> = mutableListOf()) {
76
numSamplesnull77 fun numSamples() : Int {
78 return this.cold.size + this.warm.size
79 }
80 }
81
82 class ApplicationRecord(val quicken : CompilerRecord = CompilerRecord(),
83 val speed : CompilerRecord = CompilerRecord(),
84 val speedProfile : CompilerRecord = CompilerRecord()) {
85
numSamplesnull86 fun numSamples() : Int {
87 return this.quicken.numSamples() + this.speed.numSamples() + this.speedProfile.numSamples()
88 }
89 }
90
91 /*
92 * Class Extensions
93 */
94
95 /*
96 * Helper Functions
97 */
98
addStartupRecordnull99 fun addStartupRecord(records : MutableMap<String, ApplicationRecord>, startupEvent : StartupEvent, appName : String, compiler : CompilerFilter, temperature : Temperature) {
100 val applicationRecord = records.getOrPut(appName) { ApplicationRecord() }
101
102 val compilerRecord =
103 when (compiler) {
104 CompilerFilter.QUICKEN -> applicationRecord.quicken
105 CompilerFilter.SPEED -> applicationRecord.speed
106 CompilerFilter.SPEED_PROFILE -> applicationRecord.speedProfile
107 }
108
109 when (temperature) {
110 Temperature.COLD -> compilerRecord.cold
111 Temperature.WARM -> compilerRecord.warm
112 }.add(startupEvent)
113 }
114
averageAndStandardDeviationnull115 fun averageAndStandardDeviation(values : List<Double>) : Pair<Double, Double> {
116 val total = values.sum()
117 val averageValue = total / values.size
118
119 var sumOfSquaredDiffs = 0.0
120
121 values.forEach { value ->
122 sumOfSquaredDiffs += (value - averageValue).pow(2)
123 }
124
125 return Pair(averageValue, sqrt(sumOfSquaredDiffs / values.size))
126 }
127
parseFileNamenull128 fun parseFileName(fileName : String) : Triple<String, CompilerFilter, Temperature> {
129 val md = FILENAME_PATTERN.find(fileName)
130
131 if (md != null) {
132 val compilerFilter =
133 when (md.groups[3]!!.value) {
134 "quicken" -> CompilerFilter.QUICKEN
135 "speed" -> CompilerFilter.SPEED
136 "speed-profile" -> CompilerFilter.SPEED_PROFILE
137 else -> throw Exception("Bad compiler match data.")
138 }
139
140 val temperature =
141 when (md.groups[4]!!.value) {
142 "cold" -> Temperature.COLD
143 "warm" -> Temperature.WARM
144 else -> throw Exception("Bad temperature match data.")
145 }
146
147 return Triple(md.groups[1]!!.value, compilerFilter, temperature)
148 } else {
149 println("Unrecognized file name: $fileName")
150 exitProcess(1)
151 }
152 }
153
printPlainTextnull154 fun printPlainText(records : MutableMap<String, ApplicationRecord>) {
155 records.forEach { appName, record ->
156 if (record.numSamples() > SAMPLE_THRESHOLD_APPLICATION) {
157 println("$appName:")
158 printAppRecordPlainText(record)
159 println()
160 }
161 }
162 }
163
printAppRecordPlainTextnull164 fun printAppRecordPlainText(record : ApplicationRecord) {
165 if (record.quicken.numSamples() > SAMPLE_THRESHOLD_COMPILER) {
166 println("\tQuicken:")
167 printCompilerRecordPlainText(record.quicken)
168 }
169
170 if (record.speed.numSamples() > SAMPLE_THRESHOLD_COMPILER) {
171 println("\tSpeed:")
172 printCompilerRecordPlainText(record.speed)
173 }
174
175 if (record.speedProfile.numSamples() > SAMPLE_THRESHOLD_COMPILER) {
176 println("\tSpeed Profile:")
177 printCompilerRecordPlainText(record.speedProfile)
178 }
179 }
180
printCompilerRecordPlainTextnull181 fun printCompilerRecordPlainText(record : CompilerRecord) {
182 if (record.cold.size > SAMPLE_THRESHOLD_TEMPERATURE) {
183 println("\t\tCold:")
184 printSampleSetPlainText(record.cold)
185 }
186
187 if (record.warm.size > SAMPLE_THRESHOLD_TEMPERATURE) {
188 println("\t\tWarm:")
189 printSampleSetPlainText(record.warm)
190 }
191 }
192
printSampleSetPlainTextnull193 fun printSampleSetPlainText(records : List<StartupEvent>) {
194
195 val (startupTimeAverage, startupTimeStandardDeviation) = averageAndStandardDeviation(records.map {it.endTime - it.startTime})
196 val (timeToFirstSliceAverage, timeToFirstSliceStandardDeviation) = averageAndStandardDeviation(records.map {it.firstSliceTime - it.startTime})
197 val (undifferentiatedTimeAverage, undifferentiatedTimeStandardDeviation) = averageAndStandardDeviation(records.map {it.undifferentiatedTime})
198
199 println("\t\t\tAverage startup time: ${startupTimeAverage.secondValueToMillisecondString()}")
200 println("\t\t\tStartup time standard deviation: ${startupTimeStandardDeviation.secondValueToMillisecondString()}")
201 println("\t\t\tAverage time to first slice: ${timeToFirstSliceAverage.secondValueToMillisecondString()}")
202 println("\t\t\tTTFS standard deviation: ${timeToFirstSliceStandardDeviation.secondValueToMillisecondString()}")
203 println("\t\t\tAverage undifferentiated time: ${undifferentiatedTimeAverage.secondValueToMillisecondString()}")
204 println("\t\t\tUDT standard deviation: ${undifferentiatedTimeStandardDeviation.secondValueToMillisecondString()}")
205
206 if (records.first().reportFullyDrawnTime != null) {
207 val (rfdTimeAverage, rfdTimeStandardDeviation) = averageAndStandardDeviation(records.map { it.reportFullyDrawnTime!! - it.startTime})
208 println("\t\t\tAverage RFD time: ${rfdTimeAverage.secondValueToMillisecondString()}")
209 println("\t\t\tRFD time standard deviation: ${rfdTimeStandardDeviation.secondValueToMillisecondString()}")
210 }
211
212 println()
213
214 println("\t\t\tScheduling info:")
215 SchedulingState.values().toSortedSet().forEach { schedState ->
216 val (schedStateTimeAverage, schedStateTimeStandardDeviation) = averageAndStandardDeviation(records.map {it.schedTimings.getOrDefault(schedState, 0.0)})
217
218 if (schedStateTimeAverage != 0.0) {
219 println(
220 "\t\t\t\t${schedState.friendlyName}: ${schedStateTimeAverage.secondValueToMillisecondString()} / ${schedStateTimeStandardDeviation.secondValueToMillisecondString()}")
221 }
222 }
223
224 println()
225
226 // Definition of printing helper.
227 fun printSliceTimings(sliceInfos : List<AggregateSliceInfoMap>, filterSlices : Boolean) {
228 val samples : MutableMap<String, MutableList<Double>> = mutableMapOf()
229
230 sliceInfos.forEach { sliceInfo ->
231 sliceInfo.forEach {sliceName, aggInfo ->
232 samples.getOrPut(sliceName, ::mutableListOf).add(aggInfo.totalTime)
233 }
234 }
235
236 samples.forEach {sliceName, sliceSamples ->
237 if (!filterSlices || INTERESTING_SLICES.contains(sliceName)) {
238 val (sliceDurationAverage, sliceDurationStandardDeviation) = averageAndStandardDeviation(
239 sliceSamples)
240
241 println("\t\t\t\t$sliceName:")
242
243 println(
244 "\t\t\t\t\tAverage duration: ${sliceDurationAverage.secondValueToMillisecondString()}")
245 println(
246 "\t\t\t\t\tStandard deviation: ${sliceDurationStandardDeviation.secondValueToMillisecondString()}")
247 println("\t\t\t\t\tStartup time percent: %.2f%%".format(
248 (sliceDurationAverage / startupTimeAverage) * 100))
249 }
250 }
251 }
252
253 /*
254 * Timing accumulation
255 */
256
257 println("\t\t\tTop-level timings:")
258 printSliceTimings(records.map {it.topLevelSliceInfo}, false)
259 println()
260 println("\t\t\tNon-nested timings:")
261 printSliceTimings(records.map {it.nonNestedSliceInfo}, true)
262 println()
263 println("\t\t\tUndifferentiated timing:")
264 printSliceTimings(records.map {it.undifferentiatedSliceInfo}, true)
265 println()
266 }
267
printCSVnull268 fun printCSV(records : MutableMap<String, ApplicationRecord>) {
269 println("Application Name, Compiler Filter, Temperature, Startup Time Avg (ms), Startup Time SD (ms), Time-to-first-slice Avg (ms), Time-to-first-slice SD (ms), Report Fully Drawn Avg (ms), Report Fully Drawn SD (ms)")
270
271 records.forEach { appName, record ->
272 if (record.numSamples() > SAMPLE_THRESHOLD_APPLICATION) {
273 printAppRecordCSV(appName, record)
274 }
275 }
276 }
277
printAppRecordCSVnull278 fun printAppRecordCSV(appName : String, record : ApplicationRecord) {
279 if (record.quicken.numSamples() > SAMPLE_THRESHOLD_COMPILER) {
280 printCompilerRecordCSV(appName, "quicken", record.quicken)
281 }
282
283 if (record.speed.numSamples() > SAMPLE_THRESHOLD_COMPILER) {
284 printCompilerRecordCSV(appName, "speed", record.speed)
285 }
286
287 if (record.speedProfile.numSamples() > SAMPLE_THRESHOLD_COMPILER) {
288 printCompilerRecordCSV(appName, "speed-profile", record.speedProfile)
289 }
290 }
291
printCompilerRecordCSVnull292 fun printCompilerRecordCSV(appName : String, compilerFilter : String, record : CompilerRecord) {
293 if (record.cold.size > SAMPLE_THRESHOLD_TEMPERATURE) {
294 printSampleSetCSV(appName, compilerFilter, "cold", record.cold)
295 }
296
297 if (record.warm.size > SAMPLE_THRESHOLD_TEMPERATURE) {
298 printSampleSetCSV(appName, compilerFilter, "warm", record.warm)
299 }
300 }
301
printSampleSetCSVnull302 fun printSampleSetCSV(appName : String, compilerFilter : String, temperature : String, records : List<StartupEvent>) {
303 print("$appName, $compilerFilter, $temperature, ")
304
305 val (startupTimeAverage, startupTimeStandardDeviation) = averageAndStandardDeviation(records.map {it.endTime - it.startTime})
306 print("%.3f, %.3f, ".format(startupTimeAverage * 1000, startupTimeStandardDeviation * 1000))
307
308 val (timeToFirstSliceAverage, timeToFirstSliceStandardDeviation) = averageAndStandardDeviation(records.map {it.firstSliceTime - it.startTime})
309 print("%.3f, %.3f,".format(timeToFirstSliceAverage * 1000, timeToFirstSliceStandardDeviation * 1000))
310
311 if (records.first().reportFullyDrawnTime != null) {
312 val (rfdTimeAverage, rfdTimeStandardDeviation) = averageAndStandardDeviation(records.map { it.reportFullyDrawnTime!! - it.startTime})
313 print(" %.3f, %.3f\n".format(rfdTimeAverage * 1000, rfdTimeStandardDeviation * 1000))
314
315 } else {
316 print(",\n")
317 }
318 }
319
320 /*
321 * Main Function
322 */
323
mainnull324 fun main(args: Array<String>) {
325 if (args.isEmpty()) {
326 println("Usage: StartupSummarizer <trace files>")
327 return
328 }
329
330 val records : MutableMap<String, ApplicationRecord> = mutableMapOf()
331 val exceptions : MutableList<Pair<String, Exception>> = mutableListOf()
332
333 var processedFiles = 0
334 var erroredFiles = 0
335
336 args.forEach { fileName ->
337 val (_, compiler, temperature) = parseFileName(fileName)
338
339 val trace = parseTrace(File(fileName), false)
340
341 try {
342 val traceStartupEvents : List<StartupEvent> = trace.getStartupEvents()
343
344 traceStartupEvents.forEach { startupEvent ->
345 addStartupRecord(records, startupEvent, startupEvent.name, compiler,
346 temperature)
347 }
348
349 } catch (e: Exception) {
350 exceptions.add(Pair(fileName, e))
351 ++erroredFiles
352 } finally {
353 ++processedFiles
354
355 print("\rProgress: $processedFiles ($erroredFiles) / ${args.size}")
356 }
357 }
358
359 println()
360
361 // printPlainText(records)
362 printCSV(records)
363
364 if (exceptions.count() > 0) {
365 println("Exceptions:")
366 exceptions.forEach { (fileName, exception) ->
367 println("\t$fileName: $exception${if (exception.message != null) "(${exception.message})" else ""}")
368 }
369 }
370 }