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 |