| OLD | NEW |
| (Empty) |
| 1 // Copyright (c) 2017, the Dart project authors. Please see the AUTHORS file | |
| 2 // for details. All rights reserved. Use of this source code is governed by a | |
| 3 // BSD-style license that can be found in the LICENSE file. | |
| 4 | |
| 5 /// Compares the test log of a build step with previous builds. | |
| 6 /// | |
| 7 /// Use this to detect flakiness of failures, especially timeouts. | |
| 8 | |
| 9 import 'dart:async'; | |
| 10 import 'dart:convert'; | |
| 11 import 'dart:io'; | |
| 12 | |
| 13 main(List<String> args) async { | |
| 14 if (args.length != 1) { | |
| 15 print('Usage: compare_failures <log-uri>'); | |
| 16 exit(1); | |
| 17 } | |
| 18 String url = args.first; | |
| 19 if (!url.endsWith('/text')) { | |
| 20 // Use the text version of the stdio log. | |
| 21 url += '/text'; | |
| 22 } | |
| 23 Uri uri = Uri.parse(url); | |
| 24 HttpClient client = new HttpClient(); | |
| 25 BuildUri buildUri = new BuildUri(uri); | |
| 26 List<BuildResult> results = await readBuildResults(client, buildUri); | |
| 27 print(generateBuildResultsSummary(buildUri, results)); | |
| 28 client.close(); | |
| 29 } | |
| 30 | |
| 31 /// Creates a [BuildResult] for [buildUri] and, if it contains failures, the | |
| 32 /// [BuildResult]s for the previous 5 builds. | |
| 33 Future<List<BuildResult>> readBuildResults( | |
| 34 HttpClient client, BuildUri buildUri) async { | |
| 35 List<BuildResult> summaries = <BuildResult>[]; | |
| 36 BuildResult firstSummary = await readBuildResult(client, buildUri); | |
| 37 summaries.add(firstSummary); | |
| 38 if (firstSummary.hasFailures) { | |
| 39 for (int i = 0; i < 5; i++) { | |
| 40 buildUri = buildUri.prev(); | |
| 41 summaries.add(await readBuildResult(client, buildUri)); | |
| 42 } | |
| 43 } | |
| 44 return summaries; | |
| 45 } | |
| 46 | |
| 47 /// Reads the content of [uri] as text. | |
| 48 Future<String> readUriAsText(HttpClient client, Uri uri) async { | |
| 49 HttpClientRequest request = await client.getUrl(uri); | |
| 50 HttpClientResponse response = await request.close(); | |
| 51 return UTF8.decode(await response.expand((l) => l).toList()); | |
| 52 } | |
| 53 | |
| 54 /// Parses the [buildUri] test log and creates a [BuildResult] for it. | |
| 55 Future<BuildResult> readBuildResult( | |
| 56 HttpClient client, BuildUri buildUri) async { | |
| 57 Uri uri = buildUri.toUri(); | |
| 58 log('Reading $uri'); | |
| 59 String text = await readUriAsText(client, uri); | |
| 60 | |
| 61 bool inFailure = false; | |
| 62 List<String> currentFailure; | |
| 63 bool parsingTimingBlock = false; | |
| 64 | |
| 65 List<TestFailure> failures = <TestFailure>[]; | |
| 66 List<Timing> timings = <Timing>[]; | |
| 67 for (String line in text.split('\n')) { | |
| 68 if (currentFailure != null) { | |
| 69 if (line.startsWith('!@@@STEP_CLEAR@@@')) { | |
| 70 failures.add(new TestFailure(buildUri, currentFailure)); | |
| 71 currentFailure = null; | |
| 72 } else { | |
| 73 currentFailure.add(line); | |
| 74 } | |
| 75 } else if (inFailure && line.startsWith('@@@STEP_FAILURE@@@')) { | |
| 76 inFailure = false; | |
| 77 } else if (line.startsWith('!@@@STEP_FAILURE@@@')) { | |
| 78 inFailure = true; | |
| 79 } else if (line.startsWith('FAILED:')) { | |
| 80 currentFailure = <String>[]; | |
| 81 currentFailure.add(line); | |
| 82 } | |
| 83 if (line.startsWith('--- Total time:')) { | |
| 84 parsingTimingBlock = true; | |
| 85 } else if (parsingTimingBlock) { | |
| 86 if (line.startsWith('0:')) { | |
| 87 timings.addAll(parseTimings(buildUri, line)); | |
| 88 } else { | |
| 89 parsingTimingBlock = false; | |
| 90 } | |
| 91 } | |
| 92 } | |
| 93 return new BuildResult(buildUri, failures, timings); | |
| 94 } | |
| 95 | |
| 96 /// Generate a summary of the timeouts and other failures in [results]. | |
| 97 String generateBuildResultsSummary( | |
| 98 BuildUri buildUri, List<BuildResult> results) { | |
| 99 StringBuffer sb = new StringBuffer(); | |
| 100 sb.write('Results for $buildUri:\n'); | |
| 101 Set<TestConfiguration> timeoutIds = new Set<TestConfiguration>(); | |
| 102 for (BuildResult result in results) { | |
| 103 timeoutIds.addAll(result.timeouts.map((TestFailure failure) => failure.id)); | |
| 104 } | |
| 105 if (timeoutIds.isNotEmpty) { | |
| 106 int firstBuildNumber = results.first.buildUri.buildNumber; | |
| 107 int lastBuildNumber = results.last.buildUri.buildNumber; | |
| 108 Map<TestConfiguration, Map<int, Map<String, Timing>>> map = | |
| 109 <TestConfiguration, Map<int, Map<String, Timing>>>{}; | |
| 110 Set<String> stepNames = new Set<String>(); | |
| 111 for (BuildResult result in results) { | |
| 112 for (Timing timing in result.timings) { | |
| 113 Map<int, Map<String, Timing>> builds = | |
| 114 map.putIfAbsent(timing.step.id, () => <int, Map<String, Timing>>{}); | |
| 115 stepNames.add(timing.step.stepName); | |
| 116 builds.putIfAbsent(timing.uri.buildNumber, () => <String, Timing>{})[ | |
| 117 timing.step.stepName] = timing; | |
| 118 } | |
| 119 } | |
| 120 sb.write('Timeouts for ${buildUri} :\n'); | |
| 121 map.forEach((TestConfiguration id, Map<int, Map<String, Timing>> timings) { | |
| 122 if (!timeoutIds.contains(id)) return; | |
| 123 sb.write('$id\n'); | |
| 124 sb.write( | |
| 125 '${' ' * 8} ${stepNames.map((t) => padRight(t, 14)).join(' ')}\n'); | |
| 126 for (int buildNumber = firstBuildNumber; | |
| 127 buildNumber >= lastBuildNumber; | |
| 128 buildNumber--) { | |
| 129 Map<String, Timing> steps = timings[buildNumber] ?? const {}; | |
| 130 sb.write(padRight(' ${buildNumber}: ', 8)); | |
| 131 for (String stepName in stepNames) { | |
| 132 Timing timing = steps[stepName]; | |
| 133 if (timing != null) { | |
| 134 sb.write(' ${timing.time}'); | |
| 135 } else { | |
| 136 sb.write(' --------------'); | |
| 137 } | |
| 138 } | |
| 139 sb.write('\n'); | |
| 140 } | |
| 141 sb.write('\n'); | |
| 142 }); | |
| 143 } | |
| 144 Set<TestConfiguration> errorIds = new Set<TestConfiguration>(); | |
| 145 for (BuildResult result in results) { | |
| 146 errorIds.addAll(result.errors.map((TestFailure failure) => failure.id)); | |
| 147 } | |
| 148 if (errorIds.isNotEmpty) { | |
| 149 int firstBuildNumber = results.first.buildUri.buildNumber; | |
| 150 int lastBuildNumber = results.last.buildUri.buildNumber; | |
| 151 Map<TestConfiguration, Map<int, TestFailure>> map = | |
| 152 <TestConfiguration, Map<int, TestFailure>>{}; | |
| 153 for (BuildResult result in results) { | |
| 154 for (TestFailure failure in result.errors) { | |
| 155 map.putIfAbsent(failure.id, () => <int, TestFailure>{})[ | |
| 156 failure.uri.buildNumber] = failure; | |
| 157 } | |
| 158 } | |
| 159 sb.write('Errors for ${buildUri} :\n'); | |
| 160 // TODO(johnniwinther): Improve comparison of non-timeouts. | |
| 161 map.forEach((TestConfiguration id, Map<int, TestFailure> failures) { | |
| 162 if (!errorIds.contains(id)) return; | |
| 163 sb.write('$id\n'); | |
| 164 for (int buildNumber = firstBuildNumber; | |
| 165 buildNumber >= lastBuildNumber; | |
| 166 buildNumber--) { | |
| 167 TestFailure failure = failures[buildNumber]; | |
| 168 sb.write(padRight(' ${buildNumber}: ', 8)); | |
| 169 if (failure != null) { | |
| 170 sb.write(padRight(failure.expected, 10)); | |
| 171 sb.write(' / '); | |
| 172 sb.write(padRight(failure.actual, 10)); | |
| 173 } else { | |
| 174 sb.write(' ' * 10); | |
| 175 sb.write(' / '); | |
| 176 sb.write(padRight('-- OK --', 10)); | |
| 177 } | |
| 178 sb.write('\n'); | |
| 179 } | |
| 180 sb.write('\n'); | |
| 181 }); | |
| 182 } | |
| 183 return sb.toString(); | |
| 184 } | |
| 185 | |
| 186 /// The results of a build step. | |
| 187 class BuildResult { | |
| 188 final BuildUri buildUri; | |
| 189 final List<TestFailure> _failures; | |
| 190 final List<Timing> _timings; | |
| 191 | |
| 192 BuildResult(this.buildUri, this._failures, this._timings); | |
| 193 | |
| 194 /// `true` of the build result has test failures. | |
| 195 bool get hasFailures => _failures.isNotEmpty; | |
| 196 | |
| 197 /// Returns the top-20 timings found in the build log. | |
| 198 Iterable<Timing> get timings => _timings; | |
| 199 | |
| 200 /// Returns the [TestFailure]s for tests that timed out. | |
| 201 Iterable<TestFailure> get timeouts { | |
| 202 return _failures | |
| 203 .where((TestFailure failure) => failure.actual == 'Timeout'); | |
| 204 } | |
| 205 | |
| 206 /// Returns the [TestFailure]s for failing tests that did not time out. | |
| 207 Iterable<TestFailure> get errors { | |
| 208 return _failures | |
| 209 .where((TestFailure failure) => failure.actual != 'Timeout'); | |
| 210 } | |
| 211 | |
| 212 String toString() { | |
| 213 StringBuffer sb = new StringBuffer(); | |
| 214 sb.write('$buildUri\n'); | |
| 215 sb.write('Failures:\n${_failures.join('\n-----\n')}\n'); | |
| 216 sb.write('\nTimings:\n${_timings.join('\n')}'); | |
| 217 return sb.toString(); | |
| 218 } | |
| 219 } | |
| 220 | |
| 221 /// The [Uri] of a build step stdio log split into its subparts. | |
| 222 class BuildUri { | |
| 223 final String scheme; | |
| 224 final String host; | |
| 225 final String prefix; | |
| 226 final String botName; | |
| 227 final int buildNumber; | |
| 228 final String stepName; | |
| 229 final String suffix; | |
| 230 | |
| 231 factory BuildUri(Uri uri) { | |
| 232 String scheme = uri.scheme; | |
| 233 String host = uri.host; | |
| 234 List<String> parts = | |
| 235 split(uri.path, ['/builders/', '/builds/', '/steps/', '/logs/']); | |
| 236 String prefix = parts[0]; | |
| 237 String botName = parts[1]; | |
| 238 int buildNumber = int.parse(parts[2]); | |
| 239 String stepName = parts[3]; | |
| 240 String suffix = parts[4]; | |
| 241 return new BuildUri.internal( | |
| 242 scheme, host, prefix, botName, buildNumber, stepName, suffix); | |
| 243 } | |
| 244 | |
| 245 BuildUri.internal(this.scheme, this.host, this.prefix, this.botName, | |
| 246 this.buildNumber, this.stepName, this.suffix); | |
| 247 | |
| 248 String get buildName => | |
| 249 '/builders/$botName/builds/$buildNumber/steps/$stepName'; | |
| 250 | |
| 251 String get path => '$prefix$buildName/logs/$suffix'; | |
| 252 | |
| 253 /// Creates the [Uri] for this build step stdio log. | |
| 254 Uri toUri() { | |
| 255 return new Uri(scheme: scheme, host: host, path: path); | |
| 256 } | |
| 257 | |
| 258 /// Returns the [BuildUri] the previous build of this build step. | |
| 259 BuildUri prev() { | |
| 260 return new BuildUri.internal( | |
| 261 scheme, host, prefix, botName, buildNumber - 1, stepName, suffix); | |
| 262 } | |
| 263 | |
| 264 String toString() { | |
| 265 return buildName; | |
| 266 } | |
| 267 } | |
| 268 | |
| 269 /// Id for a test on a specific configuration, for instance | |
| 270 /// `dart2js-chrome release_x64/co19/Language/Metadata/before_function_t07`. | |
| 271 class TestConfiguration { | |
| 272 final String configName; | |
| 273 final String testName; | |
| 274 | |
| 275 TestConfiguration(this.configName, this.testName); | |
| 276 | |
| 277 String toString() { | |
| 278 return '$configName $testName'; | |
| 279 } | |
| 280 | |
| 281 int get hashCode => configName.hashCode * 17 + testName.hashCode * 19; | |
| 282 | |
| 283 bool operator ==(other) { | |
| 284 if (identical(this, other)) return true; | |
| 285 if (other is! TestConfiguration) return false; | |
| 286 return configName == other.configName && testName == other.testName; | |
| 287 } | |
| 288 } | |
| 289 | |
| 290 /// Test failure data derived from the test failure summary in the build step | |
| 291 /// stdio log. | |
| 292 class TestFailure { | |
| 293 final BuildUri uri; | |
| 294 final TestConfiguration id; | |
| 295 final String expected; | |
| 296 final String actual; | |
| 297 final String text; | |
| 298 | |
| 299 factory TestFailure(BuildUri uri, List<String> lines) { | |
| 300 List<String> parts = split(lines.first, ['FAILED: ', ' ', ' ']); | |
| 301 String configName = parts[1]; | |
| 302 String archName = parts[2]; | |
| 303 String testName = parts[3]; | |
| 304 TestConfiguration id = | |
| 305 new TestConfiguration(configName, '$archName/$testName'); | |
| 306 String expected = split(lines[1], ['Expected: '])[1]; | |
| 307 String actual = split(lines[2], ['Actual: '])[1]; | |
| 308 return new TestFailure.internal( | |
| 309 uri, id, expected, actual, lines.skip(3).join('\n')); | |
| 310 } | |
| 311 | |
| 312 TestFailure.internal( | |
| 313 this.uri, this.id, this.expected, this.actual, this.text); | |
| 314 | |
| 315 String toString() { | |
| 316 StringBuffer sb = new StringBuffer(); | |
| 317 sb.write('FAILED: $id\n'); | |
| 318 sb.write('Expected: $expected\n'); | |
| 319 sb.write('Actual: $actual\n'); | |
| 320 sb.write(text); | |
| 321 return sb.toString(); | |
| 322 } | |
| 323 } | |
| 324 | |
| 325 /// Id for a single test step, for instance the compilation and run steps of | |
| 326 /// a test. | |
| 327 class TestStep { | |
| 328 final String stepName; | |
| 329 final TestConfiguration id; | |
| 330 | |
| 331 TestStep(this.stepName, this.id); | |
| 332 | |
| 333 String toString() { | |
| 334 return '$stepName - $id'; | |
| 335 } | |
| 336 | |
| 337 int get hashCode => stepName.hashCode * 13 + id.hashCode * 17; | |
| 338 | |
| 339 bool operator ==(other) { | |
| 340 if (identical(this, other)) return true; | |
| 341 if (other is! TestStep) return false; | |
| 342 return stepName == other.stepName && id == other.id; | |
| 343 } | |
| 344 } | |
| 345 | |
| 346 /// The timing result for a single test step. | |
| 347 class Timing { | |
| 348 final BuildUri uri; | |
| 349 final String time; | |
| 350 final TestStep step; | |
| 351 | |
| 352 Timing(this.uri, this.time, this.step); | |
| 353 | |
| 354 String toString() { | |
| 355 return '$time - $step'; | |
| 356 } | |
| 357 } | |
| 358 | |
| 359 /// Create the [Timing]s for the [line] as found in the top-20 timings of a | |
| 360 /// build step stdio log. | |
| 361 List<Timing> parseTimings(BuildUri uri, String line) { | |
| 362 List<String> parts = split(line, [' - ', ' - ', ' ']); | |
| 363 String time = parts[0]; | |
| 364 String stepName = parts[1]; | |
| 365 String configName = parts[2]; | |
| 366 String testNames = parts[3]; | |
| 367 List<Timing> timings = <Timing>[]; | |
| 368 for (String testName in testNames.split(',')) { | |
| 369 timings.add(new Timing( | |
| 370 uri, | |
| 371 time, | |
| 372 new TestStep( | |
| 373 stepName, new TestConfiguration(configName, testName.trim())))); | |
| 374 } | |
| 375 return timings; | |
| 376 } | |
| 377 | |
| 378 /// Split [text] using [infixes] as infix markers. | |
| 379 List<String> split(String text, List<String> infixes) { | |
| 380 List<String> result = <String>[]; | |
| 381 int start = 0; | |
| 382 for (String infix in infixes) { | |
| 383 int index = text.indexOf(infix, start); | |
| 384 if (index == -1) | |
| 385 throw "'$infix' not found in '$text' from offset ${start}."; | |
| 386 result.add(text.substring(start, index)); | |
| 387 start = index + infix.length; | |
| 388 } | |
| 389 result.add(text.substring(start)); | |
| 390 return result; | |
| 391 } | |
| 392 | |
| 393 /// Pad [text] with spaces to the right to fit [length]. | |
| 394 String padRight(String text, int length) { | |
| 395 if (text.length < length) return '${text}${' ' * (length - text.length)}'; | |
| 396 return text; | |
| 397 } | |
| 398 | |
| 399 void log(String text) { | |
| 400 print(text); | |
| 401 } | |
| OLD | NEW |