| 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 import 'src/buildbot_structures.dart'; | |
| 14 import 'src/util.dart'; | |
| 15 | |
| 16 main(List<String> args) async { | |
| 17 if (args.length != 1) { | |
| 18 print('Usage: compare_failures <log-uri>'); | |
| 19 exit(1); | |
| 20 } | |
| 21 String url = args.first; | |
| 22 if (!url.endsWith('/text')) { | |
| 23 // Use the text version of the stdio log. | |
| 24 url += '/text'; | |
| 25 } | |
| 26 Uri uri = Uri.parse(url); | |
| 27 HttpClient client = new HttpClient(); | |
| 28 BuildUri buildUri = new BuildUri(uri); | |
| 29 List<BuildResult> results = await readBuildResults(client, buildUri); | |
| 30 print(generateBuildResultsSummary(buildUri, results)); | |
| 31 client.close(); | |
| 32 } | |
| 33 | |
| 34 /// Creates a [BuildResult] for [buildUri] and, if it contains failures, the | |
| 35 /// [BuildResult]s for the previous 5 builds. | |
| 36 Future<List<BuildResult>> readBuildResults( | |
| 37 HttpClient client, BuildUri buildUri) async { | |
| 38 List<BuildResult> summaries = <BuildResult>[]; | |
| 39 BuildResult firstSummary = await readBuildResult(client, buildUri); | |
| 40 summaries.add(firstSummary); | |
| 41 if (firstSummary.hasFailures) { | |
| 42 for (int i = 0; i < 10; i++) { | |
| 43 buildUri = buildUri.prev(); | |
| 44 summaries.add(await readBuildResult(client, buildUri)); | |
| 45 } | |
| 46 } | |
| 47 return summaries; | |
| 48 } | |
| 49 | |
| 50 /// Reads the content of [uri] as text. | |
| 51 Future<String> readUriAsText(HttpClient client, Uri uri) async { | |
| 52 HttpClientRequest request = await client.getUrl(uri); | |
| 53 HttpClientResponse response = await request.close(); | |
| 54 return UTF8.decode(await response.expand((l) => l).toList()); | |
| 55 } | |
| 56 | |
| 57 /// Parses the [buildUri] test log and creates a [BuildResult] for it. | |
| 58 Future<BuildResult> readBuildResult( | |
| 59 HttpClient client, BuildUri buildUri) async { | |
| 60 Uri uri = buildUri.toUri(); | |
| 61 log('Reading $uri'); | |
| 62 String text = await readUriAsText(client, uri); | |
| 63 | |
| 64 bool inFailure = false; | |
| 65 List<String> currentFailure; | |
| 66 bool parsingTimingBlock = false; | |
| 67 | |
| 68 List<TestFailure> failures = <TestFailure>[]; | |
| 69 List<Timing> timings = <Timing>[]; | |
| 70 for (String line in text.split('\n')) { | |
| 71 if (currentFailure != null) { | |
| 72 if (line.startsWith('!@@@STEP_CLEAR@@@')) { | |
| 73 failures.add(new TestFailure(buildUri, currentFailure)); | |
| 74 currentFailure = null; | |
| 75 } else { | |
| 76 currentFailure.add(line); | |
| 77 } | |
| 78 } else if (inFailure && line.startsWith('@@@STEP_FAILURE@@@')) { | |
| 79 inFailure = false; | |
| 80 } else if (line.startsWith('!@@@STEP_FAILURE@@@')) { | |
| 81 inFailure = true; | |
| 82 } else if (line.startsWith('FAILED:')) { | |
| 83 currentFailure = <String>[]; | |
| 84 currentFailure.add(line); | |
| 85 } | |
| 86 if (line.startsWith('--- Total time:')) { | |
| 87 parsingTimingBlock = true; | |
| 88 } else if (parsingTimingBlock) { | |
| 89 if (line.startsWith('0:')) { | |
| 90 timings.addAll(parseTimings(buildUri, line)); | |
| 91 } else { | |
| 92 parsingTimingBlock = false; | |
| 93 } | |
| 94 } | |
| 95 } | |
| 96 return new BuildResult(buildUri, failures, timings); | |
| 97 } | |
| 98 | |
| 99 /// Generate a summary of the timeouts and other failures in [results]. | |
| 100 String generateBuildResultsSummary( | |
| 101 BuildUri buildUri, List<BuildResult> results) { | |
| 102 StringBuffer sb = new StringBuffer(); | |
| 103 sb.write('Results for $buildUri:\n'); | |
| 104 Set<TestConfiguration> timeoutIds = new Set<TestConfiguration>(); | |
| 105 for (BuildResult result in results) { | |
| 106 timeoutIds.addAll(result.timeouts.map((TestFailure failure) => failure.id)); | |
| 107 } | |
| 108 if (timeoutIds.isNotEmpty) { | |
| 109 int firstBuildNumber = results.first.buildUri.buildNumber; | |
| 110 int lastBuildNumber = results.last.buildUri.buildNumber; | |
| 111 Map<TestConfiguration, Map<int, Map<String, Timing>>> map = | |
| 112 <TestConfiguration, Map<int, Map<String, Timing>>>{}; | |
| 113 Set<String> stepNames = new Set<String>(); | |
| 114 for (BuildResult result in results) { | |
| 115 for (Timing timing in result.timings) { | |
| 116 Map<int, Map<String, Timing>> builds = | |
| 117 map.putIfAbsent(timing.step.id, () => <int, Map<String, Timing>>{}); | |
| 118 stepNames.add(timing.step.stepName); | |
| 119 builds.putIfAbsent(timing.uri.buildNumber, () => <String, Timing>{})[ | |
| 120 timing.step.stepName] = timing; | |
| 121 } | |
| 122 } | |
| 123 sb.write('Timeouts for ${buildUri} :\n'); | |
| 124 map.forEach((TestConfiguration id, Map<int, Map<String, Timing>> timings) { | |
| 125 if (!timeoutIds.contains(id)) return; | |
| 126 sb.write('$id\n'); | |
| 127 sb.write( | |
| 128 '${' ' * 8} ${stepNames.map((t) => padRight(t, 14)).join(' ')}\n'); | |
| 129 for (int buildNumber = firstBuildNumber; | |
| 130 buildNumber >= lastBuildNumber; | |
| 131 buildNumber--) { | |
| 132 Map<String, Timing> steps = timings[buildNumber] ?? const {}; | |
| 133 sb.write(padRight(' ${buildNumber}: ', 8)); | |
| 134 for (String stepName in stepNames) { | |
| 135 Timing timing = steps[stepName]; | |
| 136 if (timing != null) { | |
| 137 sb.write(' ${timing.time}'); | |
| 138 } else { | |
| 139 sb.write(' --------------'); | |
| 140 } | |
| 141 } | |
| 142 sb.write('\n'); | |
| 143 } | |
| 144 sb.write('\n'); | |
| 145 }); | |
| 146 } | |
| 147 Set<TestConfiguration> errorIds = new Set<TestConfiguration>(); | |
| 148 for (BuildResult result in results) { | |
| 149 errorIds.addAll(result.errors.map((TestFailure failure) => failure.id)); | |
| 150 } | |
| 151 if (errorIds.isNotEmpty) { | |
| 152 int firstBuildNumber = results.first.buildUri.buildNumber; | |
| 153 int lastBuildNumber = results.last.buildUri.buildNumber; | |
| 154 Map<TestConfiguration, Map<int, TestFailure>> map = | |
| 155 <TestConfiguration, Map<int, TestFailure>>{}; | |
| 156 for (BuildResult result in results) { | |
| 157 for (TestFailure failure in result.errors) { | |
| 158 map.putIfAbsent(failure.id, () => <int, TestFailure>{})[ | |
| 159 failure.uri.buildNumber] = failure; | |
| 160 } | |
| 161 } | |
| 162 sb.write('Errors for ${buildUri} :\n'); | |
| 163 // TODO(johnniwinther): Improve comparison of non-timeouts. | |
| 164 map.forEach((TestConfiguration id, Map<int, TestFailure> failures) { | |
| 165 if (!errorIds.contains(id)) return; | |
| 166 sb.write('$id\n'); | |
| 167 for (int buildNumber = firstBuildNumber; | |
| 168 buildNumber >= lastBuildNumber; | |
| 169 buildNumber--) { | |
| 170 TestFailure failure = failures[buildNumber]; | |
| 171 sb.write(padRight(' ${buildNumber}: ', 8)); | |
| 172 if (failure != null) { | |
| 173 sb.write(padRight(failure.expected, 10)); | |
| 174 sb.write(' / '); | |
| 175 sb.write(padRight(failure.actual, 10)); | |
| 176 } else { | |
| 177 sb.write(' ' * 10); | |
| 178 sb.write(' / '); | |
| 179 sb.write(padRight('-- OK --', 10)); | |
| 180 } | |
| 181 sb.write('\n'); | |
| 182 } | |
| 183 sb.write('\n'); | |
| 184 }); | |
| 185 } | |
| 186 return sb.toString(); | |
| 187 } | |
| 188 | |
| 189 /// The results of a build step. | |
| 190 class BuildResult { | |
| 191 final BuildUri buildUri; | |
| 192 final List<TestFailure> _failures; | |
| 193 final List<Timing> _timings; | |
| 194 | |
| 195 BuildResult(this.buildUri, this._failures, this._timings); | |
| 196 | |
| 197 /// `true` of the build result has test failures. | |
| 198 bool get hasFailures => _failures.isNotEmpty; | |
| 199 | |
| 200 /// Returns the top-20 timings found in the build log. | |
| 201 Iterable<Timing> get timings => _timings; | |
| 202 | |
| 203 /// Returns the [TestFailure]s for tests that timed out. | |
| 204 Iterable<TestFailure> get timeouts { | |
| 205 return _failures | |
| 206 .where((TestFailure failure) => failure.actual == 'Timeout'); | |
| 207 } | |
| 208 | |
| 209 /// Returns the [TestFailure]s for failing tests that did not time out. | |
| 210 Iterable<TestFailure> get errors { | |
| 211 return _failures | |
| 212 .where((TestFailure failure) => failure.actual != 'Timeout'); | |
| 213 } | |
| 214 | |
| 215 String toString() { | |
| 216 StringBuffer sb = new StringBuffer(); | |
| 217 sb.write('$buildUri\n'); | |
| 218 sb.write('Failures:\n${_failures.join('\n-----\n')}\n'); | |
| 219 sb.write('\nTimings:\n${_timings.join('\n')}'); | |
| 220 return sb.toString(); | |
| 221 } | |
| 222 } | |
| 223 | |
| 224 /// Test failure data derived from the test failure summary in the build step | |
| 225 /// stdio log. | |
| 226 class TestFailure { | |
| 227 final BuildUri uri; | |
| 228 final TestConfiguration id; | |
| 229 final String expected; | |
| 230 final String actual; | |
| 231 final String text; | |
| 232 | |
| 233 factory TestFailure(BuildUri uri, List<String> lines) { | |
| 234 List<String> parts = split(lines.first, ['FAILED: ', ' ', ' ']); | |
| 235 String configName = parts[1]; | |
| 236 String archName = parts[2]; | |
| 237 String testName = parts[3]; | |
| 238 TestConfiguration id = | |
| 239 new TestConfiguration(configName, archName, testName); | |
| 240 String expected = split(lines[1], ['Expected: '])[1]; | |
| 241 String actual = split(lines[2], ['Actual: '])[1]; | |
| 242 return new TestFailure.internal( | |
| 243 uri, id, expected, actual, lines.skip(3).join('\n')); | |
| 244 } | |
| 245 | |
| 246 TestFailure.internal( | |
| 247 this.uri, this.id, this.expected, this.actual, this.text); | |
| 248 | |
| 249 String toString() { | |
| 250 StringBuffer sb = new StringBuffer(); | |
| 251 sb.write('FAILED: $id\n'); | |
| 252 sb.write('Expected: $expected\n'); | |
| 253 sb.write('Actual: $actual\n'); | |
| 254 sb.write(text); | |
| 255 return sb.toString(); | |
| 256 } | |
| 257 } | |
| 258 | |
| 259 /// Id for a single test step, for instance the compilation and run steps of | |
| 260 /// a test. | |
| 261 class TestStep { | |
| 262 final String stepName; | |
| 263 final TestConfiguration id; | |
| 264 | |
| 265 TestStep(this.stepName, this.id); | |
| 266 | |
| 267 String toString() { | |
| 268 return '$stepName - $id'; | |
| 269 } | |
| 270 | |
| 271 int get hashCode => stepName.hashCode * 13 + id.hashCode * 17; | |
| 272 | |
| 273 bool operator ==(other) { | |
| 274 if (identical(this, other)) return true; | |
| 275 if (other is! TestStep) return false; | |
| 276 return stepName == other.stepName && id == other.id; | |
| 277 } | |
| 278 } | |
| 279 | |
| 280 /// The timing result for a single test step. | |
| 281 class Timing { | |
| 282 final BuildUri uri; | |
| 283 final String time; | |
| 284 final TestStep step; | |
| 285 | |
| 286 Timing(this.uri, this.time, this.step); | |
| 287 | |
| 288 String toString() { | |
| 289 return '$time - $step'; | |
| 290 } | |
| 291 } | |
| 292 | |
| 293 /// Create the [Timing]s for the [line] as found in the top-20 timings of a | |
| 294 /// build step stdio log. | |
| 295 List<Timing> parseTimings(BuildUri uri, String line) { | |
| 296 List<String> parts = split(line, [' - ', ' - ', ' ']); | |
| 297 String time = parts[0]; | |
| 298 String stepName = parts[1]; | |
| 299 String configName = parts[2]; | |
| 300 String testNames = parts[3]; | |
| 301 List<Timing> timings = <Timing>[]; | |
| 302 for (String name in testNames.split(',')) { | |
| 303 name = name.trim(); | |
| 304 int slashPos = name.indexOf('/'); | |
| 305 String archName = name.substring(0, slashPos); | |
| 306 String testName = name.substring(slashPos + 1); | |
| 307 timings.add(new Timing( | |
| 308 uri, | |
| 309 time, | |
| 310 new TestStep( | |
| 311 stepName, new TestConfiguration(configName, archName, testName)))); | |
| 312 } | |
| 313 return timings; | |
| 314 } | |
| OLD | NEW |